Kevin Earls created AMQ-4978: -------------------------------- Summary: JoramJmsNioTest hangs intermittently Key: AMQ-4978 URL: https://issues.apache.org/jira/browse/AMQ-4978 Project: ActiveMQ Issue Type: Bug Components: Test Cases Reporter: Kevin Earls Assignee: Kevin Earls Priority: Minor
The JoramJmsNioTest hangs intermittently, particularly on CI nodes. I'll add a stack trace. This is most likely fixed by QPID 0.26. Re-test once that is released. $ jstack 7157 2014-01-20 10:14:31 Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.45-b08 mixed mode): "Attach Listener" daemon prio=10 tid=0x00007f09f400d800 nid=0x1ca9 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "ActiveMQ BrokerService[localhost] Task-2" daemon prio=10 tid=0x00007f09e4029000 nid=0x1c97 waiting on condition [0x00007f0a1179d000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000eebf1108> (a java.util.concurrent.SynchronousQueue$TransferStack) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:359) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:942) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "ActiveMQ BrokerService[localhost] Task-1" daemon prio=10 tid=0x00007f09e4028800 nid=0x1c96 waiting on condition [0x00007f0a10782000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000eebf1108> (a java.util.concurrent.SynchronousQueue$TransferStack) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:359) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:942) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "ActiveMQ Transport Server: amqp+nio://localhost:0" daemon prio=10 tid=0x00007f0a1c69e800 nid=0x1c93 runnable [0x00007f0a10681000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) - locked <0x00000000eec186b0> (a sun.nio.ch.Util$2) - locked <0x00000000eec186a0> (a java.util.Collections$UnmodifiableSet) - locked <0x00000000eec18588> (a sun.nio.ch.EPollSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) at sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:121) - locked <0x00000000eead9ec8> (a java.lang.Object) at org.apache.activemq.transport.tcp.TcpTransportServer.run(TcpTransportServer.java:301) at java.lang.Thread.run(Thread.java:744) "RMI Reaper" prio=10 tid=0x00007f09e4038800 nid=0x1c90 in Object.wait() [0x00007f0a1149a000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000f0e6d6c0> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x00000000f0e6d6c0> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151) at sun.rmi.transport.ObjectTable$Reaper.run(ObjectTable.java:351) at java.lang.Thread.run(Thread.java:744) "RMI TCP Accept-1099" daemon prio=10 tid=0x00007f0a1c70e000 nid=0x1c8e runnable [0x00007f0a10984000] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398) at java.net.ServerSocket.implAccept(ServerSocket.java:530) at java.net.ServerSocket.accept(ServerSocket.java:498) at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:388) at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:360) at java.lang.Thread.run(Thread.java:744) "ActiveMQ NIO Worker 4" daemon prio=10 tid=0x00007f09ec194000 nid=0x1c33 waiting on condition [0x00007f0a1017c000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000f0e41258> (a java.util.concurrent.SynchronousQueue$TransferStack) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:359) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:942) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "ActiveMQ NIO Worker 3" daemon prio=10 tid=0x00007f09ec284000 nid=0x1c16 waiting on condition [0x00007f0a1047f000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000f0e41258> (a java.util.concurrent.SynchronousQueue$TransferStack) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:359) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:942) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "ActiveMQ NIO Worker 2" daemon prio=10 tid=0x00007f09ec250800 nid=0x1c11 waiting on condition [0x00007f0a10883000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000f0e41258> (a java.util.concurrent.SynchronousQueue$TransferStack) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:359) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:942) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "ActiveMQ NIO Worker 1" daemon prio=10 tid=0x00007f09f02b7000 nid=0x1c0e waiting on condition [0x00007f0a10b86000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000f0e41258> (a java.util.concurrent.SynchronousQueue$TransferStack) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:359) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:942) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "RMI Scheduler(0)" daemon prio=10 tid=0x00007f09e0010800 nid=0x1c09 waiting on condition [0x00007f0a10f8a000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000c5747e48> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "RMI TCP Connection(2)-10.179.133.105" daemon prio=10 tid=0x00007f09d4001000 nid=0x1c08 runnable [0x00007f0a1108b000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at java.io.BufferedInputStream.fill(BufferedInputStream.java:235) at java.io.BufferedInputStream.read(BufferedInputStream.java:254) - locked <0x00000000c5861c08> (a java.io.BufferedInputStream) at java.io.FilterInputStream.read(FilterInputStream.java:83) at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:538) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:811) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:670) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "RMI RenewClean-[10.179.133.105:40132]" daemon prio=10 tid=0x00007f09d8003800 nid=0x1c07 in Object.wait() [0x00007f0a1118c000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000c5748368> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x00000000c5748368> (a java.lang.ref.ReferenceQueue$Lock) at sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread.run(DGCClient.java:535) at java.lang.Thread.run(Thread.java:744) "RMI TCP Connection(1)-127.0.0.1" daemon prio=10 tid=0x00007f09dc001000 nid=0x1c06 runnable [0x00007f0a1128d000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at java.io.BufferedInputStream.fill(BufferedInputStream.java:235) at java.io.BufferedInputStream.read(BufferedInputStream.java:254) - locked <0x00000000c58620e8> (a java.io.BufferedInputStream) at java.io.FilterInputStream.read(FilterInputStream.java:83) at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:538) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:811) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:670) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "GC Daemon" daemon prio=10 tid=0x00007f09e0004800 nid=0x1c05 in Object.wait() [0x00007f0a11399000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000c597dc30> (a sun.misc.GC$LatencyLock) at sun.misc.GC$Daemon.run(GC.java:117) - locked <0x00000000c597dc30> (a sun.misc.GC$LatencyLock) "RMI TCP Accept-0" daemon prio=10 tid=0x00007f09e0001000 nid=0x1c03 runnable [0x00007f0a1159b000] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398) at java.net.ServerSocket.implAccept(ServerSocket.java:530) at java.net.ServerSocket.accept(ServerSocket.java:498) at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:388) at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:360) at java.lang.Thread.run(Thread.java:744) "Service Thread" daemon prio=10 tid=0x00007f0a1c117000 nid=0x1bff runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread1" daemon prio=10 tid=0x00007f0a1c115000 nid=0x1bfe waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" daemon prio=10 tid=0x00007f0a1c112000 nid=0x1bfd waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" daemon prio=10 tid=0x00007f0a1c107800 nid=0x1bfc runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" daemon prio=10 tid=0x00007f0a1c0f1000 nid=0x1bfb in Object.wait() [0x00007f0a18efd000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000f0e506b8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x00000000f0e506b8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189) "Reference Handler" daemon prio=10 tid=0x00007f0a1c0ed000 nid=0x1bfa in Object.wait() [0x00007f0a18ffe000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000c5862828> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:503) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) - locked <0x00000000c5862828> (a java.lang.ref.Reference$Lock) "main" prio=10 tid=0x00007f0a1c008800 nid=0x1bf6 in Object.wait() [0x00007f0a23c3e000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000eebacb28> (a java.lang.Thread) at java.lang.Thread.join(Thread.java:1280) - locked <0x00000000eebacb28> (a java.lang.Thread) at java.lang.Thread.join(Thread.java:1354) at org.apache.activemq.transport.TransportServerThreadSupport.doStop(TransportServerThreadSupport.java:81) at org.apache.activemq.transport.tcp.TcpTransportServer.doStop(TcpTransportServer.java:399) at org.apache.activemq.util.ServiceSupport.stop(ServiceSupport.java:71) at org.apache.activemq.util.ServiceStopper.stop(ServiceStopper.java:41) at org.apache.activemq.broker.TransportConnector.stop(TransportConnector.java:279) at org.apache.activemq.util.ServiceStopper.stop(ServiceStopper.java:41) at org.apache.activemq.broker.BrokerService.stopAllConnectors(BrokerService.java:2030) at org.apache.activemq.broker.BrokerService.stop(BrokerService.java:727) at org.apache.activemq.transport.amqp.joram.ActiveMQAdmin.stopServer(ActiveMQAdmin.java:125) at org.objectweb.jtests.jms.framework.JMSTestCase.tearDown(JMSTestCase.java:112) at org.objectweb.jtests.jms.framework.PTPTestCase.tearDown(PTPTestCase.java:171) at junit.framework.TestCase.runBare(TestCase.java:146) at junit.framework.TestResult$1.protect(TestResult.java:122) at junit.framework.TestResult.runProtected(TestResult.java:142) at junit.framework.TestResult.run(TestResult.java:125) at junit.framework.TestCase.run(TestCase.java:129) at junit.framework.TestSuite.runTest(TestSuite.java:255) at junit.framework.TestSuite.run(TestSuite.java:250) at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:84) at org.junit.runners.Suite.runChild(Suite.java:127) at org.junit.runners.Suite.runChild(Suite.java:26) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) at org.junit.runners.ParentRunner.run(ParentRunner.java:309) at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:53) at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:123) at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:104) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:164) at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:110) at org.apache.maven.surefire.booter.SurefireStarter.invokeProvider(SurefireStarter.java:175) at org.apache.maven.surefire.booter.SurefireStarter.runSuitesInProcessWhenForked(SurefireStarter.java:107) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:68) "VM Thread" prio=10 tid=0x00007f0a1c0ea800 nid=0x1bf9 runnable "GC task thread#0 (ParallelGC)" prio=10 tid=0x00007f0a1c01e000 nid=0x1bf7 runnable "GC task thread#1 (ParallelGC)" prio=10 tid=0x00007f0a1c020000 nid=0x1bf8 runnable "VM Periodic Task Thread" prio=10 tid=0x00007f0a1c122000 nid=0x1c00 waiting on condition JNI global references: 176 -- This message was sent by Atlassian JIRA (v6.1.5#6160)