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

[Ron Sigal]

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-->
>>>>
>>>>
>>>
>