JMS Server Locks Up

[rtm333]

Dear All,

We are using JBoss AS 4.0.5.GA with Messaging 1.0.1.SP4 and are experiencing the following problems:

1) When a certain, multi-homed client PC is trying to open a JMS connection to a Solaris based JMS server it does not receive any updates. This is most probably caused by some misconfiguration of the client-side networking parameters and can be solved by supplying the "correct" ip address in the property "jboss.messaging.callback.bind.address". Other multi-homed clients, that at first glance look identically set up, do not show this problem.

For each time the problematic client is trying to connect, the server starts throwing an exception that keeps being repeated every 224 secs until server shutdown (the port number is different for each connection attempt):

2007-02-14 13:30:44,188 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[1fa3d95, socket://11.222.111.222:3575] got Exception java.net.ConnectException: Connection timed out, creation attempt took 224680 ms




2) More seriously, eventually the JMS server locks up and already connected clients cannot disconnect, while new clients cannot connect. I have included the relevant parts of the stack dumps of the server, one client trying to close and one client trying to start the JMS connection.

On the server side most threads are waiting to lock the SimpleConnectionManager <0xb8710e68>. This lock is currently held by Timer-25, that itself is waiting to lock the ConcurrentReaderHashMap <0xbb51f358>. This lock is held by WorkerThread#11, waiting for a notification that is seemingly never coming in org.jboss.messaging.util.Future.getResult(Future.java:51).

Unfortunately, we do not yet know exactly what chain of events (it involved starting and closing several clients, including the problematic one mentioned above) leads to the lock-up and whether it is connected to problem 1) above.

Any hints welcome.



Server:
-------

"Thread-168" prio=10 tid=0x00e10ab8 nid=0x2770 waiting for monitor entry [0x9aeff000..0x9aeffaf0]
at org.jboss.jms.server.connectionmanager.SimpleConnectionManager.handleClientFailure(SimpleConnectionManager.java:131)
- waiting to lock <0xb8710e68> (a org.jboss.jms.server.connectionmanager.SimpleConnectionManager)
at org.jboss.jms.server.endpoint.ServerConsumerEndpoint$Deliverer.run(ServerConsumerEndpoint.java:814)
at EDU.oswego.cs.dl.util.concurrent.QueuedExecutor$RunLoop.run(QueuedExecutor.java:89)
at java.lang.Thread.run(Thread.java:595)

"Thread-155" prio=10 tid=0x008a4190 nid=0x25a9 waiting for monitor entry [0xab9ff000..0xab9ffb70]
at org.jboss.jms.server.connectionmanager.SimpleConnectionManager.handleClientFailure(SimpleConnectionManager.java:131)
- waiting to lock <0xb8710e68> (a org.jboss.jms.server.connectionmanager.SimpleConnectionManager)
at org.jboss.jms.server.endpoint.ServerConsumerEndpoint$Deliverer.run(ServerConsumerEndpoint.java:814)
at EDU.oswego.cs.dl.util.concurrent.QueuedExecutor$RunLoop.run(QueuedExecutor.java:89)
at java.lang.Thread.run(Thread.java:595)

"WorkerThread#15[11.222.111.222:3960]" prio=10 tid=0x01a32ec8 nid=0x1d6c waiting for monitor entry [0x9b4ff000..0x9b4ff8f0]
at org.jboss.jms.server.connectionmanager.SimpleConnectionManager.registerConnection(SimpleConnectionManager.java:82)
- waiting to lock <0xb8710e68> (a org.jboss.jms.server.connectionmanager.SimpleConnectionManager)
at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.setRemotingInformation(ServerConnectionEndpoint.java:527)
at org.jboss.jms.server.container.InjectionAspect.handleCreateConnectionDelegate(InjectionAspect.java:98)
at org.jboss.aop.advice.org.jboss.jms.server.container.InjectionAspect0.invoke(InjectionAspect0.java)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aop.Advisor.dynamicInvoke(Advisor.java:723)
at org.jboss.aop.Dispatcher.invoke(Dispatcher.java:101)
at org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:127)
at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:715)
at org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:552)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:377)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:159)

