[
https://issues.apache.org/jira/browse/QPID-6865?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15010645#comment-15010645
]
Rob Godfrey edited comment on QPID-6865 at 11/18/15 9:52 AM:
-------------------------------------------------------------
Re-running the perf tests, [~k-wall] found the following deadlock
{noformat}
Java stack information for the threads listed above:
===================================================
"Queue Runner[testQueue_0]":
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000007d039ca48> (a
java.util.concurrent.locks.ReentrantLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197)
at
java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:214)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:290)
at
org.apache.qpid.server.consumer.AbstractConsumerTarget.getSendLock(AbstractConsumerTarget.java:181)
at
org.apache.qpid.server.protocol.v0_8.AMQChannel.ensureConsumersNoticedStateChange(AMQChannel.java:3809)
at
org.apache.qpid.server.transport.AbstractAMQPConnection.setMessageAssignmentSuspended(AbstractAMQPConnection.java:413)
at
org.apache.qpid.server.transport.MultiVersionProtocolEngine.setMessageAssignmentSuspended(MultiVersionProtocolEngine.java:97)
at
org.apache.qpid.server.transport.NonBlockingConnection.reserveOutboundMessageSpace(NonBlockingConnection.java:211)
at
org.apache.qpid.server.transport.AbstractAMQPConnection.reserveOutboundMessageSpace(AbstractAMQPConnection.java:652)
at
org.apache.qpid.server.consumer.AbstractConsumerTarget.send(AbstractConsumerTarget.java:193)
at
org.apache.qpid.server.queue.QueueConsumerImpl.send(QueueConsumerImpl.java:557)
at
org.apache.qpid.server.queue.AbstractQueue.deliverMessage(AbstractQueue.java:1416)
at
org.apache.qpid.server.queue.AbstractQueue.attemptDelivery(AbstractQueue.java:2217)
at
org.apache.qpid.server.queue.AbstractQueue.processQueue(AbstractQueue.java:2389)
at org.apache.qpid.server.queue.QueueRunner.run(QueueRunner.java:75)
at
org.apache.qpid.server.virtualhost.AbstractVirtualHost$2.execute(AbstractVirtualHost.java:645)
at
org.apache.qpid.server.virtualhost.HouseKeepingTask$1.run(HouseKeepingTask.java:65)
at java.security.AccessController.doPrivileged(Native Method)
at
org.apache.qpid.server.virtualhost.HouseKeepingTask.run(HouseKeepingTask.java:60)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
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:745)
"Queue Runner[testQueue_8]":
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000716074cc0> (a
java.util.concurrent.locks.ReentrantLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197)
at
java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:214)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:290)
at
org.apache.qpid.server.consumer.AbstractConsumerTarget.getSendLock(AbstractConsumerTarget.java:181)
at
org.apache.qpid.server.protocol.v0_8.AMQChannel.ensureConsumersNoticedStateChange(AMQChannel.java:3809)
at
org.apache.qpid.server.transport.AbstractAMQPConnection.setMessageAssignmentSuspended(AbstractAMQPConnection.java:413)
at
org.apache.qpid.server.transport.MultiVersionProtocolEngine.setMessageAssignmentSuspended(MultiVersionProtocolEngine.java:97)
at
org.apache.qpid.server.transport.NonBlockingConnection.reserveOutboundMessageSpace(NonBlockingConnection.java:211)
at
org.apache.qpid.server.transport.AbstractAMQPConnection.reserveOutboundMessageSpace(AbstractAMQPConnection.java:652)
at
org.apache.qpid.server.consumer.AbstractConsumerTarget.send(AbstractConsumerTarget.java:193)
at
org.apache.qpid.server.queue.QueueConsumerImpl.send(QueueConsumerImpl.java:557)
at
org.apache.qpid.server.queue.AbstractQueue.deliverMessage(AbstractQueue.java:1416)
at
org.apache.qpid.server.queue.AbstractQueue.attemptDelivery(AbstractQueue.java:2217)
at
org.apache.qpid.server.queue.AbstractQueue.processQueue(AbstractQueue.java:2389)
at org.apache.qpid.server.queue.QueueRunner.run(QueueRunner.java:75)
at
org.apache.qpid.server.virtualhost.AbstractVirtualHost$2.execute(AbstractVirtualHost.java:645)
at
org.apache.qpid.server.virtualhost.HouseKeepingTask$1.run(HouseKeepingTask.java:65)
at java.security.AccessController.doPrivileged(Native Method)
at
org.apache.qpid.server.virtualhost.HouseKeepingTask.run(HouseKeepingTask.java:60)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
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:745)
Found 1 deadlock.
{noformat}
This is likely the cause of the test failure. The solution is to only acquire
the sending locks on consumers in the case where setMessageAssignmentSuspended
is called from doWork
was (Author: rgodfrey):
Re-running the perf tests, [k-wall] found the following deadlock
{noformat}
Java stack information for the threads listed above:
===================================================
"Queue Runner[testQueue_0]":
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000007d039ca48> (a
java.util.concurrent.locks.ReentrantLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197)
at
java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:214)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:290)
at
org.apache.qpid.server.consumer.AbstractConsumerTarget.getSendLock(AbstractConsumerTarget.java:181)
at
org.apache.qpid.server.protocol.v0_8.AMQChannel.ensureConsumersNoticedStateChange(AMQChannel.java:3809)
at
org.apache.qpid.server.transport.AbstractAMQPConnection.setMessageAssignmentSuspended(AbstractAMQPConnection.java:413)
at
org.apache.qpid.server.transport.MultiVersionProtocolEngine.setMessageAssignmentSuspended(MultiVersionProtocolEngine.java:97)
at
org.apache.qpid.server.transport.NonBlockingConnection.reserveOutboundMessageSpace(NonBlockingConnection.java:211)
at
org.apache.qpid.server.transport.AbstractAMQPConnection.reserveOutboundMessageSpace(AbstractAMQPConnection.java:652)
at
org.apache.qpid.server.consumer.AbstractConsumerTarget.send(AbstractConsumerTarget.java:193)
at
org.apache.qpid.server.queue.QueueConsumerImpl.send(QueueConsumerImpl.java:557)
at
org.apache.qpid.server.queue.AbstractQueue.deliverMessage(AbstractQueue.java:1416)
at
org.apache.qpid.server.queue.AbstractQueue.attemptDelivery(AbstractQueue.java:2217)
at
org.apache.qpid.server.queue.AbstractQueue.processQueue(AbstractQueue.java:2389)
at org.apache.qpid.server.queue.QueueRunner.run(QueueRunner.java:75)
at
org.apache.qpid.server.virtualhost.AbstractVirtualHost$2.execute(AbstractVirtualHost.java:645)
at
org.apache.qpid.server.virtualhost.HouseKeepingTask$1.run(HouseKeepingTask.java:65)
at java.security.AccessController.doPrivileged(Native Method)
at
org.apache.qpid.server.virtualhost.HouseKeepingTask.run(HouseKeepingTask.java:60)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
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:745)
"Queue Runner[testQueue_8]":
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000716074cc0> (a
java.util.concurrent.locks.ReentrantLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:867)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1197)
at
java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:214)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:290)
at
org.apache.qpid.server.consumer.AbstractConsumerTarget.getSendLock(AbstractConsumerTarget.java:181)
at
org.apache.qpid.server.protocol.v0_8.AMQChannel.ensureConsumersNoticedStateChange(AMQChannel.java:3809)
at
org.apache.qpid.server.transport.AbstractAMQPConnection.setMessageAssignmentSuspended(AbstractAMQPConnection.java:413)
at
org.apache.qpid.server.transport.MultiVersionProtocolEngine.setMessageAssignmentSuspended(MultiVersionProtocolEngine.java:97)
at
org.apache.qpid.server.transport.NonBlockingConnection.reserveOutboundMessageSpace(NonBlockingConnection.java:211)
at
org.apache.qpid.server.transport.AbstractAMQPConnection.reserveOutboundMessageSpace(AbstractAMQPConnection.java:652)
at
org.apache.qpid.server.consumer.AbstractConsumerTarget.send(AbstractConsumerTarget.java:193)
at
org.apache.qpid.server.queue.QueueConsumerImpl.send(QueueConsumerImpl.java:557)
at
org.apache.qpid.server.queue.AbstractQueue.deliverMessage(AbstractQueue.java:1416)
at
org.apache.qpid.server.queue.AbstractQueue.attemptDelivery(AbstractQueue.java:2217)
at
org.apache.qpid.server.queue.AbstractQueue.processQueue(AbstractQueue.java:2389)
at org.apache.qpid.server.queue.QueueRunner.run(QueueRunner.java:75)
at
org.apache.qpid.server.virtualhost.AbstractVirtualHost$2.execute(AbstractVirtualHost.java:645)
at
org.apache.qpid.server.virtualhost.HouseKeepingTask$1.run(HouseKeepingTask.java:65)
at java.security.AccessController.doPrivileged(Native Method)
at
org.apache.qpid.server.virtualhost.HouseKeepingTask.run(HouseKeepingTask.java:60)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
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:745)
Found 1 deadlock.
{noformat}
This is likely the cause of the test failure. The solution is to only acquire
the sending locks on consumers in the case where setMessageAssignmentSuspended
is called from doWork
> [Java Perftest] Perftest failure on 0-9
> ---------------------------------------
>
> Key: QPID-6865
> URL: https://issues.apache.org/jira/browse/QPID-6865
> Project: Qpid
> Issue Type: Bug
> Components: Java Performance Tests
> Reporter: Lorenz Quack
> Assignee: Rob Godfrey
> Attachments: VirtualHost.png, broker.log, perftest.log
>
>
> Perftest fail on draining the queues:
> {noformat}
> 2015-11-17 09:05:38,826 ERROR
> [org.apache.qpid.disttest.ControllerRunner.main()]
> o.a.q.d.c.AbstractTestRunner Couldn't run test
> org.apache.qpid.disttest.DistributedTestException:
> org.apache.qpid.disttest.DistributedTestException: Failed to drain
> queue:direct:///testQueue_2/testQueue_2?routingkey='testQueue_2'&durable='true'
> at
> org.apache.qpid.disttest.jms.QpidQueueCreator.deleteQueues(QpidQueueCreator.java:249)
> ~[classes/:na]
> at
> org.apache.qpid.disttest.jms.ControllerJmsDelegate.deleteQueues(ControllerJmsDelegate.java:268)
> ~[classes/:na]
> at
> org.apache.qpid.disttest.controller.AbstractTestRunner.deleteQueues(AbstractTestRunner.java:208)
> ~[classes/:na]
> at
> org.apache.qpid.disttest.controller.AbstractTestRunner.runParts(AbstractTestRunner.java:344)
> ~[classes/:na]
> at
> org.apache.qpid.disttest.controller.AbstractTestRunner.doIt(AbstractTestRunner.java:297)
> ~[classes/:na]
> at
> org.apache.qpid.disttest.controller.HillClimbingTestRunner.run(HillClimbingTestRunner.java:76)
> [classes/:na]
> at
> org.apache.qpid.disttest.controller.Controller.runAllTests(Controller.java:173)
> [classes/:na]
> at
> org.apache.qpid.disttest.ControllerRunner.runTest(ControllerRunner.java:211)
> [classes/:na]
> at
> org.apache.qpid.disttest.ControllerRunner.runTests(ControllerRunner.java:186)
> [classes/:na]
> at
> org.apache.qpid.disttest.ControllerRunner.runController(ControllerRunner.java:125)
> [classes/:na]
> at
> org.apache.qpid.disttest.ControllerRunner.main(ControllerRunner.java:102)
> [classes/:na]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> ~[na:1.8.0_60]
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> ~[na:1.8.0_60]
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> ~[na:1.8.0_60]
> at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_60]
> at org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:293)
> [exec-maven-plugin-1.3.2.jar:na]
> at java.lang.Thread.run(Thread.java:745) [na:1.8.0_60]
> Caused by: org.apache.qpid.disttest.DistributedTestException: Failed to drain
> queue:direct:///testQueue_2/testQueue_2?routingkey='testQueue_2'&durable='true'
> at
> org.apache.qpid.disttest.jms.QpidQueueCreator.drainQueue(QpidQueueCreator.java:323)
> ~[classes/:na]
> at
> org.apache.qpid.disttest.jms.QpidQueueCreator.access$300(QpidQueueCreator.java:57)
> ~[classes/:na]
> at
> org.apache.qpid.disttest.jms.QpidQueueCreator$2.call(QpidQueueCreator.java:225)
> ~[classes/:na]
> at
> org.apache.qpid.disttest.jms.QpidQueueCreator$2.call(QpidQueueCreator.java:214)
> ~[classes/:na]
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> ~[na:1.8.0_60]
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> ~[na:1.8.0_60]
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> ~[na:1.8.0_60]
> ... 1 common frames omitted
> Caused by: org.apache.qpid.disttest.DistributedTestException: Failed to query
> queue
> depth:direct:///testQueue_2/testQueue_2?routingkey='testQueue_2'&durable='true'
> at
> org.apache.qpid.disttest.jms.QpidQueueCreator.getQueueDepth(QpidQueueCreator.java:294)
> ~[classes/:na]
> at
> org.apache.qpid.disttest.jms.QpidQueueCreator.drainQueue(QpidQueueCreator.java:317)
> ~[classes/:na]
> ... 7 common frames omitted
> Caused by: org.apache.qpid.AMQTimeoutException: Server did not respond in a
> timely fashion
> at
> org.apache.qpid.client.util.BlockingWaiter.block(BlockingWaiter.java:170)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.client.protocol.BlockingMethodFrameListener.blockForFrame(BlockingMethodFrameListener.java:115)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.client.AMQProtocolHandler.writeCommandFrameAndWaitForReply(AMQProtocolHandler.java:685)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.client.AMQProtocolHandler.syncWrite(AMQProtocolHandler.java:706)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.client.AMQProtocolHandler.syncWrite(AMQProtocolHandler.java:700)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.client.AMQSession_0_8.sendExchangeBound(AMQSession_0_8.java:503)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.client.AMQSession_0_8.access$100(AMQSession_0_8.java:71)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.client.AMQSession_0_8$2.execute(AMQSession_0_8.java:459)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.client.AMQSession_0_8$2.execute(AMQSession_0_8.java:456)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.client.failover.FailoverNoopSupport.execute(FailoverNoopSupport.java:67)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.client.AMQSession_0_8.isBound(AMQSession_0_8.java:462)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.client.AMQSession_0_8.requestQueueDepth(AMQSession_0_8.java:964)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at org.apache.qpid.client.AMQSession$9.execute(AMQSession.java:2807)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at org.apache.qpid.client.AMQSession$9.execute(AMQSession.java:2802)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.client.failover.FailoverNoopSupport.execute(FailoverNoopSupport.java:67)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.client.AMQSession.getQueueDepth(AMQSession.java:2814)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.client.AMQSession.getQueueDepth(AMQSession.java:2786)
> ~[qpid-client-6.0.0-SNAPSHOT.jar:6.0.0-SNAPSHOT]
> at
> org.apache.qpid.disttest.jms.QpidQueueCreator.getQueueDepth(QpidQueueCreator.java:289)
> ~[classes/:na]
> ... 8 common frames omitted
> {noformat}
> Full logs as attachments.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
