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 <[email protected]> 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
