[AMQ-7217] Already connected client makes it impossible to reuse client id after disconnection

• Type: Bug
• Status: Open
• Priority: Major
• Resolution: Unresolved
• Affects Version/s: 5.14.4, 5.15.9
• Component/s: Broker
• Assignee: Unassigned
• Reporter: Piotr
• Created: 29/May/19 14:55
• Updated: 22/Feb/21 13:48

Description

Embedded single-node broker

Single client A with id=CLIENT_ID_1 connects using failover transport.

Another client B with id=CLIENT_ID_1 tries to connect.
It receives the following errors, but keeps running:

javax.jms.InvalidClientIDException: Broker: MyBroker - Client: CLIENT_ID_1 already connected from tcp://127.0.0.1:60576
        at org.apache.activemq.broker.region.RegionBroker.addConnection(RegionBroker.java:256)
        at org.apache.activemq.broker.jmx.ManagedRegionBroker.addConnection(ManagedRegionBroker.java:227)
        at org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:98)
        at org.apache.activemq.advisory.AdvisoryBroker.addConnection(AdvisoryBroker.java:116)
        at org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:98)
        at org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:98)
        at org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:98)
        at org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:103)
        at org.apache.activemq.broker.TransportConnection.processAddConnection(TransportConnection.java:852)
        at org.apache.activemq.broker.jmx.ManagedTransportConnection.processAddConnection(ManagedTransportConnection.java:77)
        at org.apache.activemq.command.ConnectionInfo.visit(ConnectionInfo.java:139)
        at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:336)
        at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:200)
        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:301)
        at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
        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)
16:44:41.744 [ActiveMQ Transport: tcp://localhost/127.0.0.1:1234@60584] DEBUG org.apache.activemq.util.ThreadPoolUtils - Shutdown of ExecutorService: java.util.concurrent.ThreadPoolExecutor@44f132b9[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0] is shutdown: true and terminated: true took: 0.000 seconds.
16:44:41.745 [ActiveMQ Transport: tcp://localhost/127.0.0.1:1234@60584] DEBUG org.apache.activemq.transport.tcp.TcpTransport - Stopping transport tcp://localhost/127.0.0.1:1234@60584
16:44:41.745 [ActiveMQ Transport: tcp://localhost/127.0.0.1:1234@60584] DEBUG org.apache.activemq.thread.TaskRunnerFactory - Initialized TaskRunnerFactory[ActiveMQ Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@5b83c04c[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
16:44:41.746 [ActiveMQ Task-1] DEBUG org.apache.activemq.transport.tcp.TcpTransport - Closed socket Socket[addr=localhost/127.0.0.1,port=1234,localport=60584]
16:44:41.746 [ActiveMQ Transport: tcp://localhost/127.0.0.1:1234@60584] DEBUG org.apache.activemq.util.ThreadPoolUtils - Forcing shutdown of ExecutorService: java.util.concurrent.ThreadPoolExecutor@5b83c04c[Running, pool size = 1, active threads = 0, queued tasks = 0, completed tasks = 1]
16:44:41.746 [ActiveMQ Transport: tcp://localhost/127.0.0.1:1234@60584] WARN org.apache.activemq.transport.failover.FailoverTransport - Transport (tcp://localhost:1234) failed , attempting to automatically reconnect: {}
java.io.EOFException: null
        at java.base/java.io.DataInputStream.readInt(DataInputStream.java:397)
        at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:268)
        at org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:240)
        at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:232)
        at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:215)
        at java.base/java.lang.Thread.run(Thread.java:834)

Client A disconnects.
 
Client B still receives the same errors.
Client B disconnects.

No client is able to connect using id=CLIENT_ID_1

Problem can be observed in version 5.14.4 and later but not in 5.4.13 and earlier.
Probably caused by: https://issues.apache.org/jira/browse/AMQ-6561
When I run broker in debug mode and force exit from the following call from TransportConnection.processAddConnection(ConnectionInfo info):

this.delayedStop(2000, "Failed with SecurityException: " + var8.getLocalizedMessage(), var8);

the issue cannot be observed.

Issue Links

• is caused by: AMQ-6561 Broker does not close connection for all connection attempt errors