[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 11:40:56 EST 2010
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