[
https://issues.apache.org/jira/browse/AMQ-7217?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17288384#comment-17288384
]
Nauman Hameed commented on AMQ-7217:
------------------------------------
[~piotrciruk] : I am facing a similar issue using ActiveMQ 5.13.2. I have 2
ActiveMQ nodes where one acts as publisher and other is subscriber. Subscriber
is attempting to make a connection with publisher after publisher re-start but
it is failing with error mentioned in this cases.
{code}
2021-02-16 19:31:26,837 | DEBUG | Setting up new connection id:
AON-CUAC01-AMS1->AON-CUAC01-LON1-49164-1611665757700-28:1, address:
vm://AON-CUAC01-AMS1#76, info: ConnectionInfo {commandId = 1, responseRequired
= true, connectionId =
AON-CUAC01-AMS1->AON-CUAC01-LON1-49164-1611665757700-28:1, clientId =
Broker12Bridge_AON-CUAC01-LON1_inbound_AON-CUAC01-AMS1, clientIp = null,
userName = amqsystem, password = *****, brokerPath = null,
brokerMasterConnector = false, manageable = false, clientMaster = true,
faultTolerant = false, failoverReconnect = false} |
org.apache.activemq.broker.TransportConnection |
triggerStartAsyncNetworkBridgeCreation:
remoteBroker=tcp://AON-CUAC01-LON1/10.250.242.29:61616@58562, localBroker=
vm://AON-CUAC01-AMS1#76
2021-02-16 19:31:26,837 | INFO | Adding Connection: ConnectionInfo {commandId
= 1, responseRequired = true, connectionId =
AON-CUAC01-AMS1->AON-CUAC01-LON1-49164-1611665757700-28:1, clientId =
Broker12Bridge_AON-CUAC01-LON1_inbound_AON-CUAC01-AMS1, clientIp =
vm://AON-CUAC01-AMS1#76, userName = amqsystem, password = *****, brokerPath =
null, brokerMasterConnector = false, manageable = false, clientMaster = true,
faultTolerant = false, failoverReconnect = false} |
org.apache.activemq.broker.util.LoggingBrokerPlugin |
triggerStartAsyncNetworkBridgeCreation:
remoteBroker=tcp://AON-CUAC01-LON1/10.250.242.29:61616@58562, localBroker=
vm://AON-CUAC01-AMS1#76
2021-02-16 19:31:26,838 | WARN | Failed to add Connection
AON-CUAC01-AMS1->AON-CUAC01-LON1-49164-1611665757700-28:1 due to
javax.jms.InvalidClientIDException: Broker: AON-CUAC01-AMS1 - Client:
Broker12Bridge_AON-CUAC01-LON1_inbound_AON-CUAC01-AMS1 already connected from
vm://AON-CUAC01-AMS1#60 | org.apache.activemq.broker.TransportConnection |
triggerStartAsyncNetworkBridgeCreation:
remoteBroker=tcp://AON-CUAC01-LON1/10.250.242.29:61616@58562, localBroker=
vm://AON-CUAC01-AMS1#76
2021-02-16 19:31:26,838 | DEBUG | Error occured while processing sync command:
ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
AON-CUAC01-AMS1->AON-CUAC01-LON1-49164-1611665757700-28:1, clientId =
Broker12Bridge_AON-CUAC01-LON1_inbound_AON-CUAC01-AMS1, clientIp =
vm://AON-CUAC01-AMS1#76, userName = amqsystem, password = *****, brokerPath =
null, brokerMasterConnector = false, manageable = false, clientMaster = true,
faultTolerant = false, failoverReconnect = false}, exception:
javax.jms.InvalidClientIDException: Broker: AON-CUAC01-AMS1 - Client:
Broker12Bridge_AON-CUAC01-LON1_inbound_AON-CUAC01-AMS1 already connected from
vm://AON-CUAC01-AMS1#60 |
org.apache.activemq.broker.TransportConnection.Service |
triggerStartAsyncNetworkBridgeCreation:
remoteBroker=tcp://AON-CUAC01-LON1/10.250.242.29:61616@58562, localBroker=
vm://AON-CUAC01-AMS1#76
javax.jms.InvalidClientIDException: Broker: AON-CUAC01-AMS1 - Client:
Broker12Bridge_AON-CUAC01-LON1_inbound_AON-CUAC01-AMS1 already connected from
vm://AON-CUAC01-AMS1#60
at
org.apache.activemq.broker.region.RegionBroker.addConnection(RegionBroker.java:255)
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.util.LoggingBrokerPlugin.addConnection(LoggingBrokerPlugin.java:178)
at
org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:98)
at
org.apache.activemq.security.SimpleAuthenticationBroker.addConnection(SimpleAuthenticationBroker.java:77)
at
org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:103)
at
org.apache.activemq.broker.TransportConnection.processAddConnection(TransportConnection.java:817)
at
org.apache.activemq.command.ConnectionInfo.visit(ConnectionInfo.java:139)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:338)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:188)
at
org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116)
at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
at
org.apache.activemq.transport.vm.VMTransport.doDispatch(VMTransport.java:162)
at
org.apache.activemq.transport.vm.VMTransport.dispatch(VMTransport.java:154)
at
org.apache.activemq.transport.vm.VMTransport.oneway(VMTransport.java:131)
at
org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:68)
at
org.apache.activemq.transport.ResponseCorrelator.asyncRequest(ResponseCorrelator.java:81)
at
org.apache.activemq.transport.ResponseCorrelator.request(ResponseCorrelator.java:86)
at
org.apache.activemq.network.DemandForwardingBridgeSupport.startLocalBridge(DemandForwardingBridgeSupport.java:468)
at
org.apache.activemq.network.DemandForwardingBridgeSupport.doStartLocalAndRemoteBridges(DemandForwardingBridgeSupport.java:421)
at
org.apache.activemq.network.DemandForwardingBridgeSupport.access$500(DemandForwardingBridgeSupport.java:105)
at
org.apache.activemq.network.DemandForwardingBridgeSupport$5.run(DemandForwardingBridgeSupport.java:336)
at java.lang.Thread.run(Thread.java:748)
2021-02-16 19:31:26,838 | INFO | Network connection between
vm://AON-CUAC01-AMS1#76 and tcp://AON-CUAC01-LON1/10.250.242.29:61616@58562
shutdown due to a local error: javax.jms.InvalidClientIDException: Broker:
AON-CUAC01-AMS1 - Client:
Broker12Bridge_AON-CUAC01-LON1_inbound_AON-CUAC01-AMS1 already connected from
vm://AON-CUAC01-AMS1#60 |
org.apache.activemq.network.DemandForwardingBridgeSupport |
triggerStartAsyncNetworkBridgeCreation:
remoteBroker=tcp://AON-CUAC01-LON1/10.250.242.29:61616@58562, localBroker=
vm://AON-CUAC01-AMS1#76
2021-02-16 19:31:26,838 | DEBUG | The local Exception was:
javax.jms.InvalidClientIDException: Broker: AON-CUAC01-AMS1 - Client:
Broker12Bridge_AON-CUAC01-LON1_inbound_AON-CUAC01-AMS1 already connected from
vm://AON-CUAC01-AMS1#60 |
org.apache.activemq.network.DemandForwardingBridgeSupport |
triggerStartAsyncNetworkBridgeCreation:
remoteBroker=tcp://AON-CUAC01-LON1/10.250.242.29:61616@58562, localBroker=
vm://AON-CUAC01-AMS1#76
javax.jms.InvalidClientIDException: Broker: AON-CUAC01-AMS1 - Client:
Broker12Bridge_AON-CUAC01-LON1_inbound_AON-CUAC01-AMS1 already connected from
vm://AON-CUAC01-AMS1#60
at
org.apache.activemq.broker.region.RegionBroker.addConnection(RegionBroker.java:255)
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.util.LoggingBrokerPlugin.addConnection(LoggingBrokerPlugin.java:178)
at
org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:98)
at
org.apache.activemq.security.SimpleAuthenticationBroker.addConnection(SimpleAuthenticationBroker.java:77)
at
org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:103)
at
org.apache.activemq.broker.TransportConnection.processAddConnection(TransportConnection.java:817)
at
org.apache.activemq.command.ConnectionInfo.visit(ConnectionInfo.java:139)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:338)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:188)
at
org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:116)
at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
at
org.apache.activemq.transport.vm.VMTransport.doDispatch(VMTransport.java:162)
at
org.apache.activemq.transport.vm.VMTransport.dispatch(VMTransport.java:154)
at
org.apache.activemq.transport.vm.VMTransport.oneway(VMTransport.java:131)
at
org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:68)
at
org.apache.activemq.transport.ResponseCorrelator.asyncRequest(ResponseCorrelator.java:81)
at
org.apache.activemq.transport.ResponseCorrelator.request(ResponseCorrelator.java:86)
at
org.apache.activemq.network.DemandForwardingBridgeSupport.startLocalBridge(DemandForwardingBridgeSupport.java:468)
at
org.apache.activemq.network.DemandForwardingBridgeSupport.doStartLocalAndRemoteBridges(DemandForwardingBridgeSupport.java:421)
at
org.apache.activemq.network.DemandForwardingBridgeSupport.access$500(DemandForwardingBridgeSupport.java:105)
at
org.apache.activemq.network.DemandForwardingBridgeSupport$5.run(DemandForwardingBridgeSupport.java:336)
at java.lang.Thread.run(Thread.java:748)
2021-02-16 19:31:26,838 | DEBUG | stopping AON-CUAC01-AMS1 bridge to
AON-CUAC01-LON1 | org.apache.activemq.network.DemandForwardingBridgeSupport |
ActiveMQ BrokerService[AON-CUAC01-AMS1] Task-112
2021-02-16 19:31:26,839 | DEBUG | Failure occurred soon after the discovery
event was generated. It will be classified as a connection failure:
[tcp://AON-CUAC01-LON1:61616, failed:true, connectionFailures:2] |
org.apache.activemq.transport.discovery.simple.SimpleDiscoveryAgent | Simple
Discovery Agent-20
2021-02-16 19:31:26,839 | DEBUG | Waiting 4000 ms before attempting to
reconnect. |
org.apache.activemq.transport.discovery.simple.SimpleDiscoveryAgent | Simple
Discovery Agent-20
2021-02-16 19:31:26,839 | DEBUG | Stopping connection: vm://AON-CUAC01-AMS1#76
| org.apache.activemq.broker.TransportConnection | ActiveMQ
BrokerService[AON-CUAC01-AMS1] Task-114
2021-02-16 19:31:26,839 | DEBUG | Stopped transport: vm://AON-CUAC01-AMS1#76 |
org.apache.activemq.broker.TransportConnection | ActiveMQ
BrokerService[AON-CUAC01-AMS1] Task-114
2021-02-16 19:31:26,839 | DEBUG | Stopping transport
tcp://AON-CUAC01-LON1/10.250.242.29:61616@58562 |
org.apache.activemq.transport.tcp.TcpTransport | ActiveMQ
BrokerService[AON-CUAC01-AMS1] Task-112
2021-02-16 19:31:26,840 | DEBUG | Connection Stopped: vm://AON-CUAC01-AMS1#76 |
org.apache.activemq.broker.TransportConnection | ActiveMQ
BrokerService[AON-CUAC01-AMS1] Task-114
2021-02-16 19:31:26,840 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ Task]
using ExecutorService: null | org.apache.activemq.thread.TaskRunnerFactory |
ActiveMQ BrokerService[AON-CUAC01-AMS1] Task-112
2021-02-16 19:31:26,840 | DEBUG | Closed socket
Socket[addr=AON-CUAC01-LON1/10.250.242.29,port=61616,localport=58562] |
org.apache.activemq.transport.tcp.TcpTransport | ActiveMQ Task-1
2021-02-16 19:31:26,840 | DEBUG | Shutting down VM connectors for broker:
AON-CUAC01-AMS1 | org.apache.activemq.transport.vm.VMTransportFactory |
ActiveMQ BrokerService[AON-CUAC01-AMS1] Task-112
2021-02-16 19:31:26,841 | DEBUG | Stopping connection: vm://AON-CUAC01-AMS1#78
| org.apache.activemq.broker.TransportConnection | ActiveMQ
BrokerService[AON-CUAC01-AMS1] Task-115
2021-02-16 19:31:26,841 | DEBUG | Stopped transport: vm://AON-CUAC01-AMS1#78 |
org.apache.activemq.broker.TransportConnection | ActiveMQ
BrokerService[AON-CUAC01-AMS1] Task-115
2021-02-16 19:31:26,841 | DEBUG | Connection Stopped: vm://AON-CUAC01-AMS1#78 |
org.apache.activemq.broker.TransportConnection | ActiveMQ
BrokerService[AON-CUAC01-AMS1] Task-115
2021-02-16 19:31:26,841 | INFO | Connector vm://AON-CUAC01-AMS1 stopped |
org.apache.activemq.broker.TransportConnector | ActiveMQ
BrokerService[AON-CUAC01-AMS1] Task-112
2021-02-16 19:31:26,841 | INFO | AON-CUAC01-AMS1 bridge to AON-CUAC01-LON1
stopped | org.apache.activemq.network.DemandForwardingBridgeSupport | ActiveMQ
BrokerService[AON-CUAC01-AMS1] Task-112
{code}
I am not sure if this is exactly same issue as yours. Can you please comment?
> Already connected client makes it impossible to reuse client id after
> disconnection
> -----------------------------------------------------------------------------------
>
> Key: AMQ-7217
> URL: https://issues.apache.org/jira/browse/AMQ-7217
> Project: ActiveMQ
> Issue Type: Bug
> Components: Broker
> Affects Versions: 5.14.4, 5.15.9
> Reporter: Piotr
> Priority: Major
>
> 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:
> {noformat}
> 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)
> {noformat}
> 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):
> {code}
> this.delayedStop(2000, "Failed with SecurityException: " +
> var8.getLocalizedMessage(), var8);
> {code}
> the issue cannot be observed.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
