[jboss-dev] Remoting behavior on error (Re: Possible blocker with jboss-cl 2.2.0.Alpha1)

Ron Sigal ron.sigal at jboss.com
Fri Feb 19 13:46:19 EST 2010


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