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