"WorkerThread#13[11.222.111.222:3898]" prio=10 tid=0x00ba1f20 nid=0x1d1a waiting for monitor entry [0x9dffe000..0x9dfff9f0]
at org.jboss.jms.server.connectionmanager.SimpleConnectionManager.unregisterConnection(SimpleConnectionManager.java:102)
- waiting to lock <0xb8710e68> (a org.jboss.jms.server.connectionmanager.SimpleConnectionManager)
at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.close(ServerConnectionEndpoint.java:332)
at org.jboss.jms.server.endpoint.advised.ConnectionAdvised.org$jboss$jms$server$endpoint$advised$ConnectionAdvised$close$aop(ConnectionAdvised.java:62)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
at org.jboss.jms.server.container.ServerLogInterceptor.invoke(ServerLogInterceptor.java:105)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aop.Advisor.dynamicInvoke(Advisor.java:723)
at org.jboss.aop.Dispatcher.invoke(Dispatcher.java:101)
at org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:127)
at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:715)
at org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:552)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:377)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:159)

"WorkerThread#8[11.222.111.223:3157]" prio=10 tid=0x00ea6890 nid=0x1866 waiting for monitor entry [0xa29fe000..0xa29ffbf0]
at org.jboss.jms.server.connectionmanager.SimpleConnectionManager.unregisterConnection(SimpleConnectionManager.java:102)
- waiting to lock <0xb8710e68> (a org.jboss.jms.server.connectionmanager.SimpleConnectionManager)
at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.close(ServerConnectionEndpoint.java:332)
at org.jboss.jms.server.endpoint.advised.ConnectionAdvised.org$jboss$jms$server$endpoint$advised$ConnectionAdvised$close$aop(ConnectionAdvised.java:62)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
at org.jboss.jms.server.container.ServerLogInterceptor.invoke(ServerLogInterceptor.java:105)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aop.Advisor.dynamicInvoke(Advisor.java:723)
at org.jboss.aop.Dispatcher.invoke(Dispatcher.java:101)
at org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:127)
at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:715)
at org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:552)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:377)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:159)

"Thread-127" prio=10 tid=0x01396d08 nid=0x1685 waiting for monitor entry [0x9d9ff000..0x9d9ff970]
at org.jboss.jms.server.connectionmanager.SimpleConnectionManager.handleClientFailure(SimpleConnectionManager.java:131)
- waiting to lock <0xb8710e68> (a org.jboss.jms.server.connectionmanager.SimpleConnectionManager)
at org.jboss.jms.server.endpoint.ServerConsumerEndpoint$Deliverer.run(ServerConsumerEndpoint.java:814)
at EDU.oswego.cs.dl.util.concurrent.QueuedExecutor$RunLoop.run(QueuedExecutor.java:89)
at java.lang.Thread.run(Thread.java:595)

"Thread-126" prio=10 tid=0x014e1680 nid=0x1684 waiting for monitor entry [0xa0eff000..0xa0eff8f0]
at org.jboss.jms.server.connectionmanager.SimpleConnectionManager.handleClientFailure(SimpleConnectionManager.java:131)
- waiting to lock <0xb8710e68> (a org.jboss.jms.server.connectionmanager.SimpleConnectionManager)
at org.jboss.jms.server.endpoint.ServerConsumerEndpoint$Deliverer.run(ServerConsumerEndpoint.java:814)
at EDU.oswego.cs.dl.util.concurrent.QueuedExecutor$RunLoop.run(QueuedExecutor.java:89)
at java.lang.Thread.run(Thread.java:595)

"WorkerThread#2[11.222.111.223:3488]" prio=10 tid=0x014f74f0 nid=0xa38 waiting for monitor entry [0xa31ff000..0xa31ffaf0]
at org.jboss.jms.server.connectionmanager.SimpleConnectionManager.registerConnection(SimpleConnectionManager.java:82)
- waiting to lock <0xb8710e68> (a org.jboss.jms.server.connectionmanager.SimpleConnectionManager)
at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.setRemotingInformation(ServerConnectionEndpoint.java:527)
at org.jboss.jms.server.container.InjectionAspect.handleCreateConnectionDelegate(InjectionAspect.java:98)
at org.jboss.aop.advice.org.jboss.jms.server.container.InjectionAspect0.invoke(InjectionAspect0.java)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aop.Advisor.dynamicInvoke(Advisor.java:723)
at org.jboss.aop.Dispatcher.invoke(Dispatcher.java:101)
at org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:127)
at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:715)
at org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:552)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:377)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:159)

