qpid-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Rob Godfrey (JIRA)" <j...@apache.org>
Subject [jira] [Comment Edited] (QPID-6865) [Java Perftest] Perftest failure on 0-9
Date Wed, 18 Nov 2015 09:53:11 GMT

    [ 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: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org


Mime
View raw message