[AMQ-7115] Deadlock between MQTTInactivityMonitor and BrokerService Threads

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 5.15.0
• Fix Version/s: 5.16.0
• Component/s: MQTT

Environment

<transportConnector name="mqtt+nio+ssl" uri="mqtt+nio+ssl://0.0.0.0:62062?maximumConnections=200000&wireFormat.maxFrameSize=104857600&transport.subscriptionStrategy=mqtt-virtual-topic-subscriptions"/>

• Assignee: Gary Tully
• Reporter: Gary Tully
• Created: 28/Nov/18 14:22
• Updated: 29/Nov/18 11:51
• Resolved: 28/Nov/18 15:06

Description

MQTT with nio+ssl, thread dead lock on concurrent processing socket read error and inactivity monitor exception.

Found one Java-level deadlock:
=============================
"MQTTInactivityMonitor Async Task: java.util.concurrent.ThreadPoolExecutor$Worker@7e51223f[State = -1, empty queue]":
 waiting to lock monitor 0x00007fd54c06d268 (object 0x00000003f63c3d50, a org.apache.activemq.broker.jmx.ManagedTransportConnection),
 which is held by "ActiveMQ BrokerService[AMQ2] Task-38733"
"ActiveMQ BrokerService[AMQ2] Task-38733":
 waiting for ownable synchronizer 0x0000000436d5d458, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
 which is held by "MQTTInactivityMonitor Async Task: java.util.concurrent.ThreadPoolExecutor$Worker@7e51223f[State = -1, empty queue]"

Java stack information for the threads listed above:
===================================================
"MQTTInactivityMonitor Async Task: java.util.concurrent.ThreadPoolExecutor$Worker@7e51223f[State = -1, empty queue]":
 at org.apache.activemq.broker.TransportConnection.processRemoveConnection(TransportConnection.java:870)
 - waiting to lock <0x00000003f63c3d50> (a org.apache.activemq.broker.jmx.ManagedTransportConnection)
 at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:73)
 at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:326)
 at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:190)
 at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:45)
 at org.apache.activemq.transport.mqtt.MQTTInactivityMonitor.onCommand(MQTTInactivityMonitor.java:162)
 at org.apache.activemq.transport.mqtt.MQTTTransportFilter.sendToActiveMQ(MQTTTransportFilter.java:106)
 at org.apache.activemq.transport.mqtt.MQTTProtocolConverter.sendToActiveMQ(MQTTProtocolConverter.java:181)
 at org.apache.activemq.transport.mqtt.MQTTProtocolConverter.onTransportError(MQTTProtocolConverter.java:650)
 at org.apache.activemq.transport.mqtt.MQTTInactivityMonitor.onException(MQTTInactivityMonitor.java:194)
 at org.apache.activemq.transport.mqtt.MQTTInactivityMonitor$2$1.run(MQTTInactivityMonitor.java:128)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
 at java.lang.Thread.run(Thread.java:748)
"ActiveMQ BrokerService[AMQ2] Task-38733":
 at sun.misc.Unsafe.park(Native Method)
 - parking to wait for <0x0000000436d5d458> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
 at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
 at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
 at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
 at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
 at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
 at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
 at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:43)
 at org.apache.activemq.transport.mqtt.MQTTInactivityMonitor.onCommand(MQTTInactivityMonitor.java:162)
 at org.apache.activemq.transport.mqtt.MQTTTransportFilter.sendToActiveMQ(MQTTTransportFilter.java:106)
 at org.apache.activemq.transport.mqtt.MQTTProtocolConverter.sendToActiveMQ(MQTTProtocolConverter.java:181)
 at org.apache.activemq.transport.mqtt.MQTTProtocolConverter.onTransportError(MQTTProtocolConverter.java:650)
 at org.apache.activemq.transport.mqtt.MQTTTransportFilter.onException(MQTTTransportFilter.java:206)
 at org.apache.activemq.transport.TransportSupport.onException(TransportSupport.java:96)
 at org.apache.activemq.transport.nio.NIOSSLTransport.serviceRead(NIOSSLTransport.java:225)
 at org.apache.activemq.transport.mqtt.MQTTNIOSSLTransport.initializeStreams(MQTTNIOSSLTransport.java:48)
 at org.apache.activemq.transport.tcp.TcpTransport.connect(TcpTransport.java:519)
 at org.apache.activemq.transport.nio.NIOTransport.doStart(NIOTransport.java:160)
 at org.apache.activemq.transport.nio.NIOSSLTransport.doStart(NIOSSLTransport.java:412)
 at org.apache.activemq.util.ServiceSupport.start(ServiceSupport.java:55)
 at org.apache.activemq.transport.TransportFilter.start(TransportFilter.java:58)
 at org.apache.activemq.transport.mqtt.MQTTTransportFilter.start(MQTTTransportFilter.java:157)
 at org.apache.activemq.transport.mqtt.MQTTInactivityMonitor.start(MQTTInactivityMonitor.java:148)
 at org.apache.activemq.transport.TransportFilter.start(TransportFilter.java:58)
 at org.apache.activemq.broker.TransportConnection.start(TransportConnection.java:1066)
 - locked <0x00000003f63c3d50> (a org.apache.activemq.broker.jmx.ManagedTransportConnection)
 at org.apache.activemq.broker.TransportConnector$1$1.run(TransportConnector.java:218)
 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
 at java.lang.Thread.run(Thread.java:748)\{code}

Issue Links

• is related to: AMQ-6414 The nio+ssl transports can block and hang on connection in certain situations