"Timer-25" daemon prio=10 tid=0x006fbd50 nid=0x38e waiting for monitor entry [0xa5cff000..0xa5cffbf0]
at EDU.oswego.cs.dl.util.concurrent.ConcurrentReaderHashMap.size(ConcurrentReaderHashMap.java:379)
- waiting to lock <0xbb51f358> (a EDU.oswego.cs.dl.util.concurrent.ConcurrentReaderHashMap)
at EDU.oswego.cs.dl.util.concurrent.ConcurrentReaderHashMap$Values.size(ConcurrentReaderHashMap.java:928)
at java.util.HashSet.(HashSet.java:99)
at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.close(ServerConnectionEndpoint.java:302)
at org.jboss.jms.server.connectionmanager.SimpleConnectionManager.handleClientFailure(SimpleConnectionManager.java:173)
- locked <0xb8710e68> (a org.jboss.jms.server.connectionmanager.SimpleConnectionManager)
at org.jboss.jms.server.connectionmanager.SimpleConnectionManager.handleConnectionException(SimpleConnectionManager.java:231)
at org.jboss.remoting.ConnectionNotifier.connectionLost(ConnectionNotifier.java:45)
at org.jboss.remoting.Lease.notifyClientLost(Lease.java:211)
at org.jboss.remoting.Lease.access$300(Lease.java:39)
at org.jboss.remoting.Lease$LeaseTimerTask.run(Lease.java:248)
at java.util.TimerThread.mainLoop(Timer.java:512)
at java.util.TimerThread.run(Timer.java:462)

"WorkerThread#11[11.222.111.222:3824]" prio=10 tid=0x00335e48 nid=0x1d01 in Object.wait() [0xa30fe000..0xa30ffb70]
at java.lang.Object.wait(Native Method)
- waiting on <0xbb5662a0> (a org.jboss.messaging.util.Future)
at java.lang.Object.wait(Object.java:474)
at org.jboss.messaging.util.Future.getResult(Future.java:51)
- locked <0xbb5662a0> (a org.jboss.messaging.util.Future)
at org.jboss.jms.server.endpoint.ServerConsumerEndpoint.stop(ServerConsumerEndpoint.java:677)
at org.jboss.jms.server.endpoint.ServerSessionEndpoint.setStarted(ServerSessionEndpoint.java:822)
- locked <0xbb51f210> (a java.util.HashMap)
at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.setStarted(ServerConnectionEndpoint.java:753)
- locked <0xbb51f358> (a EDU.oswego.cs.dl.util.concurrent.ConcurrentReaderHashMap)
at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.stop(ServerConnectionEndpoint.java:280)
- locked <0xbb51f1b8> (a org.jboss.jms.server.endpoint.ServerConnectionEndpoint)
at org.jboss.jms.server.endpoint.advised.ConnectionAdvised.org$jboss$jms$server$endpoint$advised$ConnectionAdvised$stop$aop(ConnectionAdvised.java:99)
at sun.reflect.GeneratedMethodAccessor136.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
at org.jboss.jms.server.container.ServerLogInterceptor.invoke(ServerLogInterceptor.java:105)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aop.Advisor.dynamicInvoke(Advisor.java:723)
at org.jboss.aop.Dispatcher.invoke(Dispatcher.java:101)
at org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:127)
at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:715)
at org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:552)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:377)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:159)




Closing Client Hangs:
---------------------

"WorkerThread#1[1.2.3.4:64999]" prio=6 tid=0x1d228b60 nid=0x798 runnable [0x1cf1f000..0x1cf1fc68]
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(Unknown Source)
at java.io.BufferedInputStream.fill(Unknown Source)
at java.io.BufferedInputStream.read(Unknown Source)
- locked <0x04599898> (a java.io.BufferedInputStream)
at java.io.FilterInputStream.read(Unknown Source)
at org.jboss.serial.io.JBossObjectInputStream.read(JBossObjectInputStream.java:193)
at org.jboss.remoting.transport.socket.ServerThread.readVersion(ServerThread.java:794)
at org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:499)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:377)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:159)

"WorkerThread#0[1.2.3.4:64919]" prio=6 tid=0x0090cc60 nid=0xba4 in Object.wait() [0x187af000..0x187afce8]
at java.lang.Object.wait(Native Method)
- waiting on <0x04549c60> (a org.jboss.remoting.transport.socket.ServerThread)
at java.lang.Object.wait(Unknown Source)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:203)
- locked <0x04549c60> (a org.jboss.remoting.transport.socket.ServerThread)

