Uploaded image for project: 'ActiveMQ Classic'
  1. ActiveMQ Classic
  2. AMQ-4978

JoramJmsNioTest hangs intermittently

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Minor
    • Resolution: Fixed
    • None
    • 5.9.1, 5.10.0
    • Test Cases
    • None
    • Unit Test Broken

    Description

      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

      Attachments

        Activity

          People

            kearls Kevin Anthony Earls
            kearls Kevin Anthony Earls
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: