[Design of Messaging on JBoss (Messaging/JBoss)] - Re: PingStressTests hanging
by timfox
Here's the full dump for completeness:
| Full thread dump Java HotSpot(TM) Server VM (1.5.0_13-b05 mixed mode):
|
| "New I/O client worker #202-1" daemon prio=1 tid=0x0885c330 nid=0x48ba runnable [0x8a16f000..0x8a16fdc0]
| at sun.nio.ch.PollArrayWrapper.poll0(Native Method)
| at sun.nio.ch.PollArrayWrapper.poll(PollArrayWrapper.java:100)
| at sun.nio.ch.PollSelectorImpl.doSelect(PollSelectorImpl.java:56)
| at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
| - locked <0x91ab37a0> (a sun.nio.ch.Util$1)
| - locked <0x91ab3790> (a java.util.Collections$UnmodifiableSet)
| - locked <0x91ab33e0> (a sun.nio.ch.PollSelectorImpl)
| at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
| at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:158)
| at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:72)
| at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
| at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
| at java.lang.Thread.run(Thread.java:595)
|
| "New I/O server worker #9-2" daemon prio=1 tid=0x083af868 nid=0x4898 runnable [0x89fec000..0x89fecec0]
| at sun.nio.ch.PollArrayWrapper.poll0(Native Method)
| at sun.nio.ch.PollArrayWrapper.poll(PollArrayWrapper.java:100)
| at sun.nio.ch.PollSelectorImpl.doSelect(PollSelectorImpl.java:56)
| at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
| - locked <0x91aa4ee0> (a sun.nio.ch.Util$1)
| - locked <0x91aa4ed0> (a java.util.Collections$UnmodifiableSet)
| - locked <0x91aa4cf0> (a sun.nio.ch.PollSelectorImpl)
| at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
| at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:158)
| at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:72)
| at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
| at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
| at java.lang.Thread.run(Thread.java:595)
|
| "Thread-0 (group:jbm-netty-acceptor-worker-threads-2547660)" daemon prio=1 tid=0x0849d6f8 nid=0x4893 waiting on condition [0x8bcfe000..0x8bcff140]
| at sun.misc.Unsafe.park(Native Method)
| at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:146)
| at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireNanos(AbstractQueuedSynchronizer.java:807)
| at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireNanos(AbstractQueuedSynchronizer.java:1122)
| at java.util.concurrent.SynchronousQueue$Node.waitForPut(SynchronousQueue.java:291)
| at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:443)
| at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:475)
| at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:674)
| at java.lang.Thread.run(Thread.java:595)
|
| "LocalThread i = 16" prio=1 tid=0x8bf68528 nid=0x4884 waiting on condition [0x8b9fc000..0x8b9fd0c0]
| at sun.misc.Unsafe.park(Native Method)
| at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:146)
| at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1879)
| at java.util.concurrent.ThreadPoolExecutor.awaitTermination(ThreadPoolExecutor.java:1028)
| at org.jboss.messaging.integration.transports.netty.NettyConnector.close(NettyConnector.java:363)
| - locked <0x91ab5140> (a org.jboss.messaging.integration.transports.netty.NettyConnector)
| at org.jboss.messaging.core.client.impl.ConnectionManagerImpl.checkCloseConnections(ConnectionManagerImpl.java:774)
| at org.jboss.messaging.core.client.impl.ConnectionManagerImpl.returnConnection(ConnectionManagerImpl.java:865)
| at org.jboss.messaging.core.client.impl.ConnectionManagerImpl.removeSession(ConnectionManagerImpl.java:400)
| - locked <0x91ab5358> (a java.lang.Object)
| - locked <0x91ab5350> (a java.lang.Object)
| at org.jboss.messaging.core.client.impl.ClientSessionImpl.doCleanup(ClientSessionImpl.java:1313)
| at org.jboss.messaging.core.client.impl.ClientSessionImpl.close(ClientSessionImpl.java:761)
| at org.jboss.messaging.tests.stress.remote.PingStressTest$1LocalThread.run(PingStressTest.java:242)
|
| "Timer-17" daemon prio=1 tid=0x8bf64e68 nid=0x4873 in Object.wait() [0x8bafe000..0x8baff140]
| at java.lang.Object.wait(Native Method)
| - waiting on <0x91ab9350> (a java.util.TaskQueue)
| at java.util.TimerThread.mainLoop(Timer.java:509)
| - locked <0x91ab9350> (a java.util.TaskQueue)
| at java.util.TimerThread.run(Timer.java:462)
|
| "New I/O server boss #9 (channelId: 3075861, /127.0.0.1:5445)" daemon prio=1 tid=0x8bf40ef8 nid=0x4872 runnable [0x8a06d000..0x8a06ddc0]
| at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
| at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:145)
| - locked <0x91aa98a0> (a java.lang.Object)
| at org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink$Boss.run(NioServerSocketPipelineSink.java:204)
| at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:72)
| at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
| at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
| at java.lang.Thread.run(Thread.java:595)
|
| "Timer-16" daemon prio=1 tid=0x8bf6bc38 nid=0x4871 in Object.wait() [0x8befe000..0x8befee40]
| at java.lang.Object.wait(Native Method)
| - waiting on <0x91aa0db8> (a java.util.TaskQueue)
| at java.util.TimerThread.mainLoop(Timer.java:509)
| - locked <0x91aa0db8> (a java.util.TaskQueue)
| at java.util.TimerThread.run(Timer.java:462)
|
| "Thread-0 (group:JBM-scheduled-threads-32455885)" daemon prio=1 tid=0x8bf41ce8 nid=0x4870 waiting on condition [0x8c47d000..0x8c47dec0]
| at sun.misc.Unsafe.park(Native Method)
| at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:146)
| at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1879)
| at java.util.concurrent.DelayQueue.take(DelayQueue.java:135)
| at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:504)
| at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:497)
| at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:470)
| at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:674)
| at java.lang.Thread.run(Thread.java:595)
|
| "Thread-4 (group:jbm-pinger-threads-11110706)" daemon prio=1 tid=0x08766a78 nid=0x45ab waiting on condition [0x899e0000..0x899e0f40]
| at sun.misc.Unsafe.park(Native Method)
| at java.util.concurrent.locks.LockSupport.park(LockSupport.java:118)
| at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1841)
| at java.util.concurrent.DelayQueue.take(DelayQueue.java:131)
| at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:504)
| at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:497)
| at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:470)
| at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:674)
| at java.lang.Thread.run(Thread.java:595)
|
| "Thread-3 (group:jbm-pinger-threads-11110706)" daemon prio=1 tid=0x08763950 nid=0x45a9 waiting on condition [0x89a61000..0x89a62040]
| at sun.misc.Unsafe.park(Native Method)
| at java.util.concurrent.locks.LockSupport.park(LockSupport.java:118)
| at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1841)
| at java.util.concurrent.DelayQueue.take(DelayQueue.java:131)
| at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:504)
| at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:497)
| at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:470)
| at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:674)
| at java.lang.Thread.run(Thread.java:595)
|
| "Thread-2 (group:jbm-pinger-threads-11110706)" daemon prio=1 tid=0x0869b8e8 nid=0x45a7 waiting on condition [0x89b63000..0x89b64140]
| at sun.misc.Unsafe.park(Native Method)
| at java.util.concurrent.locks.LockSupport.park(LockSupport.java:118)
| at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1841)
| at java.util.concurrent.DelayQueue.take(DelayQueue.java:131)
| at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:504)
| at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:497)
| at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:470)
| at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:674)
| at java.lang.Thread.run(Thread.java:595)
|
| "Thread-1 (group:jbm-pinger-threads-11110706)" daemon prio=1 tid=0x8bf8b988 nid=0x45a5 waiting for monitor entry [0x89c65000..0x89c65e40]
| at org.jboss.messaging.core.client.impl.ConnectionManagerImpl.failover(ConnectionManagerImpl.java:506)
| - waiting to lock <0x91ab5358> (a java.lang.Object)
| at org.jboss.messaging.core.client.impl.ConnectionManagerImpl.connectionFailed(ConnectionManagerImpl.java:424)
| at org.jboss.messaging.core.remoting.impl.RemotingConnectionImpl.callListeners(RemotingConnectionImpl.java:530)
| at org.jboss.messaging.core.remoting.impl.RemotingConnectionImpl.fail(RemotingConnectionImpl.java:421)
| at org.jboss.messaging.core.remoting.impl.RemotingConnectionImpl$Pinger.run(RemotingConnectionImpl.java:1549)
| - locked <0x91ab5648> (a org.jboss.messaging.core.remoting.impl.RemotingConnectionImpl$Pinger)
| at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:417)
| at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:280)
| at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:135)
| at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:65)
| at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:142)
| at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:166)
| at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
| at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
| at java.lang.Thread.run(Thread.java:595)
|
| "Thread-0 (group:jbm-pinger-threads-11110706)" daemon prio=1 tid=0x8bf6e2c0 nid=0x45a0 waiting on condition [0x89eea000..0x89eeb0c0]
| at sun.misc.Unsafe.park(Native Method)
| at java.util.concurrent.locks.LockSupport.park(LockSupport.java:118)
| at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1841)
| at java.util.concurrent.DelayQueue.take(DelayQueue.java:131)
| at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:504)
| at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:497)
| at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:470)
| at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:674)
| at java.lang.Thread.run(Thread.java:595)
|
| "ReaderThread" prio=1 tid=0x8c50f3d0 nid=0x4566 runnable [0x8c4fe000..0x8c4fedc0]
| at java.net.SocketInputStream.socketRead0(Native Method)
| at java.net.SocketInputStream.read(SocketInputStream.java:129)
| at sun.nio.cs.StreamDecoder$CharsetSD.readBytes(StreamDecoder.java:411)
| at sun.nio.cs.StreamDecoder$CharsetSD.implRead(StreamDecoder.java:453)
| at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:183)
| - locked <0x919fab30> (a java.io.InputStreamReader)
| at java.io.InputStreamReader.read(InputStreamReader.java:167)
| at java.io.BufferedReader.fill(BufferedReader.java:136)
| at java.io.BufferedReader.readLine(BufferedReader.java:299)
| - locked <0x919fab30> (a java.io.InputStreamReader)
| at java.io.BufferedReader.readLine(BufferedReader.java:362)
| at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner$ReaderThread.run(RemoteTestRunner.java:140)
|
| "Low Memory Detector" daemon prio=1 tid=0x08115ea8 nid=0x4564 runnable [0x00000000..0x00000000]
|
| "CompilerThread1" daemon prio=1 tid=0x081149d0 nid=0x4563 waiting on condition [0x00000000..0x8d271168]
|
| "CompilerThread0" daemon prio=1 tid=0x08113920 nid=0x4562 waiting on condition [0x00000000..0x8d2f2128]
|
| "AdapterThread" daemon prio=1 tid=0x081127a0 nid=0x4561 waiting on condition [0x00000000..0x00000000]
|
| "Signal Dispatcher" daemon prio=1 tid=0x081118d0 nid=0x4560 waiting on condition [0x00000000..0x00000000]
|
| "Finalizer" daemon prio=1 tid=0x081064c0 nid=0x455e in Object.wait() [0x8d4bb000..0x8d4bc140]
| at java.lang.Object.wait(Native Method)
| - waiting on <0x91907370> (a java.lang.ref.ReferenceQueue$Lock)
| at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
| - locked <0x91907370> (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=1 tid=0x08105f08 nid=0x455d in Object.wait() [0x8d53c000..0x8d53cdc0]
| at java.lang.Object.wait(Native Method)
| - waiting on <0x9197f6c8> (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 <0x9197f6c8> (a java.lang.ref.Reference$Lock)
|
| "main" prio=1 tid=0x0805fd70 nid=0x4554 in Object.wait() [0xbfd53000..0xbfd53bb8]
| at java.lang.Object.wait(Native Method)
| - waiting on <0x91aa3ce8> (a org.jboss.messaging.tests.stress.remote.PingStressTest$1LocalThread)
| at java.lang.Thread.join(Thread.java:1095)
| - locked <0x91aa3ce8> (a org.jboss.messaging.tests.stress.remote.PingStressTest$1LocalThread)
| at java.lang.Thread.join(Thread.java:1148)
| at org.jboss.messaging.tests.stress.remote.PingStressTest.internalTest(PingStressTest.java:266)
| at org.jboss.messaging.tests.stress.remote.PingStressTest.testMultiThreadOpenAndCloses(PingStressTest.java:111)
| 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 junit.framework.TestCase.runTest(TestCase.java:164)
| at junit.framework.TestCase.runBare(TestCase.java:130)
| at junit.framework.TestResult$1.protect(TestResult.java:106)
| at junit.framework.TestResult.runProtected(TestResult.java:124)
| at junit.framework.TestResult.run(TestResult.java:109)
| at junit.framework.TestCase.run(TestCase.java:120)
| at junit.framework.TestSuite.runTest(TestSuite.java:230)
| at junit.framework.TestSuite.run(TestSuite.java:225)
| at org.eclipse.jdt.internal.junit.runner.junit3.JUnit3TestReference.run(JUnit3TestReference.java:130)
| at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
| at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:460)
| at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:673)
| at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:386)
| at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:196)
|
| "VM Thread" prio=1 tid=0x081039f0 nid=0x455c runnable
|
| "GC task thread#0 (ParallelGC)" prio=1 tid=0x0807a7b8 nid=0x455a runnable
|
| "GC task thread#1 (ParallelGC)" prio=1 tid=0x0807b408 nid=0x455b runnable
|
| "VM Periodic Task Thread" prio=1 tid=0x08071d58 nid=0x4565 waiting on condition
|
You can see we have a thread awaiting termination of the netty worker thread pool.
There are also two netty worker threads and one netty acceptor thread in the dump.
Both netty worker threads are just sitting on a select:
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
They're not doing anything special and the thread that calls awaitTermination is not a netty worker thread.
My hunch is there is a race condition in netty, so when shutdownNow() is called, the thread is interrupted but it doesn't exit the loop properly.
This can be easily replicated by running PingStressTest until it hangs and doing a killall -3 to get the dump.
View the original post : http://www.jboss.org/index.html?module=bb&op=viewtopic&p=4215626#4215626
Reply to the post : http://www.jboss.org/index.html?module=bb&op=posting&mode=reply&p=4215626
17 years, 1 month