You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by kube <ia...@yahoo.com> on 2014/05/13 20:25:09 UTC

InvalidClientIDException between network brokers

Hi, 
   We have a three node network brokers set up and was working fine. (named
respectably, mq01, mq02 and mq03)
Recently we decided to separate the connector for topic from the connector
for queue, 
and we started to see exceptions flooding in broker's log like the
following:
javax.jms.InvalidClientIDException: Broker: mq01 - Client:
queueOnly_mq02_inbound_mq01 already connected from vm://mq01#76162 

1. The complete activemq.xml is attached at very bottom.
2. We are using ActiveMQ 5.9.0
3. The full stack trace is :
2014-05-12 14:47:51,140 | WARN | Failed to add Connection
mq01->mq02-34867-1399699310371-38095:1 |
org.apache.activemq.broker.TransportConnection |
triggerStartAsyncNetworkBridgeCreation:
remoteBroker=tcp://mq02.xxx.xxxxxxxx/192.168.42.33:61688@39099, localBroker=
vm://mq01#76164 
javax.jms.InvalidClientIDException: Broker: mq01 - Client:
queueOnly_mq02_inbound_mq01 already connected from vm://mq01#76162 
at
org.apache.activemq.broker.region.RegionBroker.addConnection(RegionBroker.java:243) 
at
org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:92) 
at
org.apache.activemq.advisory.AdvisoryBroker.addConnection(AdvisoryBroker.java:90) 
at
org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:92) 
at
org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:92) 
at
org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:97) 
at
org.apache.activemq.broker.TransportConnection.processAddConnection(TransportConnection.java:733) 
at org.apache.activemq.command.ConnectionInfo.visit(ConnectionInfo.java:139) 
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:292) 
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:149) 
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:138) 
at
org.apache.activemq.transport.vm.VMTransport.dispatch(VMTransport.java:127) 
at org.apache.activemq.transport.vm.VMTransport.oneway(VMTransport.java:104) 
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:420) 
at
org.apache.activemq.network.DemandForwardingBridgeSupport.doStartLocalAndRemoteBridges(DemandForwardingBridgeSupport.java:387) 
at
org.apache.activemq.network.DemandForwardingBridgeSupport.access$500(DemandForwardingBridgeSupport.java:73) 
at
org.apache.activemq.network.DemandForwardingBridgeSupport$5.run(DemandForwardingBridgeSupport.java:302) 
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) 
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) 
at java.lang.Thread.run(Thread.java:679)








***********************************************************************************************

<beans
  xmlns="http://www.springframework.org/schema/beans"
  xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
  xsi:schemaLocation="http://www.springframework.org/schema/beans
http://www.springframework.org/schema/beans/spring-beans.xsd
  http://activemq.apache.org/schema/core
http://activemq.apache.org/schema/core/activemq-core.xsd">

    
    <bean
class="org.springframework.beans.factory.config.PropertyPlaceholderConfigurer">
        <property name="locations">
            <value>file:${activemq.conf}/credentials.properties</value>
        </property>
    </bean>

    
    <bean id="logQuery"
class="org.fusesource.insight.log.log4j.Log4jLogQuery"
          lazy-init="false" scope="singleton"
          init-method="start" destroy-method="stop">
    </bean>

    
    <broker xmlns="http://activemq.apache.org/schema/core"
brokerName="${brokerName}" dataDirectory="${activemq.data}"
networkConnectorStartAsync="true">

        <destinationPolicy>
            <policyMap>
              <policyEntries>
                <policyEntry topic=">" >
                  <pendingMessageLimitStrategy>
                    <constantPendingMessageLimitStrategy limit="1000"/>
                  </pendingMessageLimitStrategy>
                </policyEntry>
                                <policyEntry queue=">" enableAudit="false"
queuePrefetch="10">
                                   <networkBridgeFilterFactory>
                                        
<conditionalNetworkBridgeFilterFactory replayWhenNoConsumers="true"/>
                                   </networkBridgeFilterFactory>
                                <deadLetterStrategy>
                                   <individualDeadLetterStrategy
queuePrefix="DLQ." useQueueForQueueMessages="true" />
                                </deadLetterStrategy>

                                </policyEntry>

              </policyEntries>
            </policyMap>
        </destinationPolicy>

        <managementContext>
            <managementContext createConnector="true"/>
        </managementContext>

        <persistenceAdapter>
            <kahaDB directory="${activemq.data}/kahadb"
concurrentStoreAndDispatchQueues="false"/>
        </persistenceAdapter>


          <systemUsage>
            <systemUsage sendFailIfNoSpaceAfterTimeout="30000">
                <memoryUsage>
                    <memoryUsage percentOfJvmHeap="70" />
                </memoryUsage>
                <storeUsage>
                    <storeUsage limit="100 gb"/>
                </storeUsage>
                <tempUsage>
                    <tempUsage limit="50 gb"/>
                </tempUsage>
            </systemUsage>
        </systemUsage>

        <networkConnectors>
                        <networkConnector name="topicOnly"
