[AMQ-6866] deadlock when using async dispatch

• Type: Bug
• Status: Open
• Priority: Major
• Resolution: Unresolved
• Affects Version/s: 5.14.0
• Component/s: Broker

Environment

linux suse 11 sp3
activemq 5.14.0

• Assignee: Matt Pavlovich
• Reporter: Chris Chou
• Created: 21/Nov/17 11:35
• Updated: 02/Jun/21 17:42

Description

we use activemq as out message system.

we use jdbc master slave for activemq server.

we have several node and each node has two connection, one connection(useAsyncSend=true) is used to send topic message, and another connection(useAsyncSend=false) is used to send queue message and register topic/queue message consumer listener, both of the connection is use fail over transport over ssl transport.

when we send queue message, we set persist to true and the TTL is half an hour.
when we send topic message, we set persist to false and TTL is 7 days.

both topic and queue consumer is not durable.

we use async dispatch in the MQ server which is default enabled.

after some time, we get java level deadlock in the MQ server. this problem only occurs in one of our envs, it can only be reproduced in this env after sevaral hours, cannot be reproduced in other envs.

Found one Java-level deadlock:
=============================
"ActiveMQ Transport: ssl:///220.51.13.50:46440":
  waiting to lock monitor 0x00007fa7b0069f98 (object 0x00000006a0455eb0, a org.apache.activemq.broker.region.Topic),
  which is held by "ActiveMQ Transport: ssl:///220.51.13.57:44446"
"ActiveMQ Transport: ssl:///220.51.13.57:44446":
  waiting to lock monitor 0x00007fa7a800e468 (object 0x00000006a16161c8, a java.lang.Object),
  which is held by "ActiveMQ BrokerService[localhost] Task-95"
"ActiveMQ BrokerService[localhost] Task-95":
  waiting to lock monitor 0x00007fa7b40302f8 (object 0x00000006a02f0e20, a org.apache.activemq.thread.PooledTaskRunner$1),
  which is held by "ActiveMQ Transport: ssl:///220.51.13.57:44446"

Java stack information for the threads listed above:
===================================================
"ActiveMQ Transport: ssl:///220.51.13.50:46440":
	at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:498)
	- waiting to lock <0x00000006a0455eb0> (a org.apache.activemq.broker.region.Topic)
	at org.apache.activemq.broker.region.Topic.send(Topic.java:479)
	at org.apache.activemq.broker.region.DestinationFilter.send(DestinationFilter.java:132)
	at org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:503)
	at org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:468)
	at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
	at org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:293)
	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:153)
	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:153)
	at org.apache.activemq.security.AuthorizationBroker.send(AuthorizationBroker.java:226)
	at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:158)
	at org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:578)
	at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:768)
	at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:333)
	at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:197)
	at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
	at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125)
	at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:300)
	at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
	at org.apache.activemq.transport.tcp.SslTransport.doConsume(SslTransport.java:108)
	at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:233)
	at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:215)
	at java.lang.Thread.run(Thread.java:745)
"ActiveMQ Transport: ssl:///220.51.13.57:44446":
	at org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:683)
	- waiting to lock <0x00000006a16161c8> (a java.lang.Object)
	at org.apache.activemq.broker.region.PrefetchSubscription.onDispatch(PrefetchSubscription.java:813)
	at org.apache.activemq.broker.region.PrefetchSubscription$3.onSuccess(PrefetchSubscription.java:775)
	at org.apache.activemq.broker.TransportConnection.processDispatch(TransportConnection.java:995)
	at org.apache.activemq.broker.TransportConnection.iterate(TransportConnection.java:1024)
	at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:133)
	at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:48)
	at java.util.concurrent.ThreadPoolExecutor$CallerRunsPolicy.rejectedExecution(ThreadPoolExecutor.java:2022)
	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823)
	at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1369)
	at org.apache.activemq.thread.PooledTaskRunner.wakeup(PooledTaskRunner.java:83)
	- locked <0x00000006a02f0e20> (a org.apache.activemq.thread.PooledTaskRunner$1)
	at org.apache.activemq.broker.TransportConnection.dispatchAsync(TransportConnection.java:950)
	at org.apache.activemq.broker.region.TopicSubscription.dispatch(TopicSubscription.java:680)
	at org.apache.activemq.broker.region.TopicSubscription.add(TopicSubscription.java:122)
	- locked <0x00000006a2a0af58> (a java.lang.Object)
	at org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:48)
	at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:761)
	at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:553)
	- locked <0x00000006a0455eb0> (a org.apache.activemq.broker.region.Topic)
	at org.apache.activemq.broker.region.Topic.send(Topic.java:479)
	at org.apache.activemq.broker.region.DestinationFilter.send(DestinationFilter.java:132)
	at org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:503)
	at org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:468)
	at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
	at org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:293)
	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:153)
	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:153)
	at org.apache.activemq.security.AuthorizationBroker.send(AuthorizationBroker.java:226)
	at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:158)
	at org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:578)
	at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:768)
	at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:333)
	at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:197)
	at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
	at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125)
	at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:300)
	at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
	at org.apache.activemq.transport.tcp.SslTransport.doConsume(SslTransport.java:108)
	at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:233)
	at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:215)
	at java.lang.Thread.run(Thread.java:745)
"ActiveMQ BrokerService[localhost] Task-95":
	at org.apache.activemq.thread.PooledTaskRunner.wakeup(PooledTaskRunner.java:62)
	- waiting to lock <0x00000006a02f0e20> (a org.apache.activemq.thread.PooledTaskRunner$1)
	at org.apache.activemq.broker.TransportConnection.dispatchAsync(TransportConnection.java:950)
	at org.apache.activemq.broker.region.PrefetchSubscription.dispatch(PrefetchSubscription.java:793)
	at org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:717)
	- locked <0x00000006a16161e0> (a java.lang.Object)
	- locked <0x00000006a16161c8> (a java.lang.Object)
	at org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:162)
	at org.apache.activemq.broker.region.Queue.doActualDispatch(Queue.java:2071)
	at org.apache.activemq.broker.region.Queue.doDispatch(Queue.java:2019)
	at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:2160)
	at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1601)
	- locked <0x00000006a1ed9c58> (a java.lang.Object)
	at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:133)
	at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:48)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)

Found 1 deadlock.