"ServerSocketRefresh" prio=6 tid=0x008f94c0 nid=0xbe8 waiting on condition [0x1d01f000..0x1d01fae8]
at java.lang.Thread.sleep(Native Method)
at org.jboss.remoting.transport.socket.SocketServerInvoker$ServerSocketRefresh.run(SocketServerInvoker.java:677)

"AcceptorThread#0:3134" prio=6 tid=0x008fae70 nid=0xb10 runnable [0x1cfdf000..0x1cfdfb68]
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(Unknown Source)
- locked <0x044cc018> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(Unknown Source)
at java.net.ServerSocket.accept(Unknown Source)
at org.jboss.remoting.transport.socket.SocketServerInvoker.run(SocketServerInvoker.java:502)
at java.lang.Thread.run(Unknown Source)

"AWT-EventQueue-0" prio=6 tid=0x0087e2c0 nid=0xf48 runnable [0x1ad5e000..0x1ad5fc68]
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(Unknown Source)
at java.io.BufferedInputStream.fill(Unknown Source)
at java.io.BufferedInputStream.read(Unknown Source)
- locked <0x0443b740> (a java.io.BufferedInputStream)
at java.io.FilterInputStream.read(Unknown Source)
at org.jboss.serial.io.JBossObjectInputStream.read(JBossObjectInputStream.java:193)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.readVersion(MicroSocketClientInvoker.java:902)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:552)
at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:122)
at org.jboss.remoting.Client.invoke(Client.java:1414)
at org.jboss.remoting.Client.invoke(Client.java:511)
at org.jboss.jms.client.delegate.DelegateSupport.invoke(DelegateSupport.java:111)
at org.jboss.jms.client.delegate.ClientConnectionDelegate$close_N4742752445160157748.invokeNext(ClientConnectionDelegate$close_N4742752445160157748.java)
at org.jboss.jms.client.container.ConnectionAspect.handleClose(ConnectionAspect.java:169)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.jboss.aop.advice.PerInstanceAdvice.invoke(PerInstanceAdvice.java:130)
at org.jboss.jms.client.delegate.ClientConnectionDelegate$close_N4742752445160157748.invokeNext(ClientConnectionDelegate$close_N4742752445160157748.java)
at org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:182)
at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:117)
at org.jboss.jms.client.delegate.ClientConnectionDelegate$close_N4742752445160157748.invokeNext(ClientConnectionDelegate$close_N4742752445160157748.java)
at org.jboss.jms.client.container.ExceptionInterceptor.invoke(ExceptionInterceptor.java:69)
at org.jboss.jms.client.delegate.ClientConnectionDelegate$close_N4742752445160157748.invokeNext(ClientConnectionDelegate$close_N4742752445160157748.java)
at org.jboss.jms.client.container.ClientLogInterceptor.invoke(ClientLogInterceptor.java:107)
at org.jboss.jms.client.delegate.ClientConnectionDelegate$close_N4742752445160157748.invokeNext(ClientConnectionDelegate$close_N4742752445160157748.java)
at org.jboss.jms.client.delegate.ClientConnectionDelegate.close(ClientConnectionDelegate.java)
at org.jboss.jms.client.JBossConnection.close(JBossConnection.java:132)
...



Starting Client Hangs:
----------------------

"ServerSocketRefresh" prio=6 tid=0x008eae70 nid=0xfb8 waiting on condition [0x1d1cf000..0x1d1cfbe8]
at java.lang.Thread.sleep(Native Method)
at org.jboss.remoting.transport.socket.SocketServerInvoker$ServerSocketRefresh.run(SocketServerInvoker.java:677)

"AcceptorThread#0:2773" prio=6 tid=0x008f3900 nid=0xc8c runnable [0x1cfcf000..0x1cfcfce8]
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(Unknown Source)
- locked <0x044d9628> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(Unknown Source)
at java.net.ServerSocket.accept(Unknown Source)
at org.jboss.remoting.transport.socket.SocketServerInvoker.run(SocketServerInvoker.java:502)
at java.lang.Thread.run(Unknown Source)

