[AMQ-7106] TransportConnection pendingStop support during start is broken

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

Environment

mqtt nio ssl

• Assignee: Gary Tully
• Reporter: Gary Tully
• Created: 21/Nov/18 10:19
• Updated: 11/Mar/21 14:55
• Resolved: 21/Nov/18 10:30

Description

If start blocks, the inactivity monitor can kick in. The intent is that it can see the starting state and initiate a pending stop and complete.
The current synchronization breaks this b/c the start code holds a lock for its duration, which requires the stopAsync code to block in error.
This means there is a blocked inactivity monitor thread per blocked starting connection...  very quickly too many threads.
A blocked ssl handshake can demonstrate.

"MQTTInactivityMonitor Async Task: java.util.concurrent.ThreadPoolExecutor$Worker@7c1745f4[State = -1, empty queue]" #4412 daemon prio=5 os_prio=0 tid=0x00007fd524f2c800 nid=0x622d waiting for monitor entry [0x00007fd393776000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.apache.activemq.broker.TransportConnection.stopAsync(TransportConnection.java:1136)
        - waiting to lock <0x00000004dc8059b0> (a org.apache.activemq.broker.jmx.ManagedTransportConnection)
        at org.apache.activemq.broker.jmx.ManagedTransportConnection.stopAsync(ManagedTransportConnection.java:66)
        at org.apache.activemq.broker.TransportConnection.stopAsync(TransportConnection.java:1131)
        at org.apache.activemq.broker.TransportConnection.serviceTransportException(TransportConnection.java:235)
        at org.apache.activemq.broker.TransportConnection$1.onException(TransportConnection.java:206)
        at org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:101)
        at org.apache.activemq.transport.mqtt.MQTTInactivityMonitor.onException(MQTTInactivityMonitor.java:196)
        at org.apache.activemq.transport.mqtt.MQTTInactivityMonitor$1$1.run(MQTTInactivityMonitor.java:81)
        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)

   Locked ownable synchronizers:
        - <0x00000004d7803c60> (a java.util.concurrent.ThreadPoolExecutor$Worker)

"ActiveMQ BrokerService[BB] Task-51959" #4414527 daemon prio=5 os_prio=0 tid=0x00007fd5f83b9800 nid=0x1846 runnable [0x00007fd3873b3000]
   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:93)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        - locked <0x00000004dc805830> (a sun.nio.ch.Util$3)
        - locked <0x00000004dc805820> (a java.util.Collections$UnmodifiableSet)
        - locked <0x00000004dc805840> (a sun.nio.ch.EPollSelectorImpl)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at org.apache.activemq.transport.nio.NIOSSLTransport.doHandshake(NIOSSLTransport.java:380)
        at org.apache.activemq.transport.nio.NIOSSLTransport.initializeStreams(NIOSSLTransport.java:137)
        at org.apache.activemq.transport.mqtt.MQTTNIOSSLTransport.initializeStreams(MQTTNIOSSLTransport.java:46)
        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 <0x00000004dc8059b0> (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)

   Locked ownable synchronizers:
        - <0x00000004dc805a78> (a java.util.concurrent.ThreadPoolExecutor$Worker)

Issue Links

• causes: AMQ-8183 Setting a maxFrameSize can lead to infinite loop and high cpu usage