[jboss-dev] Remoting behavior on error (Re: Possible blocker with jboss-cl 2.2.0.Alpha1)
Jaikiran Pai
jpai at redhat.com
Fri Feb 19 14:04:00 EST 2010
Gave it a try locally and the fix works perfect. The default timeout
gets set to 30 minutes:
2010-02-20 00:27:55,841 TRACE
[org.jboss.remoting.transport.socket.SocketWrapper] constructing
org.jboss.remoting.transport.socket.ClientSocketWrapper instance for
Socket[addr=/127.0.0.1,port=3873,localport=44015], using timeout 1800000
2010-02-20 00:27:55,842 TRACE
[org.jboss.remoting.transport.socket.SocketWrapper]
ClientSocketWrapper[Socket[addr=/127.0.0.1,port=3873,localport=44015].18e18a3]
setting timeout to 1800000
Also tried the scenario where the timeout is overriden:
socket://${jboss.bind.address}:${port}?timeout=12345
That too worked fine:
2010-02-20 00:29:22,106 TRACE
[org.jboss.remoting.transport.socket.SocketWrapper] constructing
org.jboss.remoting.transport.socket.ClientSocketWrapper instance for
Socket[addr=/127.0.0.1,port=3873,localport=42510], using timeout 12345
2010-02-20 00:29:22,106 TRACE
[org.jboss.remoting.transport.socket.SocketWrapper]
ClientSocketWrapper[Socket[addr=/127.0.0.1,port=3873,localport=42510].1f38fc6]
setting timeout to 12345
Thanks for the quick fix, Ron.
-Jaikiran
Ron Sigal wrote:
> Hey Jaikiran,
>
> I've attached to JBREM-1188 a jboss-remoting.jar with the fix, just in
> case you want to try it out.
>
> -Ron
>
> Ron Sigal wrote:
>> JBREM-1188 "Socket transport doesn't set "timeout" to default value".
>>
>> Mia faccia e un pomodoro! [My face is a tomato!]
>>
>> Thanks, Jaikiran!
>>
>> -Ron
>>
>> Jaikiran Pai wrote:
>>> Bug, bug, bug ;)
>>>
>>> There's some Java initialization trick going on with that piece of
>>> code (only relevant code has been pasted below):
>>>
>>> public class SocketClientInvoker extends MicroSocketClientInvoker
>>> {
>>>
>>> /**
>>> * Default value for socket timeout is 30 minutes.
>>> */
>>> public static final int SO_TIMEOUT_DEFAULT = 1800000;
>>>
>>> protected int timeout = SO_TIMEOUT_DEFAULT;
>>> ...
>>>
>>> public SocketClientInvoker(InvokerLocator locator)
>>> {
>>> this(locator, null);
>>> }
>>>
>>> public SocketClientInvoker(InvokerLocator locator, Map configuration)
>>> {
>>> super(locator, configuration);
>>> configureParameters();
>>> }
>>>
>>> protected ServerAddress createServerAddress(InetAddress addr, int
>>> port)
>>> {
>>> return new ServerAddress(addr.getHostAddress(), port,
>>> enableTcpNoDelay, timeout, maxPoolSize);
>>> }
>>> ...
>>> }
>>>
>>>
>>> public class MicroSocketClientInvoker ...
>>> {
>>>
>>> public MicroSocketClientInvoker(InvokerLocator locator, Map
>>> configuration)
>>> {
>>> ...
>>>
>>> try
>>> {
>>> setup();
>>> }
>>> ...
>>>
>>> log.debug(this + " constructed");
>>> }
>>>
>>> protected void setup() throws Exception
>>> {
>>> ...
>>> address = createServerAddress(addr, port);
>>> }
>>> ...
>>> }
>>>
>>> 1) SocketClientInvoker extends MicroSocketClientInvoker
>>> 2) When someone constructs SocketClientInvoker through it's
>>> constructor, JVM first constructs MicroSocketClientInvoker.
>>> 3) This includes MicroSocketClientInvoker's object field
>>> initialization and then the code execution in
>>> MicroSocketClientInvoker's constructor.
>>> 4) MicroSocketClientInvoker's constructor invokes setup() on itself
>>> which then invokes the (overridden) createServerAddress() on
>>> SocketClientInvoker
>>> 5) Note that, at this point the object field initialization of
>>> SocketClientInvoker has *not* yet been done. So the
>>>
>>> protected int timeout = SO_TIMEOUT_DEFAULT;
>>>
>>> in SocketClientInvoker hasn't yet been executed. Effectively, when
>>> SocketClientInvoker.createServerAddress() is invoked, the timeout
>>> value is 0. As a result, SocketClientInvoker.createServerAddress()
>>> ends up creating a ServerAddress with timeout = 0 (infinite timeout).
>>> (Rest of the flow is irrelevant, but let's just outline it here for
>>> the sake of completeness)
>>> 6) After completion of SocketClientInvoker.createServerAddress()
>>> method invoked in step#4, the MicroSocketClientInvoker.setup too
>>> completes and ultimately the code execution in the
>>> MicroSocketClientInvoker's constructor too is completed.
>>> 7) After step#6, the object field initialization of
>>> SocketClientInvoker starts and it's at this point where the timeout
>>> field value gets set to 1800000, but by now it's too late.
>>>
>>> And here are the logs (only a part of the entire log file) from
>>> remoting which prove that the timeout is being set to 0:
>>>
>>> 2010-02-19 16:32:29,104 DEBUG [org.jboss.remoting.Client]
>>> Client[16278782:3j001-51zxod-g5uvg99p-1-g5uvg99q-2].connect(null)
>>> 2010-02-19 16:32:29,104 TRACE [org.jboss.remoting.Client]
>>> Client[16278782:3j001-51zxod-g5uvg99p-1-g5uvg99q-2]: metadata = null
>>> 2010-02-19 16:32:29,172 DEBUG
>>> [org.jboss.remoting.transport.socket.MicroSocketClientInvoker]
>>> SocketClientInvoker[879860, socket://localhost.localdomain:3873]
>>> constructed
>>> 2010-02-19 16:32:29,172 DEBUG
>>> [org.jboss.remoting.MicroRemoteClientInvoker]
>>> SocketClientInvoker[879860, socket://localhost.localdomain:3873]
>>> connecting
>>> 2010-02-19 16:32:29,173 DEBUG
>>> [org.jboss.remoting.transport.socket.MicroSocketClientInvoker]
>>> Creating semaphore with size 50
>>> 2010-02-19 16:32:29,173 TRACE
>>> [org.jboss.remoting.transport.socket.MicroSocketClientInvoker]
>>> SocketClientInvoker[879860, socket://localhost.localdomain:3873]
>>> added new pool ([]) as ServerAddress[127.0.0.1:3873, NO
>>> enableTcpNoDelay timeout 0 ms, maxPoolSize=50]
>>> ....
>>> 2010-02-19 16:32:29,185 TRACE
>>> [org.jboss.remoting.transport.socket.MicroSocketClientInvoker]
>>> SocketClientInvoker[879860, socket://localhost.localdomain:3873]
>>> retryCount: 0
>>> 2010-02-19 16:32:29,185 TRACE
>>> [org.jboss.remoting.transport.socket.MicroSocketClientInvoker]
>>> SocketClientInvoker[879860, socket://localhost.localdomain:3873]
>>> obtained semaphore: 49
>>> 2010-02-19 16:32:29,185 TRACE
>>> [org.jboss.remoting.transport.socket.MicroSocketClientInvoker]
>>> SocketClientInvoker[879860, socket://localhost.localdomain:3873]
>>> creating socket
>>> 2010-02-19 16:32:29,186 TRACE
>>> [org.jboss.remoting.transport.socket.MicroSocketClientInvoker]
>>> SocketClientInvoker[879860, socket://localhost.localdomain:3873]
>>> created socket: Socket[addr=/127.0.0.1,port=3873,localport=39135]
>>> 2010-02-19 16:32:29,187 TRACE
>>> [org.jboss.remoting.transport.socket.SocketWrapper] constructing
>>> org.jboss.remoting.transport.socket.ClientSocketWrapper instance for
>>> Socket[addr=/127.0.0.1,port=3873,localport=39135], using timeout 0
>>> 2010-02-19 16:32:29,187 TRACE
>>> [org.jboss.remoting.transport.socket.SocketWrapper]
>>> ClientSocketWrapper[Socket[addr=/127.0.0.1,port=3873,localport=39135].6c5482]
>>> setting timeout to 0
>>> ...
>>>
>>> regards,
>>> -Jaikiran
>>>
>>> Ron Sigal wrote:
>>>> Uh, maybe it's 30 minutes in metric. :)
>>>>
>>>> Actually, we fooled you. The actual client invoker is
>>>> org.jboss.remoting.transport.socket.SocketClientInvoker, which
>>>> overrides createServerAddress():
>>>>
>>>> protected ServerAddress createServerAddress()
>>>> {
>>>> return new ServerAddress(addr.getHostAddress(), port,
>>>> enableTcpNoDelay, timeout, maxPoolSize);
>>>> }
>>>>
>>>> "Once upon upon, in a disney far away", Tom Elrod got a request to
>>>> make Remoting suitable for micro devices without timeouts, and he
>>>> broke out MicroSocketClientInvoker from the original
>>>> SocketClientInvoker. It never went anywhere, since the requester
>>>> soon disappeared, as usual.
>>>>
>>>> -Ron
>>>>
>>>> ===========================
>>>> /*Snore Wife and Some Several Dwarts*
>>>>
>>>> Once upon upon in a dizney far away - say three hundred year agoal
>>>> if you like-there lived in a sneaky forest some several dwarts or
>>>> cretins; all named - Sleezy, Grumpty, Sneeky, Dog, Smirkey, Alice?
>>>> Derick - and Wimpey. Anyway they all dug about in a diamond mind,
>>>> which was rich beyond compere. Every day when they came hulme from
>>>> wirk, they would sing a song - just like ordinary wirkers - the
>>>> song went something like - 'Yo, ho! Yo, ho! it's off to wirk we
>>>> go!' - which is silly really considerable they were comeing hulme.
>>>> (Perhaps ther was slight housework to be do.)
>>>> One day howitzer they (Dwarts) arrived home, at aprodestant six
>>>> o'cloth, and who? - who do they find? - but only Snore Wife, asleep
>>>> in Grumpty's bed. He didn't seem to mine. 'Sambody's been feeding
>>>> my porrage!' screams Wimpey, who was wearing a light blue pullover.
>>>> Meanwife in a grand Carstle, not so a mile away, a womand is
>>>> looging in her daily mirror shouting, 'Mirror mirror on the wall,
>>>> whom is de fairy in the land.' which doesn't even rhyme.
>>>> 'Cassandle!' answers the mirror. 'Chirsh O'Malley' studders the
>>>> womand who appears to be a Queen or a witch or an acorn.
>>>>
>>>> -/John Lennon, /A Spaniard in the Works
>>>>
>>>> /
>>>> Jaikiran Pai wrote:
>>>>> The testcase has been hung since more than 3 days, now :) So looks
>>>>> like that default client timeout of 30 minutes isn't being
>>>>> honoured. By the way, EJB3 uses its own config file for remoting
>>>>> JBOSS_HOME/server/<
>>>>> servername>/deploy/ejb3-connectors-jboss-beans.xml. But that's
>>>>> irrelevant since the defaults should apply to any remoting config
>>>>> irrespective of which file it's configured in.
>>>>>
>>>>> So I looked at this in a bit more detail and it now appears to be
>>>>> a bug in JBoss Remoting. Here's what's happening:
>>>>>
>>>>> - A EJB3 client interceptor
>>>>> (org.jboss.aspects.remoting.InvokeRemoteInterceptor) responsible
>>>>> for invoking the remote EJB container does a remoting call:
>>>>>
>>>>> InvokerLocator locator =
>>>>> (InvokerLocator)invocation.getMetaData(REMOTING, INVOKER_LOCATOR);
>>>>> ...
>>>>> Client client = new Client(locator, subsystem);
>>>>> try
>>>>> {
>>>>> client.connect();
>>>>> ...
>>>>> client.invoke(invocation, null);
>>>>>
>>>>> - Remoting internally creates a
>>>>> org.jboss.remoting.transport.socket.MicroSocketClientInvoker which
>>>>> creates a ServerAddress:
>>>>>
>>>>> protected ServerAddress createServerAddress(InetAddress addr, int
>>>>> port)
>>>>> {
>>>>> return new ServerAddress(addr.getHostAddress(), port,
>>>>> enableTcpNoDelay, -1, maxPoolSize);
>>>>> }
>>>>>
>>>>> Notice the hardcoded -1 being passed to the ServerAddress. That's
>>>>> the "timeout". The ServerAddress internally ignores negative
>>>>> timeout values and sets the timeout to 0 (resulting in infinite
>>>>> timeout).
>>>>>
>>>>> - The MicroSocketClientInvoker then ultimately ends up creating a
>>>>> client socket with timeout = 0.
>>>>>
>>>>> - So when the server side remoting thread crashes (for any
>>>>> unrelated reason - like the classloading issue), the client ends
>>>>> up with this infinite block.
>>>>>
>>>>> The issues i see here:
>>>>>
>>>>> 1) I don't see a way, how i can pass a timeout for the client
>>>>> socket. Contrary to the comments in remoting-jboss-beans.xml,
>>>>> based on what i see in the code, it's only the server side timeout
>>>>> which has a corresponding param. Did i miss something?
>>>>>
>>>>> 2) Even if there was some way of passing the client socket
>>>>> timeout, currently the ServerAddress creation through
>>>>> MicroSocketClientInvoker hardcodes the timeout to -1.
>>>>>
>>>>> regards,
>>>>> -Jaikiran Adrian Brock wrote:
>>>>>> On Tue, 2010-02-16 at 18:14 +0530, Jaikiran Pai wrote:
>>>>>>> Ron Sigal wrote:
>>>>>>>> Yeah, Carlo also pointed out that NCDFE is a java.lang.Error,
>>>>>>>> which, as you note, is not caught. I agree that if
>>>>>>>> ServerThread is going to terminate due to an error, then it
>>>>>>>> should certainly close its socket, so that's a bug (JBREM-1183
>>>>>>>> "ServerThread should catch java.lang.Error"). But I have mixed
>>>>>>>> feelings about terminating ServerThread in this case. Unlike,
>>>>>>>> IOException, SocketException, etc., the NoClassDefFoundError
>>>>>>>> doesn't suggest that the socket is no longer usable. Maybe a
>>>>>>>> better solution (along with fixing the classloader problem, of
>>>>>>>> course) is to use a positive timeout on the client side.
>>>>>>> I think some (sensible) default timeout needs to be added so
>>>>>>> that the client does not end up hung. Is this something that can
>>>>>>> be added to some *-jboss-beans.xml in the AS?
>>>>>>>
>>>>>>
>>>>>> It already exists, but whether 30 minutes is a "sensible" default
>>>>>> is a different issue. ;-)
>>>>>>
>>>>>> See remoting-jboss-beans.xml
>>>>>>
>>>>>> <!-- Socket read timeout. Defaults to
>>>>>> 60000 ms (1 minute)
>>>>>> -->
>>>>>> <!-- on the server, 1800000 ms (30 minutes) on the
>>>>>> client.
>>>>>> -->
>>>>>> <!--entry><key>timeout</key>
>>>>>> <value>120000</value></entry-->
>>>>>>
>>>>>>
>>>>>
>>>
More information about the jboss-development
mailing list