"Thread-21" prio=6 tid=0x008d5900 nid=0xeb4 runnable [0x1d08f000..0x1d08fae8]
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(Unknown Source)
at java.io.BufferedInputStream.fill(Unknown Source)
at java.io.BufferedInputStream.read(Unknown Source)
- locked <0x04448c18> (a java.io.BufferedInputStream)
at java.io.FilterInputStream.read(Unknown Source)
at org.jboss.serial.io.JBossObjectInputStream.read(JBossObjectInputStream.java:193)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.readVersion(MicroSocketClientInvoker.java:902)
at org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:552)
at org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:122)
at org.jboss.remoting.Client.invoke(Client.java:1414)
at org.jboss.remoting.Client.invoke(Client.java:511)
at org.jboss.jms.client.delegate.ClientConnectionFactoryDelegate.invoke(ClientConnectionFactoryDelegate.java:199)
- locked <0x04448d78> (a org.jboss.jms.client.delegate.ClientConnectionFactoryDelegate)
at org.jboss.jms.client.delegate.ClientConnectionFactoryDelegate$createConnectionDelegate_N6840474864420126404.invokeNext(ClientConnectionFactoryDelegate$createConnectionDelegate_N6840474864420126404.java)
at org.jboss.jms.client.container.StateCreationAspect.handleCreateConnectionDelegate(StateCreationAspect.java:81)
at org.jboss.aop.advice.org.jboss.jms.client.container.StateCreationAspect0.invoke(StateCreationAspect0.java)
at org.jboss.jms.client.delegate.ClientConnectionFactoryDelegate$createConnectionDelegate_N6840474864420126404.invokeNext(ClientConnectionFactoryDelegate$createConnectionDelegate_N6840474864420126404.java)
at org.jboss.jms.client.container.ExceptionInterceptor.invoke(ExceptionInterceptor.java:69)
at org.jboss.jms.client.delegate.ClientConnectionFactoryDelegate$createConnectionDelegate_N6840474864420126404.invokeNext(ClientConnectionFactoryDelegate$createConnectionDelegate_N6840474864420126404.java)
at org.jboss.jms.client.container.ClientLogInterceptor.invoke(ClientLogInterceptor.java:107)
at org.jboss.jms.client.delegate.ClientConnectionFactoryDelegate$createConnectionDelegate_N6840474864420126404.invokeNext(ClientConnectionFactoryDelegate$createConnectionDelegate_N6840474864420126404.java)
at org.jboss.jms.client.delegate.ClientConnectionFactoryDelegate.createConnectionDelegate(ClientConnectionFactoryDelegate.java)
at org.jboss.jms.client.JBossConnectionFactory.createConnectionInternal(JBossConnectionFactory.java:203)
at org.jboss.jms.client.JBossConnectionFactory.createTopicConnection(JBossConnectionFactory.java:121)
at org.jboss.jms.client.JBossConnectionFactory.createTopicConnection(JBossConnectionFactory.java:116)
...

[timfox]

Just to clarify, you say this is solved by setting jboss.messaging.callback.bind.address?

[clebert.suconic]

http://jira.jboss.org/jira/browse/JBMESSAGING-836


I see that ServerConnectionEndpoint::setSTarted is synchronizing sessions

 private void setStarted(boolean s) throws Throwable
 {
 synchronized(sessions)
 {
 for (Iterator i = sessions.values().iterator(); i.hasNext(); )
 {
 ServerSessionEndpoint sd = (ServerSessionEndpoint)i.next();
 sd.setStarted(s);
 }
 started = s;
 }
 }

While this pattern will also synchronize sessions:

 for(Iterator i = new HashSet(sessions.values()).iterator(); i.hasNext(); )

So... basically I know how to fix this... but it would be nice to have a testcase replicating this. I'm trying to exercize my imagination now.. any help?

[clebert.suconic]

A workaround for you would be to keep your Sessions active.. .not closing them so often. Don't know if that would be a temporary solution for you?

[rtm333]

Hi Tim,

Thanks for your quick reply.

The first problem, namely the failure to receive any JMS messages and the subsequent timeout exceptions on the server, does not occur when the explicit ip address is specified. In this case, the special client behaves just like any other "normal" client.

I can't be sure whether the server lock-up is really related to this client. Probably yes, as up to now, we have observed the lock-up only when this peculiar client has attempted to connect (without providing the explicit ip address) several times.

[clebert.suconic]

"rtm333" wrote:
Hi Tim,

Thanks for your quick reply.

The first problem, namely the failure to receive any JMS messages and the subsequent timeout exceptions on the server, does not occur when the explicit ip address is specified. In this case, the special client behaves just like any other "normal" client.

