activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Edwin Yu (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (AMQ-4097) Broker-to-Broker Reconnect fails wrongly due to duplicate name
Date Thu, 15 Nov 2012 19:45:15 GMT

    [ https://issues.apache.org/jira/browse/AMQ-4097?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13498277#comment-13498277
] 

Edwin Yu commented on AMQ-4097:
-------------------------------

We also encountered this error in our load testing lab when we had an actual network disruption.
 We repeated the scenario by disconnecting and reconnecting the network cable.  If we had
a long break between the disconnection and reconnection, our network of brokers establish
connections just fine.  If we had a very short break (less than a minute) between the disconnection
and reconnection while the load is high, we encountered this issue.  Below is the error in
the log.

2012-11-15 08:37:08,953 WARN   [ActiveMQ Transport: tcp://n4-perform70/10.40.100.17:61613]
[DemandForwardingBridgeSupport:363] (   ) Network connection between vm://local-amq-broker#68046
and tcp://n4-perform70/10.40.100.17:61613 shutdown due to a remote error: javax.jms.InvalidClientIDException:
Broker: amq-broker - Client: center-to-amq-broker_outbound already connected from tcp://10.47.103.25:51353

We are not using the duplex connection.  We're using ActiveMQ 5.6.0.
regards.
                
> Broker-to-Broker Reconnect fails wrongly due to duplicate name
> --------------------------------------------------------------
>
>                 Key: AMQ-4097
>                 URL: https://issues.apache.org/jira/browse/AMQ-4097
>             Project: ActiveMQ
>          Issue Type: Bug
>    Affects Versions: 5.7.0
>         Environment: A central broker to which a lot (50+) of external brokers connect
with a duplex bridge. A special routing/firewall is used which can affect timing but not order
of TCP packets. This can be simulated by using socat.
> Actually we are using 5.7-SNAPSHOT of 2012-08-31.
>            Reporter: Ron Koerner
>
> The situation is as follows:
> - an external broker A connects
> - time passes
> - a lot of external brokers disconnect including A
> - A reconnects (as well as all the other external brokers)
> - wrong message about duplicate name is generated
> In the log it looks like this:
> {code}
> 2012-10-08 17:11:19,835 INFO  .DemandForwardingBridgeSupport - Network connection between
vm://c04ptec#278 and tcp:///127.0.0.1:54191(cbox-56BU902442) has been established. [StartLocalBridge:
localBroker=vm://c04ptec#278]
> ...
> ... a lot more of the following with different ports
> 2012-10-08 17:37:01,958 WARN  .DemandForwardingBridgeSupport - Network connection between
vm://c04ptec#278 and tcp:///127.0.0.1:54191 shutdown due to a remote error: java.io.EOFException
[ActiveMQ NIO Worker 193]
> ... more of these
> 2012-10-08 17:37:03,438 INFO  emq.broker.TransportConnection - Started responder end
of duplex bridge cBox 56BU902442 to cBox Proxy@ID:P013SPWMK1WN-39320-1349704902319-0:1 [ActiveMQ
NIO Worker 215]
> ...
> 2012-10-08 17:37:03,922 WARN  emq.broker.TransportConnection - Failed to add Connection
ID:c04ptec-51799-1349706422094-242:2, reason: javax.jms.InvalidClientIDException: Broker:
c04ptec - Client: cBox 56BU902442 to cBox Proxy_cbox-56BU902442_inbound_c04ptec already connected
from vm://c04ptec#278 [StartLocalBridge: localBroker=vm://c04ptec#478]
> 2012-10-08 17:37:03,923 INFO  .DemandForwardingBridgeSupport - Network connection between
vm://c04ptec#478 and tcp:///127.0.0.1:56529 shutdown due to a local error: javax.jms.InvalidClientIDException:
Broker: c04ptec - Client: cBox 56BU902442 to cBox Proxy_cbox-56BU902442_inbound_c04ptec already
connected from vm://c04ptec#278 [StartLocalBridge: localBroker=vm://c04ptec#478]
> ...
> 2012-10-08 17:37:04,036 INFO  .DemandForwardingBridgeSupport - c04ptec bridge to cbox-56BU902442
stopped [ActiveMQ Task-182]
> ...
> 2012-10-08 17:37:06,540 INFO  emq.broker.TransportConnection - Started responder end
of duplex bridge cBox 56BU902442 to cBox Proxy@ID:P013SPWMK1WN-39320-1349704902319-0:1 [ActiveMQ
NIO Worker 207]
> ...
> 2012-10-08 17:37:06,548 WARN  emq.broker.TransportConnection - Failed to add Connection
ID:c04ptec-51799-1349706422094-292:1, reason: javax.jms.InvalidClientIDException: Broker:
c04ptec - Client: cBox 56BU902442 to cBox Proxy_cbox-56BU902442_inbound_c04ptec already connected
from vm://c04ptec#278 [StartLocalBridge: localBroker=vm://c04ptec#570]
> 2012-10-08 17:37:06,548 INFO  .DemandForwardingBridgeSupport - Network connection between
vm://c04ptec#570 and tcp:///127.0.0.1:56576 shutdown due to a local error: javax.jms.InvalidClientIDException:
Broker: c04ptec - Client: cBox 56BU902442 to cBox Proxy_cbox-56BU902442_inbound_c04ptec already
connected from vm://c04ptec#278 [StartLocalBridge: localBroker=vm://c04ptec#570]
> ...
> 2012-10-08 17:37:06,559 INFO  .DemandForwardingBridgeSupport - c04ptec bridge to cbox-56BU902442
stopped [ActiveMQ Task-204]
> ...
> 2012-10-08 17:37:24,417 INFO  .DemandForwardingBridgeSupport - c04ptec bridge to cbox-56BU902442
stopped [ActiveMQ Task-73]
> ...
> 2012-10-08 17:37:25,103 INFO  emq.broker.TransportConnection - Started responder end
of duplex bridge cBox 56BU902442 to cBox Proxy@ID:P013SPWMK1WN-39320-1349704902319-0:1 [ActiveMQ
NIO Worker 268]
> ...
> 2012-10-08 17:37:29,110 INFO  .DemandForwardingBridgeSupport - Network connection between
vm://c04ptec#594 and tcp:///127.0.0.1:56656(cbox-56BU902442) has been established. [StartLocalBridge:
localBroker=vm://c04ptec#594]
> ...
> 2012-10-08 17:37:59,669 WARN  .DemandForwardingBridgeSupport - Network connection between
vm://c04ptec#594 and tcp:///127.0.0.1:56656(cbox-56BU902442) was interrupted during establishment.
[StartLocalBridge: localBroker=vm://c04ptec#594]
> ...
> 2012-10-08 17:38:09,005 INFO  .DemandForwardingBridgeSupport - c04ptec bridge to cbox-56BU902442
stopped [ActiveMQ Task-228]
> ...
> 2012-10-08 17:38:18,681 INFO  emq.broker.TransportConnection - Started responder end
of duplex bridge cBox 56BU902442 to cBox Proxy@ID:P013SPWMK1WN-39320-1349704902319-0:1 [ActiveMQ
NIO Worker 292]
> 2012-10-08 17:38:18,681 WARN  emq.broker.TransportConnection - Failed to add Connection
ID:P013SPWMK1WN-39320-1349704902319-152:1, reason: javax.jms.InvalidClientIDException: Broker:
c04ptec - Client: cBox 56BU902442 to cBox Proxy_cbox-56BU902442_outbound already connected
from vm://c04ptec#594 [ActiveMQ NIO Worker 292]
> 2012-10-08 17:38:18,682 WARN  er.TransportConnection.Service - Async error occurred:
javax.jms.InvalidClientIDException: Broker: c04ptec - Client: cBox 56BU902442 to cBox Proxy_cbox-56BU902442_outbound
already connected from vm://c04ptec#594 [ActiveMQ NIO Worker 292]
> javax.jms.InvalidClientIDException: Broker: c04ptec - Client: cBox 56BU902442 to cBox
Proxy_cbox-56BU902442_outbound already connected from vm://c04ptec#594
>         at org.apache.activemq.broker.region.RegionBroker.addConnection(RegionBroker.java:222)
~[activemq-core-5.7-SNAPSHOT.jar:5.7-SNAPSHOT]
> {code}
> This repeats until the external broker is stopped and started manually.
> I assume there is a race condition which shows up under high load preventing the information
about the disconnected client to be removed before the same client reconnects.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message