#160 Client-Server Connection hangs and locks clients
OpenJMS works fine for 2-3 days, then suddenly, client connections seem to keep hanging on the server side.
When doing a netstat:
tcp 0 0 ::ffff:192.168.111.190:3035 ::ffff:192.168.111.166:1397 ESTABLISHED
tcp 0 0 ::ffff:192.168.111.190:3035 ::ffff:192.168.111.162:1389 ESTABLISHED
tcp 0 0 ::ffff:192.168.111.190:3035 ::ffff:192.168.111.161:1193 ESTABLISHED
And these hanging connections cause all new incoming client connections to lock on creating a session on the connection.
The place where the client JMS implementation blocks is:
javax.jms.ConnectionFactory factory = (ConnectionFactory) context.lookup("TCPConnectionFactory");
javax.jms.Connection connection = factory.createConnection();
// blocks here forever !
// -----------------------
javax.jms.Session session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);
// -----------------------
This situation is only resolved when stopping the jms server and restarting it. Then it works fine again for 2-3 days, and the whole problem reoccurs.
The problem mostly occurs when client applications connect through a VPN, and when the connection is then lost because the VPN disconnects.
There should be a (server.xml) configurable option that stalled connections should be disconnected after a while, but there is no configuration option.
Also in the JMS client API, there is no way to set a connection timeout when creating a session from a connection object or when sending a message on a disconnected connection.
connection.stop,close or session.close does not do anything !!! The client keeps blocked on the connection.createSession !
Please take this bug serious, because it seems that others also have this problem.
Logged In: YES
user_id=1663703
Originator: YES
I tried to force the phenomenon, and I succeeded.
What I did was: (using Windows XP and VPN connection)
1) Start a VPN connection to remote network with our openJMS server. Let it only have a Topic with a TCP connection factory configured.
2) connect a JMS client application (via the VPN connection) and let it send repeated messages to the topic (send/receive)
3) disconnect hard the VPN connection while client is sending/receiving
4) check on remote site that network connection was still in netstat.
5) the JMS server now hangs, and does allow incoming connections, but blocks on all other connecting clients when creating a session on that connection.
6) situation only resolves when restarting jms server again.
Logged In: YES
user_id=1120792
Originator: NO
I also experience this problem. What I did to reproduce was essentially a multiple-senders-multiple-receivers kind of test over a network which loses packets. It happens almost immediately, may be a few minutes of activity and it locks up.
The clients appear to block in createSession, like Peter said. The bad thing about this is that the server simply won't come back to life, no matter if I kill all the clients and wait (for reasonable amount of time). It has to be restarted.
Logged In: YES
user_id=557161
Originator: NO
Please attach a stack dump of both the client and server.
Logged In: YES
user_id=1120792
Originator: NO
**************************
Server stack dump upon a lockup:
**************************
Full thread dump Java HotSpot(TM) Server VM (diablo-1.5.0_07-b00 mixed mode):
"tcp://1.2.3.4:7480/[server]-Multiplexer" prio=5 tid=0x08445800 nid=0x829de00 runnable [0xbeac5000..0xbeac5c00]
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.net.SocketInputStream.read(SocketInputStream.java:182)
at java.io.DataInputStream.readByte(DataInputStream.java:241)
at org.exolab.jms.net.multiplexer.Multiplexer.multiplex(Multiplexer.java:525)
at org.exolab.jms.net.multiplexer.Multiplexer.run(Multiplexer.java:181)
at java.lang.Thread.run(Thread.java:595)
"tcp://1.2.3.4:7476/[server]-Multiplexer" prio=5 tid=0x08421200 nid=0x8293e00 runnable [0xbe9c1000..0xbe9c1b80]
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.net.SocketInputStream.read(SocketInputStream.java:182)
at java.io.DataInputStream.readByte(DataInputStream.java:241)
at org.exolab.jms.net.multiplexer.Multiplexer.multiplex(Multiplexer.java:525)
at org.exolab.jms.net.multiplexer.Multiplexer.run(Multiplexer.java:181)
at java.lang.Thread.run(Thread.java:595)
"tcp://1.2.3.4:7475/[server]-Multiplexer" prio=5 tid=0x08161200 nid=0x8161400 runnable [0xbf326000..0xbf326d00]
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.net.SocketInputStream.read(SocketInputStream.java:182)
at java.io.DataInputStream.readByte(DataInputStream.java:241)
at org.exolab.jms.net.multiplexer.Multiplexer.multiplex(Multiplexer.java:525)
at org.exolab.jms.net.multiplexer.Multiplexer.run(Multiplexer.java:181)
at java.lang.Thread.run(Thread.java:595)
"tcp://1.2.3.4:7471/[server]-Multiplexer" prio=5 tid=0x082e3000 nid=0x8262800 runnable [0xbed4f000..0xbed4fa00]
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.net.SocketInputStream.read(SocketInputStream.java:182)
at java.io.DataInputStream.readByte(DataInputStream.java:241)
at org.exolab.jms.net.multiplexer.Multiplexer.multiplex(Multiplexer.java:525)
at org.exolab.jms.net.multiplexer.Multiplexer.run(Multiplexer.java:181)
at java.lang.Thread.run(Thread.java:595)
"tcp://1.2.3.4:7463/[server]-Multiplexer" prio=5 tid=0x08293000 nid=0x83b2600 runnable [0xbe674000..0xbe674b00]
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.net.SocketInputStream.read(SocketInputStream.java:182)
at java.io.DataInputStream.readByte(DataInputStream.java:241)
at org.exolab.jms.net.multiplexer.Multiplexer.multiplex(Multiplexer.java:525)
at org.exolab.jms.net.multiplexer.Multiplexer.run(Multiplexer.java:181)
at java.lang.Thread.run(Thread.java:595)
"ManagedConnectionReaper1" prio=5 tid=0x08259c00 nid=0x8262c00 in Object.wait() [0xbed0e000..0xbed0ea80]
at java.lang.Object.wait(Native Method)
- waiting on <0x32aaf378> (a EDU.oswego.cs.dl.util.concurrent.ClockDaemon)
at EDU.oswego.cs.dl.util.concurrent.ClockDaemon.nextTask(Unknown Source)
- locked <0x32aaf378> (a EDU.oswego.cs.dl.util.concurrent.ClockDaemon)
at EDU.oswego.cs.dl.util.concurrent.ClockDaemon$RunLoop.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"tcp://1.2.3.4:7462/[server]-Multiplexer" prio=5 tid=0x08259600 nid=0x8262000 runnable [0xbedd1000..0xbedd1c00]
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.net.SocketInputStream.read(SocketInputStream.java:182)
at java.io.DataInputStream.readByte(DataInputStream.java:241)
at org.exolab.jms.net.multiplexer.Multiplexer.multiplex(Multiplexer.java:525)
at org.exolab.jms.net.multiplexer.Multiplexer.run(Multiplexer.java:181)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-19" prio=5 tid=0x08445400 nid=0x8445600 in Object.wait() [0xbe52f000..0xbe52fd00]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e555f0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e555f0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-18" prio=5 tid=0x08445000 nid=0x8445200 in Object.wait() [0xbe570000..0xbe570c80]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e59c38> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e59c38> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-17" prio=5 tid=0x083b2800 nid=0x83b2a00 in Object.wait() [0xbe633000..0xbe633b00]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e577f8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e577f8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-16" prio=5 tid=0x083daa00 nid=0x83dac00 in Object.wait() [0xbe737000..0xbe737d00]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e4a1f8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e4a1f8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-15" prio=5 tid=0x083da600 nid=0x83da800 in Object.wait() [0xbe778000..0xbe778c80]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e32b60> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e32b60> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-14" prio=5 tid=0x082e3a00 nid=0x82e3c00 in Object.wait() [0xbe83b000..0xbe83bb00]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e3d100> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e3d100> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-13" prio=5 tid=0x082e3600 nid=0x82e3800 in Object.wait() [0xbe87c000..0xbe87ca80]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e53358> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e53358> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-12" prio=5 tid=0x082e3200 nid=0x82e3400 in Object.wait() [0xbe8bd000..0xbe8bdc00]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e41620> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e41620> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-11" prio=5 tid=0x083b8e00 nid=0x824bc00 in Object.wait() [0xbee12000..0xbee12c80]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e30358> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e30358> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-10" prio=5 tid=0x083b8800 nid=0x83b8a00 in Object.wait() [0xbe8fe000..0xbe8fea80]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e34f58> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e34f58> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-9" prio=5 tid=0x083b8400 nid=0x83b8600 in Object.wait() [0xbe93f000..0xbe93fc00]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e37350> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e37350> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-8" prio=5 tid=0x08293800 nid=0x8293a00 in Object.wait() [0xbea02000..0xbea02c80]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e50818> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e50818> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-7" prio=5 tid=0x08293400 nid=0x8293600 in Object.wait() [0xbea43000..0xbea43a00]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e47b00> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e47b00> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-6" prio=5 tid=0x08266600 nid=0x8302800 in Object.wait() [0xbec0a000..0xbec0ac80]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e4c5a0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e4c5a0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-5" prio=5 tid=0x0827d200 nid=0x8259a00 in Object.wait() [0xbec8c000..0xbec8c980]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e4e4e8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e4e4e8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"Scheduler-Worker-10" prio=5 tid=0x0824b800 nid=0x824ba00 in Object.wait() [0xbee53000..0xbee53b80]
at java.lang.Object.wait(Native Method)
- waiting on <0x329a5b10> (a java.lang.Object)
at java.lang.Object.wait(Object.java:474)
at EDU.oswego.cs.dl.util.concurrent.LinkedQueue.take(Unknown Source)
- locked <0x329a5b10> (a java.lang.Object)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"Scheduler-Worker-9" prio=5 tid=0x08266a00 nid=0x824b000 in Object.wait() [0xbee94000..0xbee94d00]
at java.lang.Object.wait(Native Method)
- waiting on <0x329a5b10> (a java.lang.Object)
at java.lang.Object.wait(Object.java:474)
at EDU.oswego.cs.dl.util.concurrent.LinkedQueue.take(Unknown Source)
- locked <0x329a5b10> (a java.lang.Object)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"EventManager-Worker-4" daemon prio=5 tid=0x08223400 nid=0x8223600 in Object.wait() [0xbef16000..0xbef16a00]
at java.lang.Object.wait(Native Method)
- waiting on <0x329df880> (a org.exolab.jms.common.util.FifoQueue)
at java.lang.Object.wait(Object.java:474)
at org.exolab.jms.common.util.FifoQueue.waitWhileEmpty(FifoQueue.java:274)
- locked <0x329df880> (a org.exolab.jms.common.util.FifoQueue)
at org.exolab.jms.common.util.FifoQueue.get(FifoQueue.java:191)
- locked <0x329df880> (a org.exolab.jms.common.util.FifoQueue)
at org.exolab.jms.common.threads.ThreadPoolWorker.runWork(ThreadPoolWorker.java:175)
at org.exolab.jms.common.threads.ThreadPoolWorker.access$000(ThreadPoolWorker.java:64)
at org.exolab.jms.common.threads.ThreadPoolWorker$1.run(ThreadPoolWorker.java:119)
at java.lang.Thread.run(Thread.java:595)
"EventManager-Worker-3" daemon prio=5 tid=0x08223000 nid=0x8223200 in Object.wait() [0xbef57000..0xbef57980]
at java.lang.Object.wait(Native Method)
- waiting on <0x329df900> (a org.exolab.jms.common.util.FifoQueue)
at java.lang.Object.wait(Object.java:474)
at org.exolab.jms.common.util.FifoQueue.waitWhileEmpty(FifoQueue.java:274)
- locked <0x329df900> (a org.exolab.jms.common.util.FifoQueue)
at org.exolab.jms.common.util.FifoQueue.get(FifoQueue.java:191)
- locked <0x329df900> (a org.exolab.jms.common.util.FifoQueue)
at org.exolab.jms.common.threads.ThreadPoolWorker.runWork(ThreadPoolWorker.java:175)
at org.exolab.jms.common.threads.ThreadPoolWorker.access$000(ThreadPoolWorker.java:64)
at org.exolab.jms.common.threads.ThreadPoolWorker$1.run(ThreadPoolWorker.java:119)
at java.lang.Thread.run(Thread.java:595)
"EventManager-Worker-2" daemon prio=5 tid=0x085efc00 nid=0x85efe00 in Object.wait() [0xbef98000..0xbef98b00]
at java.lang.Object.wait(Native Method)
- waiting on <0x329df980> (a org.exolab.jms.common.util.FifoQueue)
at java.lang.Object.wait(Object.java:474)
at org.exolab.jms.common.util.FifoQueue.waitWhileEmpty(FifoQueue.java:274)
- locked <0x329df980> (a org.exolab.jms.common.util.FifoQueue)
at org.exolab.jms.common.util.FifoQueue.get(FifoQueue.java:191)
- locked <0x329df980> (a org.exolab.jms.common.util.FifoQueue)
at org.exolab.jms.common.threads.ThreadPoolWorker.runWork(ThreadPoolWorker.java:175)
at org.exolab.jms.common.threads.ThreadPoolWorker.access$000(ThreadPoolWorker.java:64)
at org.exolab.jms.common.threads.ThreadPoolWorker$1.run(ThreadPoolWorker.java:119)
at java.lang.Thread.run(Thread.java:595)
"EventManager-Worker-1" daemon prio=5 tid=0x085ef800 nid=0x85efa00 in Object.wait() [0xbefd9000..0xbefd9a80]
at java.lang.Object.wait(Native Method)
- waiting on <0x329dfd08> (a org.exolab.jms.common.util.FifoQueue)
at java.lang.Object.wait(Object.java:474)
at org.exolab.jms.common.util.FifoQueue.waitWhileEmpty(FifoQueue.java:274)
- locked <0x329dfd08> (a org.exolab.jms.common.util.FifoQueue)
at org.exolab.jms.common.util.FifoQueue.get(FifoQueue.java:191)
- locked <0x329dfd08> (a org.exolab.jms.common.util.FifoQueue)
at org.exolab.jms.common.threads.ThreadPoolWorker.runWork(ThreadPoolWorker.java:175)
at org.exolab.jms.common.threads.ThreadPoolWorker.access$000(ThreadPoolWorker.java:64)
at org.exolab.jms.common.threads.ThreadPoolWorker$1.run(ThreadPoolWorker.java:119)
at java.lang.Thread.run(Thread.java:595)
"EventManager-Worker-0" daemon prio=5 tid=0x085ef400 nid=0x85ef600 in Object.wait() [0xbf01a000..0xbf01ac00]
at java.lang.Object.wait(Native Method)
- waiting on <0x329dfda8> (a org.exolab.jms.common.util.FifoQueue)
at java.lang.Object.wait(Object.java:474)
at org.exolab.jms.common.util.FifoQueue.waitWhileEmpty(FifoQueue.java:274)
- locked <0x329dfda8> (a org.exolab.jms.common.util.FifoQueue)
at org.exolab.jms.common.util.FifoQueue.get(FifoQueue.java:191)
- locked <0x329dfda8> (a org.exolab.jms.common.util.FifoQueue)
at org.exolab.jms.common.threads.ThreadPoolWorker.runWork(ThreadPoolWorker.java:175)
at org.exolab.jms.common.threads.ThreadPoolWorker.access$000(ThreadPoolWorker.java:64)
at org.exolab.jms.common.threads.ThreadPoolWorker$1.run(ThreadPoolWorker.java:119)
at java.lang.Thread.run(Thread.java:595)
"Scheduler-Worker-8" prio=5 tid=0x085ef000 nid=0x85ef200 in Object.wait() [0xbf05b000..0xbf05bb80]
at java.lang.Object.wait(Native Method)
- waiting on <0x329a5b10> (a java.lang.Object)
at java.lang.Object.wait(Object.java:474)
at EDU.oswego.cs.dl.util.concurrent.LinkedQueue.take(Unknown Source)
- locked <0x329a5b10> (a java.lang.Object)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"Scheduler-Worker-7" prio=5 tid=0x0851ac00 nid=0x851ae00 in Object.wait() [0xbf09c000..0xbf09cd00]
at java.lang.Object.wait(Native Method)
- waiting on <0x329a5b10> (a java.lang.Object)
at java.lang.Object.wait(Object.java:474)
at EDU.oswego.cs.dl.util.concurrent.LinkedQueue.take(Unknown Source)
- locked <0x329a5b10> (a java.lang.Object)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"Scheduler-Worker-6" prio=5 tid=0x0851a600 nid=0x851a800 in Object.wait() [0xbf0dd000..0xbf0ddc80]
at java.lang.Object.wait(Native Method)
- waiting on <0x329a5b10> (a java.lang.Object)
at java.lang.Object.wait(Object.java:474)
at EDU.oswego.cs.dl.util.concurrent.LinkedQueue.take(Unknown Source)
- locked <0x329a5b10> (a java.lang.Object)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"Scheduler-Worker-5" prio=5 tid=0x0851a200 nid=0x851a400 in Object.wait() [0xbf11e000..0xbf11ea00]
at java.lang.Object.wait(Native Method)
- waiting on <0x329a5b10> (a java.lang.Object)
at java.lang.Object.wait(Object.java:474)
at EDU.oswego.cs.dl.util.concurrent.LinkedQueue.take(Unknown Source)
- locked <0x329a5b10> (a java.lang.Object)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"Scheduler-Worker-4" prio=5 tid=0x08442e00 nid=0x851a000 in Object.wait() [0xbf15f000..0xbf15f980]
at java.lang.Object.wait(Native Method)
- waiting on <0x329a5b10> (a java.lang.Object)
at java.lang.Object.wait(Object.java:474)
at EDU.oswego.cs.dl.util.concurrent.LinkedQueue.take(Unknown Source)
- locked <0x329a5b10> (a java.lang.Object)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"Scheduler-Worker-3" prio=5 tid=0x08442a00 nid=0x8442c00 in Object.wait() [0xbf1a0000..0xbf1a0b00]
at java.lang.Object.wait(Native Method)
- waiting on <0x329a5b10> (a java.lang.Object)
at java.lang.Object.wait(Object.java:474)
at EDU.oswego.cs.dl.util.concurrent.LinkedQueue.take(Unknown Source)
- locked <0x329a5b10> (a java.lang.Object)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"Scheduler-Worker-2" prio=5 tid=0x08442600 nid=0x8442800 in Object.wait() [0xbf1e1000..0xbf1e1a80]
at java.lang.Object.wait(Native Method)
- waiting on <0x329a5b10> (a java.lang.Object)
at java.lang.Object.wait(Object.java:474)
at EDU.oswego.cs.dl.util.concurrent.LinkedQueue.take(Unknown Source)
- locked <0x329a5b10> (a java.lang.Object)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"Scheduler-Worker-1" prio=5 tid=0x08442200 nid=0x8442400 in Object.wait() [0xbf222000..0xbf222c00]
at java.lang.Object.wait(Native Method)
- waiting on <0x329a5b10> (a java.lang.Object)
at java.lang.Object.wait(Object.java:474)
at EDU.oswego.cs.dl.util.concurrent.LinkedQueue.take(Unknown Source)
- locked <0x329a5b10> (a java.lang.Object)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-4" prio=5 tid=0x08161e00 nid=0x8442000 in Object.wait() [0xbf263000..0xbf263b80]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e3f3c0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e3f3c0> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-3" prio=5 tid=0x08161600 nid=0x8161800 in Object.wait() [0xbf2e5000..0xbf2e5c80]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e43758> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e43758> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-2" prio=5 tid=0x08421e00 nid=0x8161000 in Object.wait() [0xbf367000..0xbf367980]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e45ba8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e45ba8> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"ORB-Worker-1" prio=5 tid=0x08421a00 nid=0x8421c00 in Object.wait() [0xbf3a8000..0xbf3a8b00]
at java.lang.Object.wait(Native Method)
- waiting on <0x40e3ab70> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.SynchronousChannel.poll(Unknown Source)
- locked <0x40e3ab70> (a EDU.oswego.cs.dl.util.concurrent.LinkedNode)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor.getTask(Unknown Source)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
"DestroyJavaVM" prio=5 tid=0x0805cc00 nid=0x805c000 waiting on condition [0x00000000..0xbfbfda80]
"tcp://server.ext.addr:7862/[acceptor]" prio=5 tid=0x0823de00 nid=0x8421000 runnable [0xbf4ac000..0xbf4acd00]
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)
- locked <0x329b4250> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:450)
at java.net.ServerSocket.accept(ServerSocket.java:421)
at org.exolab.jms.net.socket.SocketManagedConnectionAcceptor$Dispatcher.run(SocketManagedConnectionAcceptor.java:309)
"LeaseManager" prio=5 tid=0x0823d800 nid=0x823da00 in Object.wait() [0xbf4ed000..0xbf4edc80]
at java.lang.Object.wait(Native Method)
- waiting on <0x3291eb40> (a java.lang.Object)
at java.lang.Object.wait(Object.java:474)
at org.exolab.jms.lease.LeaseManager.run(LeaseManager.java:171)
- locked <0x3291eb40> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:595)
"Thread-0" daemon prio=5 tid=0x0823d200 nid=0x823d400 waiting on condition [0xbf52e000..0xbf52ea00]
at java.lang.Thread.sleep(Native Method)
at org.apache.commons.pool.impl.GenericObjectPool$Evictor.run(GenericObjectPool.java:1080)
at java.lang.Thread.run(Thread.java:595)
"BasicEventManager" prio=5 tid=0x0827de00 nid=0x823d000 in Object.wait() [0xbf56f000..0xbf56f980]
at java.lang.Object.wait(Native Method)
- waiting on <0x329a5e70> (a java.lang.Object)
at org.exolab.jms.events.BasicEventManager.run(BasicEventManager.java:250)
- locked <0x329a5e70> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:595)
"Clock Daemon" daemon prio=10 tid=0x0827d600 nid=0x827dc00 waiting on condition [0xbf5b0000..0xbf5b0b00]
at java.lang.Thread.sleep(Native Method)
at org.exolab.jms.common.uuid.Clock.run(Clock.java:210)
"Low Memory Detector" daemon prio=5 tid=0x081d7800 nid=0x81d7a00 runnable [0x00000000..0x00000000]
"CompilerThread1" daemon prio=9 tid=0x081d7400 nid=0x81d7600 waiting on condition [0x00000000..0xbf672d48]
"CompilerThread0" daemon prio=9 tid=0x081d7000 nid=0x81d7200 waiting on condition [0x00000000..0xbf6b3ec8]
"AdapterThread" daemon prio=9 tid=0x081b3c00 nid=0x81b3e00 waiting on condition [0x00000000..0x00000000]
"Signal Dispatcher" daemon prio=9 tid=0x081b3800 nid=0x81b3a00 waiting on condition [0x00000000..0x00000000]
"Finalizer" daemon prio=8 tid=0x081b3200 nid=0x81b3400 in Object.wait() [0xbf777000..0xbf777980]
at java.lang.Object.wait(Native Method)
- waiting on <0x3296f6d0> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
- locked <0x3296f6d0> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
"Reference Handler" daemon prio=10 tid=0x08069e00 nid=0x81b3000 in Object.wait() [0xbf7b8000..0xbf7b8b00]
at java.lang.Object.wait(Native Method)
- waiting on <0x32978048> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:474)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
- locked <0x32978048> (a java.lang.ref.Reference$Lock)
"VM Thread" prio=9 tid=0x08143f00 nid=0x8069c00 runnable
"GC task thread#0 (ParallelGC)" prio=5 tid=0x080ee000 nid=0x8069200 runnable
"GC task thread#1 (ParallelGC)" prio=5 tid=0x080ee500 nid=0x8069400 runnable
"GC task thread#2 (ParallelGC)" prio=5 tid=0x080ee600 nid=0x8069600 runnable
"GC task thread#3 (ParallelGC)" prio=5 tid=0x080ee700 nid=0x8069800 runnable
"VM Periodic Task Thread" prio=9 tid=0x08056e00 nid=0x81d7e00 waiting on condition
Logged In: YES
user_id=1120792
Originator: NO
OpenJMS log contains lots of
06:49:09.906 DEBUG [tcp://1.2.3.4:7431/[server]-Multiplexer] - Cleaning up active sessions
06:49:09.908 DEBUG [tcp://1.2.3.4:7428/[server]-Multiplexer] - Detected disconnection of caller=tcp://1.2.3.4:7428/. Cleaning up resources
06:49:09.909 DEBUG [tcp://1.2.3.4:7428/[server]-Multiplexer] - Cleaning up active sessions
06:49:09.921 DEBUG [tcp://1.2.3.4:7426/[server]-Multiplexer] - Detected disconnection of caller=tcp://1.2.3.4:7426/. Cleaning up resources
Logged In: YES
user_id=1120792
Originator: NO
**************************
Client stack dump upon a lockup:
**************************
Full thread dump Java HotSpot(TM) Client VM (1.5.0_10-b03 mixed mode, sharing):
"ManagedConnectionReaper1" prio=6 tid=0x02cdb958 nid=0xa9c8 in Object.wait() [0x02f5f000..0x02f5fcec]
at java.lang.Object.wait(Native Method)
- waiting on <0x22f7e020> (a EDU.oswego.cs.dl.util.concurrent.ClockDaemon)
at EDU.oswego.cs.dl.util.concurrent.ClockDaemon.nextTask(Unknown Source)
- locked <0x22f7e020> (a EDU.oswego.cs.dl.util.concurrent.ClockDaemon)
at EDU.oswego.cs.dl.util.concurrent.ClockDaemon$RunLoop.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
"tcp://1.2.3.4:7862/[client]-Multiplexer" prio=6 tid=0x02c8ae10 nid=0xa9c4 runnable [0x02f1f000..0x02f1fd6c]
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(Unknown Source)
at java.net.SocketInputStream.read(Unknown Source)
at java.io.DataInputStream.readByte(Unknown Source)
at org.exolab.jms.net.multiplexer.Multiplexer.multiplex(Multiplexer.java:525)
at org.exolab.jms.net.multiplexer.Multiplexer.run(Multiplexer.java:181)
at java.lang.Thread.run(Unknown Source)
"Thread-0" prio=6 tid=0x00aac008 nid=0xa9c0 in Object.wait() [0x02e8f000..0x02e8f9ec]
at java.lang.Object.wait(Native Method)
- waiting on <0x22f937a8> (a java.lang.Object)
at java.lang.Object.wait(Unknown Source)
at org.exolab.jms.net.multiplexer.MultiplexInputStream.read(MultiplexInputStream.java:232)
- locked <0x22f937a8> (a java.lang.Object)
at java.io.ObjectInputStream$PeekInputStream.read(Unknown Source)
at java.io.ObjectInputStream$PeekInputStream.readFully(Unknown Source)
at java.io.ObjectInputStream$BlockDataInputStream.readShort(Unknown Source)
at java.io.ObjectInputStream.readStreamHeader(Unknown Source)
at java.io.ObjectInputStream.<init>(Unknown Source)
at org.exolab.jms.net.multiplexer.Channel.invoke(Channel.java:168)
at org.exolab.jms.net.multiplexer.MultiplexedManagedConnection.invoke(MultiplexedManagedConnection.java:344)
at org.exolab.jms.net.multiplexer.MultiplexedConnection.invoke(MultiplexedConnection.java:86)
at org.exolab.jms.net.connector.ManagedConnectionHandle$ConnectionHandle.invoke(ManagedConnectionHandle.java:263)
at org.exolab.jms.net.orb.UnicastDelegate.invoke(UnicastDelegate.java:153)
at org.exolab.jms.net.proxy.Proxy.invoke(Proxy.java:102)
at org.exolab.jms.server.net.RemoteServerSession__Proxy.setMessageListener(RemoteServerSession__Proxy.java:418)
at org.exolab.jms.client.net.JmsSessionStubImpl.<init>(JmsSessionStubImpl.java:111)
at org.exolab.jms.client.net.JmsConnectionStubImpl.createSession(JmsConnectionStubImpl.java:171)
at org.exolab.jms.client.JmsSession.<init>(JmsSession.java:214)
at org.exolab.jms.client.JmsConnection.createSession(JmsConnection.java:458)
at org.pythomnic.java.jmshook.JMSHookAdapter.openProducerSession(JMSHookAdapter.java:212)
at org.pythomnic.java.jmshook.JMSHookAdapter.run(JMSHookAdapter.java:801)
"Low Memory Detector" daemon prio=6 tid=0x00a71de8 nid=0xa9b4 runnable [0x00000000..0x00000000]
"CompilerThread0" daemon prio=10 tid=0x00a70af0 nid=0xa9b0 waiting on condition [0x00000000..0x02bcf84c]
"Signal Dispatcher" daemon prio=10 tid=0x00a6fd70 nid=0xa9ac waiting on condition [0x00000000..0x00000000]
"Finalizer" daemon prio=8 tid=0x00a42d58 nid=0xa9a8 in Object.wait() [0x02b4f000..0x02b4fc6c]
at java.lang.Object.wait(Native Method)
- waiting on <0x22f69988> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(Unknown Source)
- locked <0x22f69988> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(Unknown Source)
at java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source)
"Reference Handler" daemon prio=10 tid=0x0003fb30 nid=0xa9a4 in Object.wait() [0x02b0f000..0x02b0fcec]
at java.lang.Object.wait(Native Method)
- waiting on <0x22f69670> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Unknown Source)
at java.lang.ref.Reference$ReferenceHandler.run(Unknown Source)
- locked <0x22f69670> (a java.lang.ref.Reference$Lock)
"main" prio=6 tid=0x000369a0 nid=0xa99c in Object.wait() [0x0007f000..0x0007fc3c]
at java.lang.Object.wait(Native Method)
- waiting on <0x22f69678> (a org.pythomnic.java.jmshook.JMSHookAdapter)
at java.lang.Thread.join(Unknown Source)
- locked <0x22f69678> (a org.pythomnic.java.jmshook.JMSHookAdapter)
at java.lang.Thread.join(Unknown Source)
at org.pythomnic.java.jmshook.JMSHook.main(JMSHook.java:135)
"VM Thread" prio=10 tid=0x00a40ed8 nid=0xa9a0 runnable
"VM Periodic Task Thread" prio=10 tid=0x00a73040 nid=0xa9b8 waiting on condition
Logged In: YES
user_id=1706342
Originator: NO
Have experienced similar behaviour. Although when calling createSession(false, Session.AUTO_ACKNOWLEDGE)
we noticed a block-time of about 30 sec. - 2 minutes. That you are blocked "forever" could be caused
by the fact that your message producer has not set a value for setTimeToLive(value); The default value
is zero and means forever. I suggest that you try to set the setTimeToLive to a value of 1000 or something
like that and check what happens...
Logged In: YES
user_id=557161
Originator: NO
Tentatively fixed. The stack dumps aren't conclusive, but changes have been made to connection pool to perform asynchronous management of connections. Previously, it performed synchronous connection management. In some instances one non-responsive connection could look the pool.
Fixed for 0.7.7-beta-1 release, a snapshot of which is temporarily available at http://openjms.sf.net/openjms-0.7.7-beta-1-SNAPSHOT.zip