I can't be sure whether the server lock-up is really related to this client. Probably yes, as up to now, we have observed the lock-up only when this peculiar client has attempted to connect (without providing the explicit ip address) several times.

Makes sense from what I saw in the code...

We are synchronizing sessions hashmap... while the server is also closing the tree.. and on that process we are flushing messages to the client... Because we can't reach the client... we are holding the HashMap locked on setStarted. I will try to create a testcase based in what you said.

[clebert.suconic]

rtm333,

It would help if you could attach a complete stack trace here:

http://jira.jboss.org/jira/browse/JBMESSAGING-836

In particular... I want to know what is holding this thread to finish, ont the future task:

"WorkerThread#11[11.222.111.222:3824]" prio=10 tid=0x00335e48 nid=0x1d01 in Object.wait() [0xa30fe000..0xa30ffb70]
at java.lang.Object.wait(Native Method)
- waiting on <0xbb5662a0> (a org.jboss.messaging.util.Future)
at java.lang.Object.wait(Object.java:474)
at org.jboss.messaging.util.Future.getResult(Future.java:51)
- locked <0xbb5662a0> (a org.jboss.messaging.util.Future)
at org.jboss.jms.server.endpoint.ServerConsumerEndpoint.stop(ServerConsumerEndpoint.java:677)
at org.jboss.jms.server.endpoint.ServerSessionEndpoint.setStarted(ServerSessionEndpoint.java:822)
- locked <0xbb51f210> (a java.util.HashMap)
at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.setStarted(ServerConnectionEndpoint.java:753)
- locked <0xbb51f358> (a EDU.oswego.cs.dl.util.concurrent.ConcurrentReaderHashMap)
at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.stop(ServerConnectionEndpoint.java:280)
- locked <0xbb51f1b8> (a org.jboss.jms.server.endpoint.ServerConnectionEndpoint)
at org.jboss.jms.server.endpoint.advised.ConnectionAdvised.org$jboss$jms$server$endpoint$advised$ConnectionAdvised$stop$aop(ConnectionAdvised.java:99)
at sun.reflect.GeneratedMethodAccessor136.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
at org.jboss.jms.server.container.ServerLogInterceptor.invoke(ServerLogInterceptor.java:105)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aop.Advisor.dynamicInvoke(Advisor.java:723)
at org.jboss.aop.Dispatcher.invoke(Dispatcher.java:101)
at org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:127)
at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:715)
at org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:552)
at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:377)
at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:159)

[timfox]

No need for another stack trace - I can see what is happening - it's all in the original trace

The consumer close tries to flush any deliveries in progress to the network, and it tries to wait for that to return, but it doesn't because the previous task in the queued executor is locked on the simpleconnectionmanager:

"Thread-168" prio=10 tid=0x00e10ab8 nid=0x2770 waiting for monitor entry [0x9aeff000..0x9aeffaf0]
at org.jboss.jms.server.connectionmanager.SimpleConnectionManager.handleClientFailure(SimpleConnectionManager.java:131)
- waiting to lock <0xb8710e68> (a org.jboss.jms.server.connectionmanager.SimpleConnectionManager)
at org.jboss.jms.server.endpoint.ServerConsumerEndpoint$Deliverer.run(ServerConsumerEndpoint.java:814)
at EDU.oswego.cs.dl.util.concurrent.QueuedExecutor$RunLoop.run(QueuedExecutor.java:89)
at java.lang.Thread.run(Thread.java:595)

So it all seizes up.

This should be a simple fix.

[rtm333]

Tim, Clebert,

Many thanks for your support.

To help us assess the risk incurred by this issue, I have a few questions:

1. What is your estimate when the bug fix (SP5) will be released?

2. From your analysis, do you think the lock-up will only occur after a "problematic" client has tried to connect, or can it happen anyway?

3. Is there a way to revive only the locked-up Messaging on the server without having to restart the whole JBoss AS (e.g. via an MBean)?

BTW: The connection problem seems to be caused by a routing issue to the second NIC.

[clebert.suconic]

2. From your analysis, do you think the lock-up will only occur after a "problematic" client has tried to connect, or can it happen anyway?

It only happens with Lease and an invalid client. If your server has access to clients... this won't happen.

3. Is there a way to revive only the locked-up Messaging on the server without having to restart the whole JBoss AS (e.g. via an MBean)?

I'm not 100% sure if you kill your client, if that would unlock the dead lock. From what I saw when the server locks you need to restart it.