You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by Gary Tully <ga...@gmail.com> on 2013/05/02 14:57:09 UTC
Re: Slow Failover
on your clients, enable trace level logging for :
org.apache.activemq.transport.failover.FailoverTransport
that will help you see what is going on under the hood till the
reconnect occurs.
There could be some dns/ip matching issues between the client and the brokers.
post the logging output if you need some more input.
there were a few fixes in this area in the past weeks on trunk so it
may be something that has been resolved or there is a workaround for.
On 29 April 2013 17:31, thomas.r.parkinson <th...@gmail.com> wrote:
> Hello Ladies and Gentlemen,
>
> Having a problem using the failover protocol to connect to another broker
> when the connection to the current broker dies. The client is taking a long
> time about 1min and 15 seconds to failover to another known broker. Is
> there are configuration options i can use to improve this such that clients
> failover faster?
>
> I've tried using the backup=true on client connection but that makes no
> difference!
>
> Using activeMq 5.8 three brokers using static network protocol all three
> brokers create duplex connection to each other.
>
> Were using update configuration properties:
> updateClusterClients="true"
> rebalanceClusterClients="true"
> updateClusterClientsOnRemove="true"
>
> So we can scale and rebalance the cluster at will depending on demand.
>
> Clients are connecting with configuration uri:
> failover:(tcp://" + brokerIp +
> ":61616)?useExponentialBackOff=false&updateURIsSupported=true
>
> Sample config from one brokers:
> <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>
>
> <broker xmlns="http://activemq.apache.org/schema/core"
> useJmx="true"
> brokerName="amq-node-1"
> dataDirectory="${activemq.data}"
> networkConnectorStartAsync="true">
>
> <destinationPolicy>
> <policyMap>
> <policyEntries>
> <policyEntry topic=">" producerFlowControl="true">
> <pendingMessageLimitStrategy>
> <constantPendingMessageLimitStrategy
> limit="100000"/>
> </pendingMessageLimitStrategy>
> </policyEntry>
> <policyEntry queue=">" producerFlowControl="true"
> queuePrefetch="1">
> <pendingMessageLimitStrategy>
> <constantPendingMessageLimitStrategy
> limit="100000"/>
> </pendingMessageLimitStrategy>
> </policyEntry>
> </policyEntries>
> </policyMap>
> </destinationPolicy>
>
>
> <managementContext>
> <managementContext createConnector="true"/>
> </managementContext>
>
>
> <persistenceAdapter>
> <kahaDB
> directory="${activemq.data}/kahadb"
> indexCacheSize="131072"/>
> </persistenceAdapter>
>
> <systemUsage>
> <systemUsage>
> <memoryUsage>
> <memoryUsage limit="2 gb"/>
> </memoryUsage>
> <storeUsage>
> <storeUsage limit="50 gb"/>
> </storeUsage>
> <tempUsage>
> <tempUsage limit="20 gb"/>
> </tempUsage>
> </systemUsage>
> </systemUsage>
>
> <networkConnectors>
> <networkConnector name="amq-node-1-amq-node-3-queuesOnly"
>
> uri="static:(tcp://172.27.1.137:61616?connectionTimeout=5000)?maxReconnectDelay=5000"
> networkTTL="1"
> conduitSubscriptions="false"
> duplex="true">
> <dynamicallyIncludedDestinations>
> <queue physicalName=">"/>
> </dynamicallyIncludedDestinations>
> </networkConnector>
> <networkConnector name="amq-node-1-amq-node-3-topicsOnly"
>
> uri="static:(tcp://172.27.1.137:61616?connectionTimeout=5000)?maxReconnectDelay=5000"
> networkTTL="1"
> suppressDuplicateQueueSubscriptions="true"
> duplex="true">
> <dynamicallyIncludedDestinations>
> <topic physicalName=">"/>
> </dynamicallyIncludedDestinations>
> </networkConnector>
> <networkConnector name="amq-node-1-amq-node-2-queuesOnly"
>
> uri="static:(tcp://172.27.1.113:61616?connectionTimeout=5000)?maxReconnectDelay=5000"
> networkTTL="1"
> conduitSubscriptions="false"
> duplex="true">
> <dynamicallyIncludedDestinations>
> <queue physicalName=">"/>
> </dynamicallyIncludedDestinations>
> </networkConnector>
> <networkConnector name="amq-node-1-amq-node-2-topicsOnly"
>
> uri="static:(tcp://172.27.1.113:61616?connectionTimeout=5000)?maxReconnectDelay=5000"
> networkTTL="1"
> suppressDuplicateQueueSubscriptions="true"
> duplex="true">
> <dynamicallyIncludedDestinations>
> <topic physicalName=">"/>
> </dynamicallyIncludedDestinations>
> </networkConnector>
> </networkConnectors>
>
>
> <transportConnectors>
>
> <transportConnector name="openwire"
> uri="tcp://0.0.0.0:61616?maximumConnections=1000&wireformat.maxFrameSize=104857600"
> updateClusterClients="true"
> rebalanceClusterClients="true"
> updateClusterClientsOnRemove="true"
> />
> <transportConnector name="stomp" uri="stomp://0.0.0.0:61613"/>
> </transportConnectors>
>
>
> <shutdownHooks>
> <bean xmlns="http://www.springframework.org/schema/beans"
> class="org.apache.activemq.hooks.SpringContextHook" />
> </shutdownHooks>
>
>
> <plugins>
> <statisticsBrokerPlugin/>
> </plugins>
>
> </broker>
>
>
> <import resource="jetty.xml"/>
>
> </beans>
>
> Any help would be greatly appreciated.
>
> Thank you
>
> Tom Parkinson
>
>
>
> --
> View this message in context: http://activemq.2283324.n4.nabble.com/Slow-Failover-tp4666393.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
--
http://redhat.com
http://blog.garytully.com
Re: Slow Failover
Posted by Gary Tully <ga...@gmail.com>.
To recognise the dead sockets that result from the cable pull more
promptly, reduce the default inactivity monitor timeouts: see:
http://activemq.apache.org/activemq-inactivitymonitor.html
If you want failover to retry immediately, reduce the failover
reconnectDelay to a few seconds.
http://activemq.apache.org/failover-transport-reference.html
On 2 May 2013 14:51, thomas.r.parkinson <th...@gmail.com> wrote:
> Creating two producers using Spring JMS template and two consumers using
> spring DefaultMessageListenerContainer. Using a ActiveMQConnectionFactory
> for both.
>
> When i pull the network cable on broker 4 i see an exception in the jms
> template about 30 seconds after then 30 seconds after that i see
> Failover.FailoverTransport: Waking up reconnect task then then 15 seconds
> later the re-connect happens.
>
> Any ideas?
>
> Logging output:
>
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Reconnect
> was triggered but transport is not started yet. Wait for start to connect
> the transport.
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Reconnect
> was triggered but transport is not started yet. Wait for start to connect
> the transport.
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Reconnect
> was triggered but transport is not started yet. Wait for start to connect
> the transport.
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Started
> unconnected
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Started
> unconnected
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Started
> unconnected
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
> reconnect task
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
> reconnect task
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
> reconnect task
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: urlList
> connectionList:[tcp://amq-node-4:61616], from: [tcp://amq-node-4:61616]
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: urlList
> connectionList:[tcp://amq-node-4:61616], from: [tcp://amq-node-4:61616]
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: urlList
> connectionList:[tcp://amq-node-4:61616], from: [tcp://amq-node-4:61616]
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Attempting
> 0th connect to: tcp://amq-node-4:61616
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Attempting
> 0th connect to: tcp://amq-node-4:61616
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Attempting
> 0th connect to: tcp://amq-node-4:61616
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Connection
> established
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Connection
> established
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Connection
> established
> [02/05/13 02:40:48:048 BST] INFO - failover.FailoverTransport: Successfully
> connected to tcp://amq-node-4:61616
> [02/05/13 02:40:48:048 BST] INFO - failover.FailoverTransport: Successfully
> connected to tcp://amq-node-4:61616
> [02/05/13 02:40:48:048 BST] INFO - failover.FailoverTransport: Successfully
> connected to tcp://amq-node-4:61616
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
> reconnect task
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
> reconnect task
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Doing
> rebalance from: tcp://amq-node-4:61616 to [tcp://amq-node-5:61616,
> tcp://amq-node-4:61616]
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
> reconnect task
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Doing
> rebalance from: tcp://amq-node-4:61616 to [tcp://amq-node-5:61616,
> tcp://amq-node-4:61616]
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waiting 10
> ms before attempting connection.
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waiting 10
> ms before attempting connection.
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Attempting
> 0th connect to: tcp://amq-node-5:61616
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Attempting
> 0th connect to: tcp://amq-node-5:61616
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Connection
> established
> [02/05/13 02:40:48:048 BST] INFO - failover.FailoverTransport: Successfully
> reconnected to tcp://amq-node-5:61616
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Connection
> established
> [02/05/13 02:40:48:048 BST] INFO - failover.FailoverTransport: Successfully
> reconnected to tcp://amq-node-5:61616
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Reconnect
> was triggered but transport is not started yet. Wait for start to connect
> the transport.
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Started
> unconnected
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
> reconnect task
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: urlList
> connectionList:[tcp://amq-node-4:61616], from: [tcp://amq-node-4:61616]
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Attempting
> 0th connect to: tcp://amq-node-4:61616
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Connection
> established
> [02/05/13 02:40:48:048 BST] INFO - failover.FailoverTransport: Successfully
> connected to tcp://amq-node-4:61616
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
> reconnect task
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Doing
> rebalance from: tcp://amq-node-4:61616 to [tcp://amq-node-5:61616,
> tcp://amq-node-4:61616]
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waiting 10
> ms before attempting connection.
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Attempting
> 0th connect to: tcp://amq-node-5:61616
> [02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Connection
> established
> [02/05/13 02:40:48:048 BST] INFO - failover.FailoverTransport: Successfully
> reconnected to tcp://amq-node-5:61616
> Exception in thread "pool-1-thread-2"
> org.springframework.jms.UncategorizedJmsException: Uncategorized exception
> occured during JMS processing; nested exception is javax.jms.JMSException:
> org.apache.activemq.transport.RequestTimedOutIOException
> at
> org.springframework.jms.support.JmsUtils.convertJmsAccessException(JmsUtils.java:316)
> at
> org.springframework.jms.support.JmsAccessor.convertJmsAccessException(JmsAccessor.java:168)
> at org.springframework.jms.core.JmsTemplate.execute(JmsTemplate.java:469)
> at org.springframework.jms.core.JmsTemplate.send(JmsTemplate.java:534)
> at
> com.brightpearl.mq.resource.dispatch.ActiveMqResourceEventDispatcher.dispatchToQueue(ActiveMqResourceEventDispatcher.java:160)
> at
> com.brightpearl.mq.resource.dispatch.ActiveMqResourceEventDispatcher.dispatchCreation(ActiveMqResourceEventDispatcher.java:134)
> at com.brightpearl.mq.it.Producer.produceMessages(Producer.java:59)
> at com.brightpearl.mq.it.Producer.run(Producer.java:65)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:722)
> Caused by: javax.jms.JMSException:
> org.apache.activemq.transport.RequestTimedOutIOException
> at
> org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:62)
> at
> org.apache.activemq.ActiveMQConnection.doSyncSendPacket(ActiveMQConnection.java:1445)
> at
> org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1425)
> at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1796)
> at
> org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:289)
> at
> org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:224)
> at
> org.apache.activemq.ActiveMQMessageProducerSupport.send(ActiveMQMessageProducerSupport.java:241)
> at org.springframework.jms.core.JmsTemplate.doSend(JmsTemplate.java:592)
> at org.springframework.jms.core.JmsTemplate.doSend(JmsTemplate.java:569)
> at org.springframework.jms.core.JmsTemplate$3.doInJms(JmsTemplate.java:536)
> at org.springframework.jms.core.JmsTemplate.execute(JmsTemplate.java:466)
> ... 8 more
> Caused by: org.apache.activemq.transport.RequestTimedOutIOException
> at
> org.apache.activemq.transport.FutureResponse.getResult(FutureResponse.java:54)
> at
> org.apache.activemq.transport.ResponseCorrelator.request(ResponseCorrelator.java:92)
> at
> org.apache.activemq.ActiveMQConnection.doSyncSendPacket(ActiveMQConnection.java:1432)
> ... 17 more
> [02/05/13 02:42:15:015 BST] DEBUG - failover.FailoverTransport: Waking up
> reconnect task
> [02/05/13 02:42:28:028 BST] TRACE - failover.FailoverTransport:
> tcp://amq-node-5:61616 handleTransportFailure:
> org.apache.activemq.transport.InactivityIOException: Channel was inactive
> for too (>30000) long: tcp://172.27.1.126:61616
> [02/05/13 02:42:28:028 BST] TRACE - failover.FailoverTransport:
> tcp://amq-node-5:61616 handleTransportFailure:
> org.apache.activemq.transport.InactivityIOException: Channel was inactive
> for too (>30000) long: tcp://172.27.1.126:61616
> [02/05/13 02:42:28:028 BST] WARN - failover.FailoverTransport: Transport
> (tcp://172.27.1.126:61616) failed, reason:
> org.apache.activemq.transport.InactivityIOException: Channel was inactive
> for too (>30000) long: tcp://172.27.1.126:61616, attempting to automatically
> reconnect
> [02/05/13 02:42:28:028 BST] WARN - failover.FailoverTransport: Transport
> (tcp://172.27.1.126:61616) failed, reason:
> org.apache.activemq.transport.InactivityIOException: Channel was inactive
> for too (>30000) long: tcp://172.27.1.126:61616, attempting to automatically
> reconnect
> [02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Waiting 10
> ms before attempting connection.
> [02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Waiting 10
> ms before attempting connection.
> [02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Attempting
> 0th connect to: tcp://amq-node-4:61616
> [02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Attempting
> 0th connect to: tcp://amq-node-4:61616
> [02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Connection
> established
> [02/05/13 02:42:28:028 BST] INFO - failover.FailoverTransport: Successfully
> reconnected to tcp://amq-node-4:61616
> [02/05/13 02:42:28:028 BST] TRACE - failover.FailoverTransport: restore
> requestMap, replay: ActiveMQTextMessage {commandId = 31302, responseRequired
> = true, messageId = ID:tom-OptiPlex-9010-38261-1367502048498-4:1:5217:1:1,
> originalDestination = null, originalTransactionId = null, producerId =
> ID:tom-OptiPlex-9010-38261-1367502048498-4:1:5217:1, destination =
> topic://VirtualTopic.resource.tom.created, transactionId = null, expiration
> = 0, timestamp = 1367502070257, arrival = 0, brokerInTime = 0, brokerOutTime
> = 0, correlationId = null, replyTo = null, persistent = true, type = null,
> priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null,
> compressed = false, userID = null, content =
> org.apache.activemq.util.ByteSequence@51a82311, marshalledProperties =
> org.apache.activemq.util.ByteSequence@75965af8, dataStructure = null,
> redeliveryCounter = 0, size = 0, properties = {account-id=ba,
> account-version=admindev}, readOnlyProperties = true, readOnlyBody = true,
> droppable = false, text =
> {"accountId":"ba","accountVersion":"admindev"...nalData":{}}}
> [02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Connection
> established
> [02/05/13 02:42:28:028 BST] INFO - failover.FailoverTransport: Successfully
> reconnected to tcp://amq-node-4:61616
> [02/05/13 02:42:28:028 BST] TRACE - failover.FailoverTransport:
> tcp://amq-node-5:61616 handleTransportFailure:
> org.apache.activemq.transport.InactivityIOException: Channel was inactive
> for too (>30000) long: tcp://172.27.1.126:61616
> [02/05/13 02:42:28:028 BST] WARN - failover.FailoverTransport: Transport
> (tcp://172.27.1.126:61616) failed, reason:
> org.apache.activemq.transport.InactivityIOException: Channel was inactive
> for too (>30000) long: tcp://172.27.1.126:61616, attempting to automatically
> reconnect
> [02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Waiting 10
> ms before attempting connection.
> [02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Attempting
> 0th connect to: tcp://amq-node-4:61616
> [02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Connection
> established
> [02/05/13 02:42:28:028 BST] INFO - failover.FailoverTransport: Successfully
> reconnected to tcp://amq-node-4:61616
>
>
>
> --
> View this message in context: http://activemq.2283324.n4.nabble.com/Slow-Failover-tp4666393p4666579.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
--
http://redhat.com
http://blog.garytully.com
Re: Slow Failover
Posted by "thomas.r.parkinson" <th...@gmail.com>.
Creating two producers using Spring JMS template and two consumers using
spring DefaultMessageListenerContainer. Using a ActiveMQConnectionFactory
for both.
When i pull the network cable on broker 4 i see an exception in the jms
template about 30 seconds after then 30 seconds after that i see
Failover.FailoverTransport: Waking up reconnect task then then 15 seconds
later the re-connect happens.
Any ideas?
Logging output:
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Reconnect
was triggered but transport is not started yet. Wait for start to connect
the transport.
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Reconnect
was triggered but transport is not started yet. Wait for start to connect
the transport.
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Reconnect
was triggered but transport is not started yet. Wait for start to connect
the transport.
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Started
unconnected
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Started
unconnected
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Started
unconnected
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
reconnect task
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
reconnect task
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
reconnect task
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: urlList
connectionList:[tcp://amq-node-4:61616], from: [tcp://amq-node-4:61616]
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: urlList
connectionList:[tcp://amq-node-4:61616], from: [tcp://amq-node-4:61616]
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: urlList
connectionList:[tcp://amq-node-4:61616], from: [tcp://amq-node-4:61616]
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Attempting
0th connect to: tcp://amq-node-4:61616
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Attempting
0th connect to: tcp://amq-node-4:61616
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Attempting
0th connect to: tcp://amq-node-4:61616
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Connection
established
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Connection
established
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Connection
established
[02/05/13 02:40:48:048 BST] INFO - failover.FailoverTransport: Successfully
connected to tcp://amq-node-4:61616
[02/05/13 02:40:48:048 BST] INFO - failover.FailoverTransport: Successfully
connected to tcp://amq-node-4:61616
[02/05/13 02:40:48:048 BST] INFO - failover.FailoverTransport: Successfully
connected to tcp://amq-node-4:61616
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
reconnect task
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
reconnect task
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Doing
rebalance from: tcp://amq-node-4:61616 to [tcp://amq-node-5:61616,
tcp://amq-node-4:61616]
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
reconnect task
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Doing
rebalance from: tcp://amq-node-4:61616 to [tcp://amq-node-5:61616,
tcp://amq-node-4:61616]
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waiting 10
ms before attempting connection.
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waiting 10
ms before attempting connection.
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Attempting
0th connect to: tcp://amq-node-5:61616
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Attempting
0th connect to: tcp://amq-node-5:61616
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Connection
established
[02/05/13 02:40:48:048 BST] INFO - failover.FailoverTransport: Successfully
reconnected to tcp://amq-node-5:61616
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Connection
established
[02/05/13 02:40:48:048 BST] INFO - failover.FailoverTransport: Successfully
reconnected to tcp://amq-node-5:61616
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Reconnect
was triggered but transport is not started yet. Wait for start to connect
the transport.
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Started
unconnected
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
reconnect task
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: urlList
connectionList:[tcp://amq-node-4:61616], from: [tcp://amq-node-4:61616]
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Attempting
0th connect to: tcp://amq-node-4:61616
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Connection
established
[02/05/13 02:40:48:048 BST] INFO - failover.FailoverTransport: Successfully
connected to tcp://amq-node-4:61616
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waking up
reconnect task
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Doing
rebalance from: tcp://amq-node-4:61616 to [tcp://amq-node-5:61616,
tcp://amq-node-4:61616]
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Waiting 10
ms before attempting connection.
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Attempting
0th connect to: tcp://amq-node-5:61616
[02/05/13 02:40:48:048 BST] DEBUG - failover.FailoverTransport: Connection
established
[02/05/13 02:40:48:048 BST] INFO - failover.FailoverTransport: Successfully
reconnected to tcp://amq-node-5:61616
Exception in thread "pool-1-thread-2"
org.springframework.jms.UncategorizedJmsException: Uncategorized exception
occured during JMS processing; nested exception is javax.jms.JMSException:
org.apache.activemq.transport.RequestTimedOutIOException
at
org.springframework.jms.support.JmsUtils.convertJmsAccessException(JmsUtils.java:316)
at
org.springframework.jms.support.JmsAccessor.convertJmsAccessException(JmsAccessor.java:168)
at org.springframework.jms.core.JmsTemplate.execute(JmsTemplate.java:469)
at org.springframework.jms.core.JmsTemplate.send(JmsTemplate.java:534)
at
com.brightpearl.mq.resource.dispatch.ActiveMqResourceEventDispatcher.dispatchToQueue(ActiveMqResourceEventDispatcher.java:160)
at
com.brightpearl.mq.resource.dispatch.ActiveMqResourceEventDispatcher.dispatchCreation(ActiveMqResourceEventDispatcher.java:134)
at com.brightpearl.mq.it.Producer.produceMessages(Producer.java:59)
at com.brightpearl.mq.it.Producer.run(Producer.java:65)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:722)
Caused by: javax.jms.JMSException:
org.apache.activemq.transport.RequestTimedOutIOException
at
org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:62)
at
org.apache.activemq.ActiveMQConnection.doSyncSendPacket(ActiveMQConnection.java:1445)
at
org.apache.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1425)
at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1796)
at
org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:289)
at
org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:224)
at
org.apache.activemq.ActiveMQMessageProducerSupport.send(ActiveMQMessageProducerSupport.java:241)
at org.springframework.jms.core.JmsTemplate.doSend(JmsTemplate.java:592)
at org.springframework.jms.core.JmsTemplate.doSend(JmsTemplate.java:569)
at org.springframework.jms.core.JmsTemplate$3.doInJms(JmsTemplate.java:536)
at org.springframework.jms.core.JmsTemplate.execute(JmsTemplate.java:466)
... 8 more
Caused by: org.apache.activemq.transport.RequestTimedOutIOException
at
org.apache.activemq.transport.FutureResponse.getResult(FutureResponse.java:54)
at
org.apache.activemq.transport.ResponseCorrelator.request(ResponseCorrelator.java:92)
at
org.apache.activemq.ActiveMQConnection.doSyncSendPacket(ActiveMQConnection.java:1432)
... 17 more
[02/05/13 02:42:15:015 BST] DEBUG - failover.FailoverTransport: Waking up
reconnect task
[02/05/13 02:42:28:028 BST] TRACE - failover.FailoverTransport:
tcp://amq-node-5:61616 handleTransportFailure:
org.apache.activemq.transport.InactivityIOException: Channel was inactive
for too (>30000) long: tcp://172.27.1.126:61616
[02/05/13 02:42:28:028 BST] TRACE - failover.FailoverTransport:
tcp://amq-node-5:61616 handleTransportFailure:
org.apache.activemq.transport.InactivityIOException: Channel was inactive
for too (>30000) long: tcp://172.27.1.126:61616
[02/05/13 02:42:28:028 BST] WARN - failover.FailoverTransport: Transport
(tcp://172.27.1.126:61616) failed, reason:
org.apache.activemq.transport.InactivityIOException: Channel was inactive
for too (>30000) long: tcp://172.27.1.126:61616, attempting to automatically
reconnect
[02/05/13 02:42:28:028 BST] WARN - failover.FailoverTransport: Transport
(tcp://172.27.1.126:61616) failed, reason:
org.apache.activemq.transport.InactivityIOException: Channel was inactive
for too (>30000) long: tcp://172.27.1.126:61616, attempting to automatically
reconnect
[02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Waiting 10
ms before attempting connection.
[02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Waiting 10
ms before attempting connection.
[02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Attempting
0th connect to: tcp://amq-node-4:61616
[02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Attempting
0th connect to: tcp://amq-node-4:61616
[02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Connection
established
[02/05/13 02:42:28:028 BST] INFO - failover.FailoverTransport: Successfully
reconnected to tcp://amq-node-4:61616
[02/05/13 02:42:28:028 BST] TRACE - failover.FailoverTransport: restore
requestMap, replay: ActiveMQTextMessage {commandId = 31302, responseRequired
= true, messageId = ID:tom-OptiPlex-9010-38261-1367502048498-4:1:5217:1:1,
originalDestination = null, originalTransactionId = null, producerId =
ID:tom-OptiPlex-9010-38261-1367502048498-4:1:5217:1, destination =
topic://VirtualTopic.resource.tom.created, transactionId = null, expiration
= 0, timestamp = 1367502070257, arrival = 0, brokerInTime = 0, brokerOutTime
= 0, correlationId = null, replyTo = null, persistent = true, type = null,
priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null,
compressed = false, userID = null, content =
org.apache.activemq.util.ByteSequence@51a82311, marshalledProperties =
org.apache.activemq.util.ByteSequence@75965af8, dataStructure = null,
redeliveryCounter = 0, size = 0, properties = {account-id=ba,
account-version=admindev}, readOnlyProperties = true, readOnlyBody = true,
droppable = false, text =
{"accountId":"ba","accountVersion":"admindev"...nalData":{}}}
[02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Connection
established
[02/05/13 02:42:28:028 BST] INFO - failover.FailoverTransport: Successfully
reconnected to tcp://amq-node-4:61616
[02/05/13 02:42:28:028 BST] TRACE - failover.FailoverTransport:
tcp://amq-node-5:61616 handleTransportFailure:
org.apache.activemq.transport.InactivityIOException: Channel was inactive
for too (>30000) long: tcp://172.27.1.126:61616
[02/05/13 02:42:28:028 BST] WARN - failover.FailoverTransport: Transport
(tcp://172.27.1.126:61616) failed, reason:
org.apache.activemq.transport.InactivityIOException: Channel was inactive
for too (>30000) long: tcp://172.27.1.126:61616, attempting to automatically
reconnect
[02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Waiting 10
ms before attempting connection.
[02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Attempting
0th connect to: tcp://amq-node-4:61616
[02/05/13 02:42:28:028 BST] DEBUG - failover.FailoverTransport: Connection
established
[02/05/13 02:42:28:028 BST] INFO - failover.FailoverTransport: Successfully
reconnected to tcp://amq-node-4:61616
--
View this message in context: http://activemq.2283324.n4.nabble.com/Slow-Failover-tp4666393p4666579.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.