uri="multicast://default" networkTTL="3">
                                <dynamicallyIncludedDestinations>
                                        <topic physicalName=">"/>
                                </dynamicallyIncludedDestinations>
                        <excludedDestinations>
                                <topic physicalName="VirtualTopic.>"/>
                        </excludedDestinations>
                        </networkConnector>
                        <networkConnector name="queueOnly"
uri="multicast://default" conduitSubscriptions="false" networkTTL="3">
                                <dynamicallyIncludedDestinations>
                        <queue physicalName=">"/>
                        </dynamicallyIncludedDestinations>
                        </networkConnector>
                </networkConnectors>


        <transportConnectors>
            <transportConnector name="default" uri="nio://0.0.0.0:61688"
discoveryUri="multicast://default" updateClusterClients="true"
rebalanceClusterClients="true" updateClusterClientsOnRemove="true"/>
                        <transportConnector name="stomp+nio"
uri="stomp+nio://0.0.0.0:61613" discoveryUri="multicast://default"
updateClusterClients="true" rebalanceClusterClients="true"
updateClusterClientsOnRemove="true"/>
        </transportConnectors>

        <shutdownHooks>
            <bean xmlns="http://www.springframework.org/schema/beans"
class="org.apache.activemq.hooks.SpringContextHook" />
        </shutdownHooks>

    </broker>


    <import resource="jetty.xml"/>

</beans>



**************************

Any input/help is very much appreciated.

thanks





--
View this message in context: http://activemq.2283324.n4.nabble.com/InvalidClientIDException-between-network-brokers-tp4681090.html
Sent from the ActiveMQ - Dev mailing list archive at Nabble.com.

Re: InvalidClientIDException between network brokers

Posted by kube <ia...@yahoo.com>.
After turning on the trace, here is that pattern we found.

1. connection issue detected at 2014-05-21 17:13:17,008 for vm://mq01#68026
2. MulticastDiscoveryAgent detected issue at 17:13:17,009, decides to wait
for 5 seconds
3. Stopping connection at 2014-05-21 17:13:17,015
4. Stopping transport at 2014-05-21 17:13:17,016
5. Cleaning up connection resources: vm://mq01#68026 at 2014-05-21
17:13:17,016
6. remove connection id: mq01->mq02-46052-1400304319531-34022:1 at
2014-05-21 17:13:17,016 
7. Unregistering MBean for consumer/producers starting from 2014-05-21
17:13:17,017
8. MulticastDiscoveryAgent kicking off recovery at 17:13:22, failed,
InvalidClientIDException logged,  wating 5 seconds
9. MulticastDiscoveryAgent kicking off recovery at 17:13:28, failed,
InvalidClientIDException logged,  wating 5 seconds
10. MulticastDiscoveryAgent kicking off recovery at 17:13:34, failed,
InvalidClientIDException logged,  wating 5 seconds
11. Unregistering MBean for consumer/producers completed at 2014-05-21
17:13:37,975
12. Connection Stopped: vm://mq01#68026 at 2014-05-21 17:13:38,012
13. MulticastDiscoveryAgent kicking off recovery at 17:13:39, and succeeded


The InvalidClientIDException we saw is actually indicating:
1. connection stopping process is till going on, the  recovery attempts
kicked of by MulticastDiscoveryAgent is not able to go through  (and
shouldn't)
2. that fact that we saw 4  InvalidClientIDException in a row after a
"connection issue" seems caused by the long running resource cleaning
up(like MBeans/consumers)
3. from the log the cleaning process is done by a single thread, and it
takes 40 milli seconds to unregister a subscription ( I am seeing remote
consumers mostly).
for instance =====> 
./mq01/tracemq01.log:2014-05-21 17:13:30,811 | DEBUG | mq01 removing
consumer: mq01->mq02-46052-1400304319531-34022:1:1:274 for destination:
queue://Template | org.apache.activemq.broker.region.AbstractRegion |
ActiveMQ BrokerService[mq01] Task-22226
./mq01/tracemq01.log:2014-05-21 17:13:30,849 | DEBUG | mq01 removing
consumer: mq01->mq02-46052-1400304319531-34022:1:1:238 for destination:
queue://Template | org.apache.activemq.broker.region.AbstractRegion |
ActiveMQ BrokerService[mq01] Task-22226

4. since we saw have 500+ remote consumers on it. 
each time a connection issue happen, it takes  30~40 seconds to clean up the
resources and reestablish new one. 


Questions:
1. is 500+ consumers on single broker node consider to be too much for a
broker?
2. is not the 30~40 per destination performance too slow? is it normal? any
way to tune it up?   
3. shouldn't the clean up process running in parallel?  


 



--
View this message in context: http://activemq.2283324.n4.nabble.com/InvalidClientIDException-between-network-brokers-tp4681090p4681383.html
Sent from the ActiveMQ - Dev mailing list archive at Nabble.com.