You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by mmg <ma...@gmail.com> on 2013/06/14 14:24:26 UTC

DemandForwardingBridge - Ignoring sub ConsumerInf

Hi,

Any idea what does the below message mean? Does this have any negative
effect on communication between producers and consumers like loss of
messages?


DEBUG DemandForwardingBridge         - Ignoring sub ConsumerInfo {commandId
= 179, responseRequired = false, consumerId =
ID:avayaiq1cr.cam.wal-mart.com-46291-1369884580806-3:3:1:174, destination =
queue://ReplyQueue, prefetchSize = 1000, maximumPendingMessageLimit = 0,
browser = false, dispatchAsync = true, selector = null, subcriptionName =
null, noLocal = false, exclusive = false, retroactive = false, priority = 0,
brokerPath = [ID:avayaiqe1.ivr.wal-mart.com-47420-1369884669888-1:0],
optimizedAcknowledge = false, noRangeAcks = false, additionalPredicate =
org.apache.activemq.command.NetworkBridgeFilter@16fa21a4} already routed
through this broker once


Thanks.



--
View this message in context: http://activemq.2283324.n4.nabble.com/DemandForwardingBridge-Ignoring-sub-ConsumerInf-tp4668211.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: DemandForwardingBridge - Ignoring sub ConsumerInf

Posted by Dejan Bosanac <de...@nighttale.net>.
You can find more info here

http://activemq.apache.org/activemq-inactivitymonitor.html

keep alive sending and inactivity monitor is on by default

Regards
--
Dejan Bosanac
----------------------
Red Hat, Inc.
FuseSource is now part of Red Hat
dbosanac@redhat.com
Twitter: @dejanb
Blog: http://sensatic.net
ActiveMQ in Action: http://www.manning.com/snyder/


On Fri, Jun 21, 2013 at 8:36 AM, mmg <ma...@gmail.com> wrote:

> Any information on this?
>
> Thanks in advance,
> mmg
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/DemandForwardingBridge-Ignoring-sub-ConsumerInf-tp4668211p4668441.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>

Re: DemandForwardingBridge - Ignoring sub ConsumerInf

Posted by mmg <ma...@gmail.com>.
Any information on this?

Thanks in advance,
mmg



--
View this message in context: http://activemq.2283324.n4.nabble.com/DemandForwardingBridge-Ignoring-sub-ConsumerInf-tp4668211p4668441.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: DemandForwardingBridge - Ignoring sub ConsumerInf

Posted by mmg <ma...@gmail.com>.
Hi Dejan,

could you please also explain how the inactivity monitor and KeepAlive work?
I could not make out much from the material available on Active MQ site.

Thanks,
mmg



--
View this message in context: http://activemq.2283324.n4.nabble.com/DemandForwardingBridge-Ignoring-sub-ConsumerInf-tp4668211p4668370.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: DemandForwardingBridge - Ignoring sub ConsumerInf

Posted by mmg <ma...@gmail.com>.
Hi Dejan,

Will setting "keepAlive=true" in the NetworkConnector on both the brokers
help?

Also what does the following error message means? I can see this message on
one broker only.

2013-06-13 03:52:31,998 [77.225.90:37027] WARN  ManagedTransportConnection    
- Failed to unregister mbean:
org.apache.activemq:BrokerName=avayaiqe1.ivr.wal-mart.com-broker,Type=Connection,ConnectorName=secured,Connection=NC_avayaiq1cr.cam.wal-mart.com-broker_outboundavayaiq1cr.cam.wal-mart.com-broker

Thanks,
-mmg



--
View this message in context: http://activemq.2283324.n4.nabble.com/DemandForwardingBridge-Ignoring-sub-ConsumerInf-tp4668211p4668369.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: DemandForwardingBridge - Ignoring sub ConsumerInf

Posted by Dejan Bosanac <de...@nighttale.net>.
Hi,

it looks like it's indeed a case of unstable physical connection between
brokers. The message

Channel was inactive for too long.
org.apache.activemq.transport.InactivityIOException: Channel was inactive
for too long.

means that socket is basically dead. I'd suggest you do some investigation
on a network connection between brokers.

Regards
--
Dejan Bosanac
----------------------
Red Hat, Inc.
FuseSource is now part of Red Hat
dbosanac@redhat.com
Twitter: @dejanb
Blog: http://sensatic.net
ActiveMQ in Action: http://www.manning.com/snyder/


On Wed, Jun 19, 2013 at 1:50 PM, mmg <ma...@gmail.com> wrote:

> Hi Dejan,
>
> Now we are not receiving any messages between these two brokers. We can see
> following exceptions and messages in Active MQ logs (there is one hr time
> difference between these two hosts). Could you please let us know the
> reason
> for these exceptions and what needs to be done to get over this issue?
>
>
> logs on host A :
>
>
> 2013-06-13 02:00:09,200 [127.0.0.1:41924] DEBUG Transport
> - Transport failed: java.io.EOFException
> java.io.EOFException
>         at java.io.DataInputStream.readInt(Unknown Source)
>         at
>
> org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
>         at java.lang.Thread.run(Unknown Source)
>
> 2013-06-13 03:00:10,196 [127.0.0.1:50816] DEBUG Transport
> - Transport failed: java.io.EOFException
> java.io.EOFException
>         at java.io.DataInputStream.readInt(Unknown Source)
>         at
>
> org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
>         at java.lang.Thread.run(Unknown Source)
>
> 2013-06-13 03:09:41,970 [iveMQ Scheduler] WARN  DemandForwardingBridge
> - Outbound transport to avayaiq1cr.cam.wal-mart.com-broker interrupted ...
> 2013-06-13 03:09:41,971 [iveMQ Scheduler] DEBUG FailoverTransport
> - Transport failed, starting up reconnect task
> org.apache.activemq.transport.InactivityIOException: Channel was inactive
> for too long.
>         at
>
> org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
>         at
>
> org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
>         at
>
> org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
>         at java.lang.Thread.run(Unknown Source)
> 2013-06-13 03:09:41,971 [ker: 1376681299] DEBUG FailoverTransport
> - Attempting connect to:
> ssl://10.77.225.90:61617?wireFormat.maxInactivityDuration=600000
> 2013-06-13 03:09:42,060 [77.225.90:61617] DEBUG TcpTransport
> - TCP consumer thread starting
> 2013-06-13 03:09:42,060 [ker: 1376681299] DEBUG WireFormatNegotiator
> - Sending: WireFormatInfo { version=1,
> properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
> SizePrefixDisabled=false, StackTraceEnabled=true,
> MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 03:09:42,498 [77.225.90:61617] DEBUG WireFormatNegotiator
> - Received WireFormat: WireFormatInfo { version=1,
> properties={StackTraceEnabled=true, TightEncodingEnabled=true,
> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
> MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 03:09:42,498 [77.225.90:61617] DEBUG WireFormatNegotiator
> - tcp://avayaiq1cr.cam.wal-mart.com/10.77.225.90:61617 before negotiation:
> OpenWireFormat{version=1, cacheEnabled=false, stackTraceEnabled=false,
> tightEncodingEnabled=false, sizePrefixDisabled=false}
> 2013-06-13 03:09:42,498 [77.225.90:61617] DEBUG WireFormatNegotiator
> - tcp://avayaiq1cr.cam.wal-mart.com/10.77.225.90:61617 after negotiation:
> OpenWireFormat{version=1, cacheEnabled=true, stackTraceEnabled=true,
> tightEncodingEnabled=true, sizePrefixDisabled=false}
> 2013-06-13 03:09:42,498 [ker: 1376681299] DEBUG FailoverTransport
> - Connection established
> 2013-06-13 03:09:42,498 [ker: 1376681299] INFO  DemandForwardingBridge
> - Outbound transport to avayaiq1cr.cam.wal-mart.com-broker resumed
> 2013-06-13 03:09:42,499 [77.225.90:61617] DEBUG FailoverTransport
> - Transport failed, starting up reconnect task
> java.net.SocketException: Socket closed
>         at java.net.SocketInputStream.socketRead0(Native Method)
>         at java.net.SocketInputStream.read(Unknown Source)
>         at com.sun.net.ssl.internal.ssl.InputRecord.readFully(Unknown
> Source)
>         at com.sun.net.ssl.internal.ssl.InputRecord.read(Unknown Source)
>         at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(Unknown
> Source)
>         at
> com.sun.net.ssl.internal.ssl.SSLSocketImpl.readDataRecord(Unknown
> Source)
>         at com.sun.net.ssl.internal.ssl.AppInputStream.read(Unknown Source)
>         at
>
> org.apache.activemq.transport.tcp.TcpBufferedInputStream.fill(TcpBufferedInputStream.java:48)
>         at
>
> org.apache.activemq.transport.tcp.TcpBufferedInputStream.read(TcpBufferedInputStream.java:55)
>         at java.io.DataInputStream.readInt(Unknown Source)
>         at
>
> org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
>         at java.lang.Thread.run(Unknown Source)
> 2013-06-13 03:09:42,499 [Thread-5       ] DEBUG FailoverTransport
> - Waiting for transport to reconnect.
> 2013-06-13 03:09:42,499 [ker: 1376681299] DEBUG FailoverTransport
> - Attempting connect to:
> ssl://10.77.225.90:61617?wireFormat.maxInactivityDuration=600000
> 2013-06-13 03:09:42,499 [77.225.90:61617] WARN  DemandForwardingBridge
> - Outbound transport to avayaiq1cr.cam.wal-mart.com-broker interrupted ...
> 2013-06-13 03:09:42,499 [77.225.90:61617] INFO  Service
> - Async error occurred: java.lang.IllegalStateException: Cannot lookup a
> connection that had not been registered:
> ID:avayaiqe1.ivr.wal-mart.com-47420-1369884669888-3:1
> java.lang.IllegalStateException: Cannot lookup a connection that had not
> been registered: ID:avayaiqe1.ivr.wal-mart.com-47420-1369884669888-3:1
>         at
>
> org.apache.activemq.broker.AbstractConnection.lookupConnectionState(AbstractConnection.java:241)
>         at
>
> org.apache.activemq.broker.AbstractConnection.processRemoveConnection(AbstractConnection.java:519)
>         at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:59)
>         at
>
> org.apache.activemq.broker.AbstractConnection.service(AbstractConnection.java:201)
>         at
>
> org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:62)
>         at
>
> org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:97)
>         at
>
> org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:63)
>         at
> org.apache.activemq.transport.vm.VMTransport.oneway(VMTransport.java:76)
>         at
> org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:44)
>         at
>
> org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
>         at
>
> org.apache.activemq.network.DemandForwardingBridgeSupport$2.transportInterupted(DemandForwardingBridgeSupport.java:138)
>         at
>
> org.apache.activemq.transport.TransportFilter.transportInterupted(TransportFilter.java:98)
>         at
>
> org.apache.activemq.transport.TransportFilter.transportInterupted(TransportFilter.java:98)
>         at
>
> org.apache.activemq.transport.failover.FailoverTransport.handleTransportFailure(FailoverTransport.java:223)
>         at
>
> org.apache.activemq.transport.failover.FailoverTransport.access$300(FailoverTransport.java:53)
>         at
>
> org.apache.activemq.transport.failover.FailoverTransport$1.onException(FailoverTransport.java:111)
>         at
>
> org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:94)
>         at
>
> org.apache.activemq.transport.WireFormatNegotiator.onException(WireFormatNegotiator.java:120)
>         at
>
> org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:149)
>         at
>
> org.apache.activemq.transport.TransportSupport.onException(TransportSupport.java:100)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:156)
>         at java.lang.Thread.run(Unknown Source)
> 2013-06-13 03:09:42,503 [her: 1344918164] WARN  DemandForwardingBridge
> - Unexpected local command: ConnectionError {commandId = 24,
> responseRequired = false, connectionId = null, exception =
> java.lang.IllegalStateException: Cannot lookup a connection that had not
> been registered: ID:avayaiqe1.ivr.wal-mart.com-47420-1369884669888-3:1}
> 2013-06-13 03:09:42,591 [ker: 1376681299] DEBUG WireFormatNegotiator
> - Sending: WireFormatInfo { version=1,
> properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
> SizePrefixDisabled=false, StackTraceEnabled=true,
> MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 03:09:42,591 [77.225.90:61617] DEBUG TcpTransport
> - TCP consumer thread starting
> 2013-06-13 03:09:43,024 [ker: 1376681299] DEBUG FailoverTransport
> - Connection established
> 2013-06-13 03:09:43,024 [ker: 1376681299] INFO  DemandForwardingBridge
> - Outbound transport to avayaiq1cr.cam.wal-mart.com-broker resumed
> 2013-06-13 03:09:43,024 [77.225.90:61617] DEBUG WireFormatNegotiator
> - Received WireFormat: WireFormatInfo { version=1,
> properties={StackTraceEnabled=true, TightEncodingEnabled=true,
> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
> MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 03:09:43,024 [77.225.90:61617] DEBUG WireFormatNegotiator
> - tcp://avayaiq1cr.cam.wal-mart.com/10.77.225.90:61617 before negotiation:
> OpenWireFormat{version=1, cacheEnabled=false, stackTraceEnabled=false,
> tightEncodingEnabled=false, sizePrefixDisabled=false}
> 2013-06-13 03:09:43,024 [77.225.90:61617] DEBUG WireFormatNegotiator
> - tcp://avayaiq1cr.cam.wal-mart.com/10.77.225.90:61617 after negotiation:
> OpenWireFormat{version=1, cacheEnabled=true, stackTraceEnabled=true,
> tightEncodingEnabled=true, sizePrefixDisabled=false}
> 2013-06-13 03:09:43,114 [Thread-6       ] INFO  DemandForwardingBridge
> - Network connection between vm://avayaiqe1.ivr.wal-mart.com-broker#0 and
> ssl://
> 10.77.225.90:61617?wireFormat.maxInactivityDuration=600000(avayaiq1cr.cam.wal-mart.com-broker)
> has been established.
> 2013-06-13 03:10:43,213 [iveMQ Scheduler] DEBUG Transport
> - Transport failed: org.apache.activemq.transport.InactivityIOException:
> Channel was inactive for too long.
> org.apache.activemq.transport.InactivityIOException: Channel was inactive
> for too long.
>         at
>
> org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
>         at
>
> org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
>         at
>
> org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
>         at java.lang.Thread.run(Unknown Source)
> 2013-06-13 03:11:08,849 [-mart.com:61617] DEBUG WireFormatNegotiator
> - Sending: WireFormatInfo { version=1,
> properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
> SizePrefixDisabled=false, StackTraceEnabled=true,
> MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 03:11:08,849 [77.225.90:39452] DEBUG TcpTransport
> - TCP consumer thread starting
> 2013-06-13 03:11:09,284 [77.225.90:39452] DEBUG WireFormatNegotiator
> - Received WireFormat: WireFormatInfo { version=1,
> properties={StackTraceEnabled=true, TightEncodingEnabled=true,
> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
> MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 03:11:09,284 [77.225.90:39452] DEBUG WireFormatNegotiator
> - tcp:///10.77.225.90:39452 before negotiation: OpenWireFormat{version=1,
> cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false,
> sizePrefixDisabled=false}
> 2013-06-13 03:11:09,284 [77.225.90:39452] DEBUG WireFormatNegotiator
> - tcp:///10.77.225.90:39452 after negotiation: OpenWireFormat{version=1,
> cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true,
> sizePrefixDisabled=false}
> 2013-06-13 03:12:11,183 [eckpoint Worker] DEBUG JournalPersistenceAdapter
> - Checkpoint started.
>
>
>
> --------------------------
>
> 2013-06-13 03:51:09,286 [iveMQ Scheduler] DEBUG Transport
> - Transport failed: org.apache.activemq.transport.InactivityIOException:
> Channel was inactive for too long.
> org.apache.activemq.transport.InactivityIOException: Channel was inactive
> for too long.
>         at
>
> org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
>         at
>
> org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
>         at
>
> org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
>         at java.lang.Thread.run(Unknown Source)
> 2013-06-13 03:51:31,017 [77.225.90:37022] DEBUG TcpTransport
> - TCP consumer thread starting
> 2013-06-13 03:51:31,017 [-mart.com:61617] DEBUG WireFormatNegotiator
> - Sending: WireFormatInfo { version=1,
> properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
> SizePrefixDisabled=false, StackTraceEnabled=true,
> MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 03:51:31,455 [77.225.90:37022] DEBUG WireFormatNegotiator
> - Received WireFormat: WireFormatInfo { version=1,
> properties={StackTraceEnabled=true, TightEncodingEnabled=true,
> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
> MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 03:51:31,456 [77.225.90:37022] DEBUG WireFormatNegotiator
> - tcp:///10.77.225.90:37022 before negotiation: OpenWireFormat{version=1,
> cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false,
> sizePrefixDisabled=false}
> 2013-06-13 03:51:31,456 [77.225.90:37022] DEBUG WireFormatNegotiator
> - tcp:///10.77.225.90:37022 after negotiation: OpenWireFormat{version=1,
> cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true,
> sizePrefixDisabled=false}
> 2013-06-13 03:52:31,466 [77.225.90:37022] DEBUG Transport
> - Transport failed: java.io.EOFException
> java.io.EOFException
>         at java.io.DataInputStream.readInt(Unknown Source)
>         at
>
> org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
>         at java.lang.Thread.run(Unknown Source)
> 2013-06-13 03:52:31,555 [77.225.90:37027] DEBUG TcpTransport
> - TCP consumer thread starting
> 2013-06-13 03:52:31,555 [-mart.com:61617] DEBUG WireFormatNegotiator
> - Sending: WireFormatInfo { version=1,
> properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
> SizePrefixDisabled=false, StackTraceEnabled=true,
> MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 03:52:31,992 [77.225.90:37027] DEBUG WireFormatNegotiator
> - Received WireFormat: WireFormatInfo { version=1,
> properties={StackTraceEnabled=true, TightEncodingEnabled=true,
> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
> MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 03:52:31,992 [77.225.90:37027] DEBUG WireFormatNegotiator
> - tcp:///10.77.225.90:37027 before negotiation: OpenWireFormat{version=1,
> cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false,
> sizePrefixDisabled=false}
> 2013-06-13 03:52:31,992 [77.225.90:37027] DEBUG WireFormatNegotiator
> - tcp:///10.77.225.90:37027 after negotiation: OpenWireFormat{version=1,
> cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true,
> sizePrefixDisabled=false}
> 2013-06-13 03:52:31,997 [cher: 872130173] DEBUG Transport
> - Transport failed: java.net.SocketException: Connection closed by remote
> host
> java.net.SocketException: Connection closed by remote host
>         at com.sun.net.ssl.internal.ssl.SSLSocketImpl.checkWrite(Unknown
> Source)
>         at com.sun.net.ssl.internal.ssl.AppOutputStream.write(Unknown
> Source)
>         at
>
> org.apache.activemq.transport.tcp.TcpBufferedOutputStream.flush(TcpBufferedOutputStream.java:108)
>         at java.io.DataOutputStream.flush(Unknown Source)
>         at
>
> org.apache.activemq.transport.tcp.TcpTransport.oneway(TcpTransport.java:125)
>         at
>
> org.apache.activemq.transport.InactivityMonitor.oneway(InactivityMonitor.java:141)
>         at
>
> org.apache.activemq.transport.TransportFilter.oneway(TransportFilter.java:78)
>         at
>
> org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:77)
>         at
> org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:44)
>         at
>
> org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
>         at
>
> org.apache.activemq.broker.TransportConnection.dispatch(TransportConnection.java:211)
>         at
>
> org.apache.activemq.broker.AbstractConnection.processDispatch(AbstractConnection.java:581)
>         at
>
> org.apache.activemq.broker.AbstractConnection.iterate(AbstractConnection.java:597)
>         at
>
> org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:87)
>         at
>
> org.apache.activemq.thread.DedicatedTaskRunner.access$000(DedicatedTaskRunner.java:24)
>         at
>
> org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:38)
> 2013-06-13 03:52:31,997 [77.225.90:37027] DEBUG Transport
> - Transport failed: java.io.EOFException
> java.io.EOFException
>         at java.io.DataInputStream.readInt(Unknown Source)
>         at
>
> org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
>         at java.lang.Thread.run(Unknown Source)
> 2013-06-13 03:52:31,998 [77.225.90:37027] WARN  ManagedTransportConnection
> - Failed to unregister mbean:
>
> org.apache.activemq:BrokerName=avayaiqe1.ivr.wal-mart.com-broker,Type=Connection,ConnectorName=secured,Connection=NC_avayaiq1cr.cam.wal-mart.com-broker_outboundavayaiq1cr.cam.wal-mart.com-broker
> 2013-06-13 03:52:32,082 [-mart.com:61617] DEBUG WireFormatNegotiator
> - Sending: WireFormatInfo { version=1,
> properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
> SizePrefixDisabled=false, StackTraceEnabled=true,
> MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 03:52:32,082 [77.225.90:37028] DEBUG TcpTransport
> - TCP consumer thread starting
> 2013-06-13 03:52:32,516 [77.225.90:37028] DEBUG WireFormatNegotiator
> - Received WireFormat: WireFormatInfo { version=1,
> properties={StackTraceEnabled=true, TightEncodingEnabled=true,
> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
> MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 03:52:32,516 [77.225.90:37028] DEBUG WireFormatNegotiator
> - tcp:///10.77.225.90:37028 before negotiation: OpenWireFormat{version=1,
> cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false,
> sizePrefixDisabled=false}
> 2013-06-13 03:52:32,516 [77.225.90:37028] DEBUG WireFormatNegotiator
> - tcp:///10.77.225.90:37028 after negotiation: OpenWireFormat{version=1,
> cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true,
> sizePrefixDisabled=false}
> 2013-06-13 03:56:11,183 [eckpoint Worker] DEBUG JournalPersistenceAdapter
> - Checkpoint started.
>
>
> ---------------------------------
> 2013-06-13 04:23:02,518 [iveMQ Scheduler] DEBUG Transport
> - Transport failed: org.apache.activemq.transport.InactivityIOException:
> Channel was inactive for too long.
> org.apache.activemq.transport.InactivityIOException: Channel was inactive
> for too long.
>         at
>
> org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
>         at
>
> org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
>         at
>
> org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
>         at java.lang.Thread.run(Unknown Source)
> 2013-06-13 04:23:11,183 [eckpoint Worker] DEBUG JournalPersistenceAdapter
> - Checkpoint started.
>
>
>
>
> On Host B:
> --------------
>
>
> 2013-06-13 02:10:43,257 [.19.48.24:61617] WARN  DemandForwardingBridge
> - Outbound transport to avayaiqe1.ivr.wal-mart.com-broker interrupted ...
> 2013-06-13 02:10:43,266 [.19.48.24:61617] DEBUG FailoverTransport
> - Transport failed, starting up reconnect task
> java.io.EOFException
>         at java.io.DataInputStream.readInt(Unknown Source)
>         at
>
> org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
>         at java.lang.Thread.run(Unknown Source)
> 2013-06-13 02:10:43,266 [ker: 1430534144] DEBUG FailoverTransport
> - Attempting connect to:
> ssl://172.19.48.24:61617?wireFormat.maxInactivityDuration=600000
> 2013-06-13 02:11:08,805 [.19.48.24:61617] DEBUG TcpTransport
> - TCP consumer thread starting
> 2013-06-13 02:11:08,805 [ker: 1430534144] DEBUG WireFormatNegotiator
> - Sending: WireFormatInfo { version=1,
> properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
> SizePrefixDisabled=false, StackTraceEnabled=true,
> MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 02:11:09,239 [.19.48.24:61617] DEBUG WireFormatNegotiator
> - Received WireFormat: WireFormatInfo { version=1,
> properties={StackTraceEnabled=true, TightEncodingEnabled=true,
> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
> MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 02:11:09,239 [.19.48.24:61617] DEBUG WireFormatNegotiator
> - tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 before negotiation:
> OpenWireFormat{version=1, cacheEnabled=false, stackTraceEnabled=false,
> tightEncodingEnabled=false, sizePrefixDisabled=false}
> 2013-06-13 02:11:09,239 [.19.48.24:61617] DEBUG WireFormatNegotiator
> - tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 after negotiation:
> OpenWireFormat{version=1, cacheEnabled=true, stackTraceEnabled=true,
> tightEncodingEnabled=true, sizePrefixDisabled=false}
> 2013-06-13 02:11:09,239 [ker: 1430534144] DEBUG FailoverTransport
> - Connection established
> 2013-06-13 02:11:09,239 [ker: 1430534144] INFO  DemandForwardingBridge
> - Outbound transport to avayaiqe1.ivr.wal-mart.com-broker resumed
> 2013-06-13 02:11:09,328 [Thread-8       ] INFO  DemandForwardingBridge
> - Network connection between vm://avayaiq1cr.cam.wal-mart.com-broker#0 and
> ssl://
> 172.19.48.24:61617?wireFormat.maxInactivityDuration=600000(avayaiqe1.ivr.wal-mart.com-broker)
> has been established.
> 2013-06-13 02:11:09,333 [.19.48.24:61617] DEBUG DemandForwardingBridge
> - Forwarding sub on vm://avayaiq1cr.cam.wal-mart.com-broker#0 from
> avayaiqe1.ivr.wal-mart.com-broker :  ConsumerInfo {commandId = 12,
> responseRequired = true, consumerId =
> ID:avayaiqe1.ivr.wal-mart.com-55507-1368756619514-1:9:5:1, destination =
> topic://com.avaya.syncandnotification.namemgmt.NOTIFICATIONTOPIC,
> prefetchSize = 32766, maximumPendingMessageLimit = 0, browser = false,
> dispatchAsync = false, selector = null, subcriptionName = null, noLocal =
> false, exclusive = false, retroactive = false, priority = 0, brokerPath =
> [ID:avayaiqe1.ivr.wal-mart.com-47420-1369884669888-1:0],
> optimizedAcknowledge = false, noRangeAcks = false, additionalPredicate =
> null}
> 2013-06-13 02:11:13,070 [iveMQ Scheduler] DEBUG Transport
> - Transport failed: org.apache.activemq.transport.InactivityIOException:
> Channel was inactive for too long.
> org.apache.activemq.transport.InactivityIOException: Channel was inactive
> for too long.
>         at
>
> org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
>         at
>
> org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
>         at
>
> org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
>         at java.lang.Thread.run(Unknown Source)
>
> --------------------------------
>
>
> 2013-06-13 02:51:30,871 [.19.48.24:61617] WARN  DemandForwardingBridge
> - Outbound transport to avayaiqe1.ivr.wal-mart.com-broker interrupted ...
> 2013-06-13 02:51:30,879 [.19.48.24:61617] DEBUG FailoverTransport
> - Transport failed, starting up reconnect task
> java.io.EOFException
>         at java.io.DataInputStream.readInt(Unknown Source)
>         at
>
> org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
>         at java.lang.Thread.run(Unknown Source)
> 2013-06-13 02:51:30,879 [ker: 1430534144] DEBUG FailoverTransport
> - Attempting connect to:
> ssl://172.19.48.24:61617?wireFormat.maxInactivityDuration=600000
> 2013-06-13 02:51:30,968 [.19.48.24:61617] DEBUG TcpTransport
> - TCP consumer thread starting
> 2013-06-13 02:51:30,968 [ker: 1430534144] DEBUG WireFormatNegotiator
> - Sending: WireFormatInfo { version=1,
> properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
> SizePrefixDisabled=false, StackTraceEnabled=true,
> MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 02:51:31,412 [.19.48.24:61617] DEBUG WireFormatNegotiator
> - Received WireFormat: WireFormatInfo { version=1,
> properties={StackTraceEnabled=true, TightEncodingEnabled=true,
> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
> MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 02:51:31,412 [.19.48.24:61617] DEBUG WireFormatNegotiator
> - tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 before negotiation:
> OpenWireFormat{version=1, cacheEnabled=false, stackTraceEnabled=false,
> tightEncodingEnabled=false, sizePrefixDisabled=false}
> 2013-06-13 02:51:31,412 [.19.48.24:61617] DEBUG WireFormatNegotiator
> - tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 after negotiation:
> OpenWireFormat{version=1, cacheEnabled=true, stackTraceEnabled=true,
> tightEncodingEnabled=true, sizePrefixDisabled=false}
> 2013-06-13 02:51:31,412 [ker: 1430534144] DEBUG FailoverTransport
> - Connection established
> 2013-06-13 02:51:31,412 [ker: 1430534144] INFO  DemandForwardingBridge
> - Outbound transport to avayaiqe1.ivr.wal-mart.com-broker resumed
> 2013-06-13 02:51:31,501 [Thread-10      ] INFO  DemandForwardingBridge
> - Network connection between vm://avayaiq1cr.cam.wal-mart.com-broker#0 and
> ssl://
> 172.19.48.24:61617?wireFormat.maxInactivityDuration=600000(avayaiqe1.ivr.wal-mart.com-broker)
> has been established.
> 2013-06-13 02:51:31,883 [.19.48.24:61617] DEBUG DemandForwardingBridge
> - Forwarding sub on vm://avayaiq1cr.cam.wal-mart.com-broker#0 from
> avayaiqe1.ivr.wal-mart.com-broker :  ConsumerInfo {commandId = 12,
> responseRequired = true, consumerId =
> ID:avayaiqe1.ivr.wal-mart.com-55507-1368756619514-1:9:5:1, destination =
> topic://com.avaya.syncandnotification.namemgmt.NOTIFICATIONTOPIC,
> prefetchSize = 32766, maximumPendingMessageLimit = 0, browser = false,
> dispatchAsync = false, selector = null, subcriptionName = null, noLocal =
> false, exclusive = false, retroactive = false, priority = 0, brokerPath =
> [ID:avayaiqe1.ivr.wal-mart.com-47420-1369884669888-1:0],
> optimizedAcknowledge = false, noRangeAcks = false, additionalPredicate =
> null}
>
> ----------------------
>
>
> 2013-06-13 02:52:31,413 [iveMQ Scheduler] WARN  DemandForwardingBridge
> - Outbound transport to avayaiqe1.ivr.wal-mart.com-broker interrupted ...
> 2013-06-13 02:52:31,422 [iveMQ Scheduler] DEBUG FailoverTransport
> - Transport failed, starting up reconnect task
> org.apache.activemq.transport.InactivityIOException: Channel was inactive
> for too long.
>         at
>
> org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
>         at
>
> org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
>         at
>
> org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
>         at
>
> edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
>         at java.lang.Thread.run(Unknown Source)
> 2013-06-13 02:52:31,422 [ker: 1430534144] DEBUG FailoverTransport
> - Attempting connect to:
> ssl://172.19.48.24:61617?wireFormat.maxInactivityDuration=600000
> 2013-06-13 02:52:31,511 [.19.48.24:61617] DEBUG TcpTransport
> - TCP consumer thread starting
> 2013-06-13 02:52:31,511 [ker: 1430534144] DEBUG WireFormatNegotiator
> - Sending: WireFormatInfo { version=1,
> properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
> SizePrefixDisabled=false, StackTraceEnabled=true,
> MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 02:52:31,947 [.19.48.24:61617] DEBUG WireFormatNegotiator
> - Received WireFormat: WireFormatInfo { version=1,
> properties={StackTraceEnabled=true, TightEncodingEnabled=true,
> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
> MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 02:52:31,947 [.19.48.24:61617] DEBUG WireFormatNegotiator
> - tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 before negotiation:
> OpenWireFormat{version=1, cacheEnabled=false, stackTraceEnabled=false,
> tightEncodingEnabled=false, sizePrefixDisabled=false}
> 2013-06-13 02:52:31,947 [.19.48.24:61617] DEBUG WireFormatNegotiator
> - tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 after negotiation:
> OpenWireFormat{version=1, cacheEnabled=true, stackTraceEnabled=true,
> tightEncodingEnabled=true, sizePrefixDisabled=false}
> 2013-06-13 02:52:31,947 [ker: 1430534144] DEBUG FailoverTransport
> - Connection established
> 2013-06-13 02:52:31,947 [ker: 1430534144] INFO  DemandForwardingBridge
> - Outbound transport to avayaiqe1.ivr.wal-mart.com-broker resumed
> 2013-06-13 02:52:31,947 [.19.48.24:61617] DEBUG FailoverTransport
> - Transport failed, starting up reconnect task
> java.net.SocketException: Socket closed
>         at java.net.SocketInputStream.socketRead0(Native Method)
>         at java.net.SocketInputStream.read(Unknown Source)
>         at com.sun.net.ssl.internal.ssl.InputRecord.readFully(Unknown
> Source)
>         at com.sun.net.ssl.internal.ssl.InputRecord.read(Unknown Source)
>         at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(Unknown
> Source)
>         at
> com.sun.net.ssl.internal.ssl.SSLSocketImpl.readDataRecord(Unknown
> Source)
>         at com.sun.net.ssl.internal.ssl.AppInputStream.read(Unknown Source)
>         at
>
> org.apache.activemq.transport.tcp.TcpBufferedInputStream.fill(TcpBufferedInputStream.java:48)
>         at
>
> org.apache.activemq.transport.tcp.TcpBufferedInputStream.read(TcpBufferedInputStream.java:55)
>         at java.io.DataInputStream.readInt(Unknown Source)
>         at
>
> org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
>         at java.lang.Thread.run(Unknown Source)
> 2013-06-13 02:52:31,947 [Thread-11      ] DEBUG FailoverTransport
> - Waiting for transport to reconnect.
> 2013-06-13 02:52:31,947 [ker: 1430534144] DEBUG FailoverTransport
> - Attempting connect to:
> ssl://172.19.48.24:61617?wireFormat.maxInactivityDuration=600000
> 2013-06-13 02:52:31,948 [.19.48.24:61617] WARN  DemandForwardingBridge
> - Outbound transport to avayaiqe1.ivr.wal-mart.com-broker interrupted ...
> 2013-06-13 02:52:31,948 [.19.48.24:61617] INFO  Service
> - Async error occurred: java.lang.IllegalStateException: Cannot lookup a
> connection that had not been registered:
> ID:avayaiq1cr.cam.wal-mart.com-46291-1369884580806-3:7
> java.lang.IllegalStateException: Cannot lookup a connection that had not
> been registered: ID:avayaiq1cr.cam.wal-mart.com-46291-1369884580806-3:7
>         at
>
> org.apache.activemq.broker.AbstractConnection.lookupConnectionState(AbstractConnection.java:241)
>         at
>
> org.apache.activemq.broker.AbstractConnection.processRemoveConnection(AbstractConnection.java:519)
>         at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:59)
>         at
>
> org.apache.activemq.broker.AbstractConnection.service(AbstractConnection.java:201)
>         at
>
> org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:62)
>         at
>
> org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:97)
>         at
>
> org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:63)
>         at
> org.apache.activemq.transport.vm.VMTransport.oneway(VMTransport.java:76)
>         at
> org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:44)
>         at
>
> org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
>         at
>
> org.apache.activemq.network.DemandForwardingBridgeSupport$2.transportInterupted(DemandForwardingBridgeSupport.java:138)
>         at
>
> org.apache.activemq.transport.TransportFilter.transportInterupted(TransportFilter.java:98)
>         at
>
> org.apache.activemq.transport.TransportFilter.transportInterupted(TransportFilter.java:98)
>         at
>
> org.apache.activemq.transport.failover.FailoverTransport.handleTransportFailure(FailoverTransport.java:223)
>         at
>
> org.apache.activemq.transport.failover.FailoverTransport.access$300(FailoverTransport.java:53)
>         at
>
> org.apache.activemq.transport.failover.FailoverTransport$1.onException(FailoverTransport.java:111)
>         at
>
> org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:94)
>         at
>
> org.apache.activemq.transport.WireFormatNegotiator.onException(WireFormatNegotiator.java:120)
>         at
>
> org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:149)
>         at
>
> org.apache.activemq.transport.TransportSupport.onException(TransportSupport.java:100)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:156)
>         at java.lang.Thread.run(Unknown Source)
> 2013-06-13 02:52:31,948 [tcher: 98401221] WARN  DemandForwardingBridge
> - Unexpected local command: ConnectionError {commandId = 1599,
> responseRequired = false, connectionId = null, exception =
> java.lang.IllegalStateException: Cannot lookup a connection that had not
> been registered: ID:avayaiq1cr.cam.wal-mart.com-46291-1369884580806-3:7}
> 2013-06-13 02:52:32,040 [.19.48.24:61617] DEBUG TcpTransport
> - TCP consumer thread starting
> 2013-06-13 02:52:32,040 [ker: 1430534144] DEBUG WireFormatNegotiator
> - Sending: WireFormatInfo { version=1,
> properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
> SizePrefixDisabled=false, StackTraceEnabled=true,
> MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 02:52:32,472 [ker: 1430534144] DEBUG FailoverTransport
> - Connection established
> 2013-06-13 02:52:32,472 [ker: 1430534144] INFO  DemandForwardingBridge
> - Outbound transport to avayaiqe1.ivr.wal-mart.com-broker resumed
> 2013-06-13 02:52:32,472 [.19.48.24:61617] DEBUG WireFormatNegotiator
> - Received WireFormat: WireFormatInfo { version=1,
> properties={StackTraceEnabled=true, TightEncodingEnabled=true,
> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
> MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-06-13 02:52:32,472 [.19.48.24:61617] DEBUG WireFormatNegotiator
> - tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 before negotiation:
> OpenWireFormat{version=1, cacheEnabled=false, stackTraceEnabled=false,
> tightEncodingEnabled=false, sizePrefixDisabled=false}
> 2013-06-13 02:52:32,472 [.19.48.24:61617] DEBUG WireFormatNegotiator
> - tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 after negotiation:
> OpenWireFormat{version=1, cacheEnabled=true, stackTraceEnabled=true,
> tightEncodingEnabled=true, sizePrefixDisabled=false}
> 2013-06-13 02:52:32,560 [Thread-12      ] INFO  DemandForwardingBridge
> - Network connection between vm://avayaiq1cr.cam.wal-mart.com-broker#0 and
> ssl://
> 172.19.48.24:61617?wireFormat.maxInactivityDuration=600000(avayaiqe1.ivr.wal-mart.com-broker)
> has been established.
> 2013-06-13 02:53:11,614 [eckpoint Worker] DEBUG JournalPersistenceAdapter
> - Checkpoint started.
>
>
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/DemandForwardingBridge-Ignoring-sub-ConsumerInf-tp4668211p4668353.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>

Re: DemandForwardingBridge - Ignoring sub ConsumerInf

Posted by mmg <ma...@gmail.com>.
Hi Dejan,

Now we are not receiving any messages between these two brokers. We can see
following exceptions and messages in Active MQ logs (there is one hr time
difference between these two hosts). Could you please let us know the reason
for these exceptions and what needs to be done to get over this issue?


logs on host A :


2013-06-13 02:00:09,200 [127.0.0.1:41924] DEBUG Transport                     
- Transport failed: java.io.EOFException
java.io.EOFException
	at java.io.DataInputStream.readInt(Unknown Source)
	at
org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
	at java.lang.Thread.run(Unknown Source)
    
2013-06-13 03:00:10,196 [127.0.0.1:50816] DEBUG Transport                     
- Transport failed: java.io.EOFException
java.io.EOFException
	at java.io.DataInputStream.readInt(Unknown Source)
	at
org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
	at java.lang.Thread.run(Unknown Source)
    
2013-06-13 03:09:41,970 [iveMQ Scheduler] WARN  DemandForwardingBridge        
- Outbound transport to avayaiq1cr.cam.wal-mart.com-broker interrupted ...
2013-06-13 03:09:41,971 [iveMQ Scheduler] DEBUG FailoverTransport             
- Transport failed, starting up reconnect task
org.apache.activemq.transport.InactivityIOException: Channel was inactive
for too long.
	at
org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
	at
org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
	at
org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
	at
edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
	at
edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
	at
edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
	at
edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
	at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
	at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
	at java.lang.Thread.run(Unknown Source)
2013-06-13 03:09:41,971 [ker: 1376681299] DEBUG FailoverTransport             
- Attempting connect to:
ssl://10.77.225.90:61617?wireFormat.maxInactivityDuration=600000
2013-06-13 03:09:42,060 [77.225.90:61617] DEBUG TcpTransport                  
- TCP consumer thread starting
2013-06-13 03:09:42,060 [ker: 1376681299] DEBUG WireFormatNegotiator          
- Sending: WireFormatInfo { version=1,
properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
SizePrefixDisabled=false, StackTraceEnabled=true,
MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 03:09:42,498 [77.225.90:61617] DEBUG WireFormatNegotiator          
- Received WireFormat: WireFormatInfo { version=1,
properties={StackTraceEnabled=true, TightEncodingEnabled=true,
TcpNoDelayEnabled=true, SizePrefixDisabled=false,
MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 03:09:42,498 [77.225.90:61617] DEBUG WireFormatNegotiator          
- tcp://avayaiq1cr.cam.wal-mart.com/10.77.225.90:61617 before negotiation:
OpenWireFormat{version=1, cacheEnabled=false, stackTraceEnabled=false,
tightEncodingEnabled=false, sizePrefixDisabled=false}
2013-06-13 03:09:42,498 [77.225.90:61617] DEBUG WireFormatNegotiator          
- tcp://avayaiq1cr.cam.wal-mart.com/10.77.225.90:61617 after negotiation:
OpenWireFormat{version=1, cacheEnabled=true, stackTraceEnabled=true,
tightEncodingEnabled=true, sizePrefixDisabled=false}
2013-06-13 03:09:42,498 [ker: 1376681299] DEBUG FailoverTransport             
- Connection established
2013-06-13 03:09:42,498 [ker: 1376681299] INFO  DemandForwardingBridge        
- Outbound transport to avayaiq1cr.cam.wal-mart.com-broker resumed
2013-06-13 03:09:42,499 [77.225.90:61617] DEBUG FailoverTransport             
- Transport failed, starting up reconnect task
java.net.SocketException: Socket closed
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(Unknown Source)
	at com.sun.net.ssl.internal.ssl.InputRecord.readFully(Unknown Source)
	at com.sun.net.ssl.internal.ssl.InputRecord.read(Unknown Source)
	at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(Unknown Source)
	at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readDataRecord(Unknown
Source)
	at com.sun.net.ssl.internal.ssl.AppInputStream.read(Unknown Source)
	at
org.apache.activemq.transport.tcp.TcpBufferedInputStream.fill(TcpBufferedInputStream.java:48)
	at
org.apache.activemq.transport.tcp.TcpBufferedInputStream.read(TcpBufferedInputStream.java:55)
	at java.io.DataInputStream.readInt(Unknown Source)
	at
org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
	at java.lang.Thread.run(Unknown Source)
2013-06-13 03:09:42,499 [Thread-5       ] DEBUG FailoverTransport             
- Waiting for transport to reconnect.
2013-06-13 03:09:42,499 [ker: 1376681299] DEBUG FailoverTransport             
- Attempting connect to:
ssl://10.77.225.90:61617?wireFormat.maxInactivityDuration=600000
2013-06-13 03:09:42,499 [77.225.90:61617] WARN  DemandForwardingBridge        
- Outbound transport to avayaiq1cr.cam.wal-mart.com-broker interrupted ...
2013-06-13 03:09:42,499 [77.225.90:61617] INFO  Service                       
- Async error occurred: java.lang.IllegalStateException: Cannot lookup a
connection that had not been registered:
ID:avayaiqe1.ivr.wal-mart.com-47420-1369884669888-3:1
java.lang.IllegalStateException: Cannot lookup a connection that had not
been registered: ID:avayaiqe1.ivr.wal-mart.com-47420-1369884669888-3:1
	at
org.apache.activemq.broker.AbstractConnection.lookupConnectionState(AbstractConnection.java:241)
	at
org.apache.activemq.broker.AbstractConnection.processRemoveConnection(AbstractConnection.java:519)
	at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:59)
	at
org.apache.activemq.broker.AbstractConnection.service(AbstractConnection.java:201)
	at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:62)
	at
org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:97)
	at
org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:63)
	at org.apache.activemq.transport.vm.VMTransport.oneway(VMTransport.java:76)
	at
org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:44)
	at
org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
	at
org.apache.activemq.network.DemandForwardingBridgeSupport$2.transportInterupted(DemandForwardingBridgeSupport.java:138)
	at
org.apache.activemq.transport.TransportFilter.transportInterupted(TransportFilter.java:98)
	at
org.apache.activemq.transport.TransportFilter.transportInterupted(TransportFilter.java:98)
	at
org.apache.activemq.transport.failover.FailoverTransport.handleTransportFailure(FailoverTransport.java:223)
	at
org.apache.activemq.transport.failover.FailoverTransport.access$300(FailoverTransport.java:53)
	at
org.apache.activemq.transport.failover.FailoverTransport$1.onException(FailoverTransport.java:111)
	at
org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:94)
	at
org.apache.activemq.transport.WireFormatNegotiator.onException(WireFormatNegotiator.java:120)
	at
org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:149)
	at
org.apache.activemq.transport.TransportSupport.onException(TransportSupport.java:100)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:156)
	at java.lang.Thread.run(Unknown Source)
2013-06-13 03:09:42,503 [her: 1344918164] WARN  DemandForwardingBridge        
- Unexpected local command: ConnectionError {commandId = 24,
responseRequired = false, connectionId = null, exception =
java.lang.IllegalStateException: Cannot lookup a connection that had not
been registered: ID:avayaiqe1.ivr.wal-mart.com-47420-1369884669888-3:1}
2013-06-13 03:09:42,591 [ker: 1376681299] DEBUG WireFormatNegotiator          
- Sending: WireFormatInfo { version=1,
properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
SizePrefixDisabled=false, StackTraceEnabled=true,
MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 03:09:42,591 [77.225.90:61617] DEBUG TcpTransport                  
- TCP consumer thread starting
2013-06-13 03:09:43,024 [ker: 1376681299] DEBUG FailoverTransport             
- Connection established
2013-06-13 03:09:43,024 [ker: 1376681299] INFO  DemandForwardingBridge        
- Outbound transport to avayaiq1cr.cam.wal-mart.com-broker resumed
2013-06-13 03:09:43,024 [77.225.90:61617] DEBUG WireFormatNegotiator          
- Received WireFormat: WireFormatInfo { version=1,
properties={StackTraceEnabled=true, TightEncodingEnabled=true,
TcpNoDelayEnabled=true, SizePrefixDisabled=false,
MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 03:09:43,024 [77.225.90:61617] DEBUG WireFormatNegotiator          
- tcp://avayaiq1cr.cam.wal-mart.com/10.77.225.90:61617 before negotiation:
OpenWireFormat{version=1, cacheEnabled=false, stackTraceEnabled=false,
tightEncodingEnabled=false, sizePrefixDisabled=false}
2013-06-13 03:09:43,024 [77.225.90:61617] DEBUG WireFormatNegotiator          
- tcp://avayaiq1cr.cam.wal-mart.com/10.77.225.90:61617 after negotiation:
OpenWireFormat{version=1, cacheEnabled=true, stackTraceEnabled=true,
tightEncodingEnabled=true, sizePrefixDisabled=false}
2013-06-13 03:09:43,114 [Thread-6       ] INFO  DemandForwardingBridge        
- Network connection between vm://avayaiqe1.ivr.wal-mart.com-broker#0 and
ssl://10.77.225.90:61617?wireFormat.maxInactivityDuration=600000(avayaiq1cr.cam.wal-mart.com-broker)
has been established.
2013-06-13 03:10:43,213 [iveMQ Scheduler] DEBUG Transport                     
- Transport failed: org.apache.activemq.transport.InactivityIOException:
Channel was inactive for too long.
org.apache.activemq.transport.InactivityIOException: Channel was inactive
for too long.
	at
org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
	at
org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
	at
org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
	at
edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
	at
edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
	at
edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
	at
edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
	at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
	at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
	at java.lang.Thread.run(Unknown Source)
2013-06-13 03:11:08,849 [-mart.com:61617] DEBUG WireFormatNegotiator          
- Sending: WireFormatInfo { version=1,
properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
SizePrefixDisabled=false, StackTraceEnabled=true,
MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 03:11:08,849 [77.225.90:39452] DEBUG TcpTransport                  
- TCP consumer thread starting
2013-06-13 03:11:09,284 [77.225.90:39452] DEBUG WireFormatNegotiator          
- Received WireFormat: WireFormatInfo { version=1,
properties={StackTraceEnabled=true, TightEncodingEnabled=true,
TcpNoDelayEnabled=true, SizePrefixDisabled=false,
MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 03:11:09,284 [77.225.90:39452] DEBUG WireFormatNegotiator          
- tcp:///10.77.225.90:39452 before negotiation: OpenWireFormat{version=1,
cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false}
2013-06-13 03:11:09,284 [77.225.90:39452] DEBUG WireFormatNegotiator          
- tcp:///10.77.225.90:39452 after negotiation: OpenWireFormat{version=1,
cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true,
sizePrefixDisabled=false}
2013-06-13 03:12:11,183 [eckpoint Worker] DEBUG JournalPersistenceAdapter     
- Checkpoint started.



--------------------------

2013-06-13 03:51:09,286 [iveMQ Scheduler] DEBUG Transport                     
- Transport failed: org.apache.activemq.transport.InactivityIOException:
Channel was inactive for too long.
org.apache.activemq.transport.InactivityIOException: Channel was inactive
for too long.
	at
org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
	at
org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
	at
org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
	at
edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
	at
edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
	at
edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
	at
edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
	at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
	at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
	at java.lang.Thread.run(Unknown Source)
2013-06-13 03:51:31,017 [77.225.90:37022] DEBUG TcpTransport                  
- TCP consumer thread starting
2013-06-13 03:51:31,017 [-mart.com:61617] DEBUG WireFormatNegotiator          
- Sending: WireFormatInfo { version=1,
properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
SizePrefixDisabled=false, StackTraceEnabled=true,
MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 03:51:31,455 [77.225.90:37022] DEBUG WireFormatNegotiator          
- Received WireFormat: WireFormatInfo { version=1,
properties={StackTraceEnabled=true, TightEncodingEnabled=true,
TcpNoDelayEnabled=true, SizePrefixDisabled=false,
MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 03:51:31,456 [77.225.90:37022] DEBUG WireFormatNegotiator          
- tcp:///10.77.225.90:37022 before negotiation: OpenWireFormat{version=1,
cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false}
2013-06-13 03:51:31,456 [77.225.90:37022] DEBUG WireFormatNegotiator          
- tcp:///10.77.225.90:37022 after negotiation: OpenWireFormat{version=1,
cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true,
sizePrefixDisabled=false}
2013-06-13 03:52:31,466 [77.225.90:37022] DEBUG Transport                     
- Transport failed: java.io.EOFException
java.io.EOFException
	at java.io.DataInputStream.readInt(Unknown Source)
	at
org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
	at java.lang.Thread.run(Unknown Source)
2013-06-13 03:52:31,555 [77.225.90:37027] DEBUG TcpTransport                  
- TCP consumer thread starting
2013-06-13 03:52:31,555 [-mart.com:61617] DEBUG WireFormatNegotiator          
- Sending: WireFormatInfo { version=1,
properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
SizePrefixDisabled=false, StackTraceEnabled=true,
MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 03:52:31,992 [77.225.90:37027] DEBUG WireFormatNegotiator          
- Received WireFormat: WireFormatInfo { version=1,
properties={StackTraceEnabled=true, TightEncodingEnabled=true,
TcpNoDelayEnabled=true, SizePrefixDisabled=false,
MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 03:52:31,992 [77.225.90:37027] DEBUG WireFormatNegotiator          
- tcp:///10.77.225.90:37027 before negotiation: OpenWireFormat{version=1,
cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false}
2013-06-13 03:52:31,992 [77.225.90:37027] DEBUG WireFormatNegotiator          
- tcp:///10.77.225.90:37027 after negotiation: OpenWireFormat{version=1,
cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true,
sizePrefixDisabled=false}
2013-06-13 03:52:31,997 [cher: 872130173] DEBUG Transport                     
- Transport failed: java.net.SocketException: Connection closed by remote
host
java.net.SocketException: Connection closed by remote host
	at com.sun.net.ssl.internal.ssl.SSLSocketImpl.checkWrite(Unknown Source)
	at com.sun.net.ssl.internal.ssl.AppOutputStream.write(Unknown Source)
	at
org.apache.activemq.transport.tcp.TcpBufferedOutputStream.flush(TcpBufferedOutputStream.java:108)
	at java.io.DataOutputStream.flush(Unknown Source)
	at
org.apache.activemq.transport.tcp.TcpTransport.oneway(TcpTransport.java:125)
	at
org.apache.activemq.transport.InactivityMonitor.oneway(InactivityMonitor.java:141)
	at
org.apache.activemq.transport.TransportFilter.oneway(TransportFilter.java:78)
	at
org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:77)
	at
org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:44)
	at
org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
	at
org.apache.activemq.broker.TransportConnection.dispatch(TransportConnection.java:211)
	at
org.apache.activemq.broker.AbstractConnection.processDispatch(AbstractConnection.java:581)
	at
org.apache.activemq.broker.AbstractConnection.iterate(AbstractConnection.java:597)
	at
org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:87)
	at
org.apache.activemq.thread.DedicatedTaskRunner.access$000(DedicatedTaskRunner.java:24)
	at
org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:38)
2013-06-13 03:52:31,997 [77.225.90:37027] DEBUG Transport                     
- Transport failed: java.io.EOFException
java.io.EOFException
	at java.io.DataInputStream.readInt(Unknown Source)
	at
org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
	at java.lang.Thread.run(Unknown Source)
2013-06-13 03:52:31,998 [77.225.90:37027] WARN  ManagedTransportConnection    
- Failed to unregister mbean:
org.apache.activemq:BrokerName=avayaiqe1.ivr.wal-mart.com-broker,Type=Connection,ConnectorName=secured,Connection=NC_avayaiq1cr.cam.wal-mart.com-broker_outboundavayaiq1cr.cam.wal-mart.com-broker
2013-06-13 03:52:32,082 [-mart.com:61617] DEBUG WireFormatNegotiator          
- Sending: WireFormatInfo { version=1,
properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
SizePrefixDisabled=false, StackTraceEnabled=true,
MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 03:52:32,082 [77.225.90:37028] DEBUG TcpTransport                  
- TCP consumer thread starting
2013-06-13 03:52:32,516 [77.225.90:37028] DEBUG WireFormatNegotiator          
- Received WireFormat: WireFormatInfo { version=1,
properties={StackTraceEnabled=true, TightEncodingEnabled=true,
TcpNoDelayEnabled=true, SizePrefixDisabled=false,
MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 03:52:32,516 [77.225.90:37028] DEBUG WireFormatNegotiator          
- tcp:///10.77.225.90:37028 before negotiation: OpenWireFormat{version=1,
cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false}
2013-06-13 03:52:32,516 [77.225.90:37028] DEBUG WireFormatNegotiator          
- tcp:///10.77.225.90:37028 after negotiation: OpenWireFormat{version=1,
cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true,
sizePrefixDisabled=false}
2013-06-13 03:56:11,183 [eckpoint Worker] DEBUG JournalPersistenceAdapter     
- Checkpoint started.


---------------------------------
2013-06-13 04:23:02,518 [iveMQ Scheduler] DEBUG Transport                     
- Transport failed: org.apache.activemq.transport.InactivityIOException:
Channel was inactive for too long.
org.apache.activemq.transport.InactivityIOException: Channel was inactive
for too long.
	at
org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
	at
org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
	at
org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
	at
edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
	at
edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
	at
edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
	at
edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
	at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
	at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
	at java.lang.Thread.run(Unknown Source)
2013-06-13 04:23:11,183 [eckpoint Worker] DEBUG JournalPersistenceAdapter     
- Checkpoint started.




On Host B:
--------------


2013-06-13 02:10:43,257 [.19.48.24:61617] WARN  DemandForwardingBridge        
- Outbound transport to avayaiqe1.ivr.wal-mart.com-broker interrupted ...
2013-06-13 02:10:43,266 [.19.48.24:61617] DEBUG FailoverTransport             
- Transport failed, starting up reconnect task
java.io.EOFException
	at java.io.DataInputStream.readInt(Unknown Source)
	at
org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
	at java.lang.Thread.run(Unknown Source)
2013-06-13 02:10:43,266 [ker: 1430534144] DEBUG FailoverTransport             
- Attempting connect to:
ssl://172.19.48.24:61617?wireFormat.maxInactivityDuration=600000
2013-06-13 02:11:08,805 [.19.48.24:61617] DEBUG TcpTransport                  
- TCP consumer thread starting
2013-06-13 02:11:08,805 [ker: 1430534144] DEBUG WireFormatNegotiator          
- Sending: WireFormatInfo { version=1,
properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
SizePrefixDisabled=false, StackTraceEnabled=true,
MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 02:11:09,239 [.19.48.24:61617] DEBUG WireFormatNegotiator          
- Received WireFormat: WireFormatInfo { version=1,
properties={StackTraceEnabled=true, TightEncodingEnabled=true,
TcpNoDelayEnabled=true, SizePrefixDisabled=false,
MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 02:11:09,239 [.19.48.24:61617] DEBUG WireFormatNegotiator          
- tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 before negotiation:
OpenWireFormat{version=1, cacheEnabled=false, stackTraceEnabled=false,
tightEncodingEnabled=false, sizePrefixDisabled=false}
2013-06-13 02:11:09,239 [.19.48.24:61617] DEBUG WireFormatNegotiator          
- tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 after negotiation:
OpenWireFormat{version=1, cacheEnabled=true, stackTraceEnabled=true,
tightEncodingEnabled=true, sizePrefixDisabled=false}
2013-06-13 02:11:09,239 [ker: 1430534144] DEBUG FailoverTransport             
- Connection established
2013-06-13 02:11:09,239 [ker: 1430534144] INFO  DemandForwardingBridge        
- Outbound transport to avayaiqe1.ivr.wal-mart.com-broker resumed
2013-06-13 02:11:09,328 [Thread-8       ] INFO  DemandForwardingBridge        
- Network connection between vm://avayaiq1cr.cam.wal-mart.com-broker#0 and
ssl://172.19.48.24:61617?wireFormat.maxInactivityDuration=600000(avayaiqe1.ivr.wal-mart.com-broker)
has been established.
2013-06-13 02:11:09,333 [.19.48.24:61617] DEBUG DemandForwardingBridge        
- Forwarding sub on vm://avayaiq1cr.cam.wal-mart.com-broker#0 from
avayaiqe1.ivr.wal-mart.com-broker :  ConsumerInfo {commandId = 12,
responseRequired = true, consumerId =
ID:avayaiqe1.ivr.wal-mart.com-55507-1368756619514-1:9:5:1, destination =
topic://com.avaya.syncandnotification.namemgmt.NOTIFICATIONTOPIC,
prefetchSize = 32766, maximumPendingMessageLimit = 0, browser = false,
dispatchAsync = false, selector = null, subcriptionName = null, noLocal =
false, exclusive = false, retroactive = false, priority = 0, brokerPath =
[ID:avayaiqe1.ivr.wal-mart.com-47420-1369884669888-1:0],
optimizedAcknowledge = false, noRangeAcks = false, additionalPredicate =
null}
2013-06-13 02:11:13,070 [iveMQ Scheduler] DEBUG Transport                     
- Transport failed: org.apache.activemq.transport.InactivityIOException:
Channel was inactive for too long.
org.apache.activemq.transport.InactivityIOException: Channel was inactive
for too long.
	at
org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
	at
org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
	at
org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
	at
edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
	at
edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
	at
edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
	at
edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
	at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
	at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
	at java.lang.Thread.run(Unknown Source)

--------------------------------


2013-06-13 02:51:30,871 [.19.48.24:61617] WARN  DemandForwardingBridge        
- Outbound transport to avayaiqe1.ivr.wal-mart.com-broker interrupted ...
2013-06-13 02:51:30,879 [.19.48.24:61617] DEBUG FailoverTransport             
- Transport failed, starting up reconnect task
java.io.EOFException
	at java.io.DataInputStream.readInt(Unknown Source)
	at
org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
	at java.lang.Thread.run(Unknown Source)
2013-06-13 02:51:30,879 [ker: 1430534144] DEBUG FailoverTransport             
- Attempting connect to:
ssl://172.19.48.24:61617?wireFormat.maxInactivityDuration=600000
2013-06-13 02:51:30,968 [.19.48.24:61617] DEBUG TcpTransport                  
- TCP consumer thread starting
2013-06-13 02:51:30,968 [ker: 1430534144] DEBUG WireFormatNegotiator          
- Sending: WireFormatInfo { version=1,
properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
SizePrefixDisabled=false, StackTraceEnabled=true,
MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 02:51:31,412 [.19.48.24:61617] DEBUG WireFormatNegotiator          
- Received WireFormat: WireFormatInfo { version=1,
properties={StackTraceEnabled=true, TightEncodingEnabled=true,
TcpNoDelayEnabled=true, SizePrefixDisabled=false,
MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 02:51:31,412 [.19.48.24:61617] DEBUG WireFormatNegotiator          
- tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 before negotiation:
OpenWireFormat{version=1, cacheEnabled=false, stackTraceEnabled=false,
tightEncodingEnabled=false, sizePrefixDisabled=false}
2013-06-13 02:51:31,412 [.19.48.24:61617] DEBUG WireFormatNegotiator          
- tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 after negotiation:
OpenWireFormat{version=1, cacheEnabled=true, stackTraceEnabled=true,
tightEncodingEnabled=true, sizePrefixDisabled=false}
2013-06-13 02:51:31,412 [ker: 1430534144] DEBUG FailoverTransport             
- Connection established
2013-06-13 02:51:31,412 [ker: 1430534144] INFO  DemandForwardingBridge        
- Outbound transport to avayaiqe1.ivr.wal-mart.com-broker resumed
2013-06-13 02:51:31,501 [Thread-10      ] INFO  DemandForwardingBridge        
- Network connection between vm://avayaiq1cr.cam.wal-mart.com-broker#0 and
ssl://172.19.48.24:61617?wireFormat.maxInactivityDuration=600000(avayaiqe1.ivr.wal-mart.com-broker)
has been established.
2013-06-13 02:51:31,883 [.19.48.24:61617] DEBUG DemandForwardingBridge        
- Forwarding sub on vm://avayaiq1cr.cam.wal-mart.com-broker#0 from
avayaiqe1.ivr.wal-mart.com-broker :  ConsumerInfo {commandId = 12,
responseRequired = true, consumerId =
ID:avayaiqe1.ivr.wal-mart.com-55507-1368756619514-1:9:5:1, destination =
topic://com.avaya.syncandnotification.namemgmt.NOTIFICATIONTOPIC,
prefetchSize = 32766, maximumPendingMessageLimit = 0, browser = false,
dispatchAsync = false, selector = null, subcriptionName = null, noLocal =
false, exclusive = false, retroactive = false, priority = 0, brokerPath =
[ID:avayaiqe1.ivr.wal-mart.com-47420-1369884669888-1:0],
optimizedAcknowledge = false, noRangeAcks = false, additionalPredicate =
null}

----------------------


2013-06-13 02:52:31,413 [iveMQ Scheduler] WARN  DemandForwardingBridge        
- Outbound transport to avayaiqe1.ivr.wal-mart.com-broker interrupted ...
2013-06-13 02:52:31,422 [iveMQ Scheduler] DEBUG FailoverTransport             
- Transport failed, starting up reconnect task
org.apache.activemq.transport.InactivityIOException: Channel was inactive
for too long.
	at
org.apache.activemq.transport.InactivityMonitor.readCheck(InactivityMonitor.java:101)
	at
org.apache.activemq.transport.InactivityMonitor.access$000(InactivityMonitor.java:35)
	at
org.apache.activemq.transport.InactivityMonitor$1.run(InactivityMonitor.java:51)
	at
edu.emory.mathcs.backport.java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:431)
	at
edu.emory.mathcs.backport.java.util.concurrent.FutureTask.runAndReset(FutureTask.java:198)
	at
edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:189)
	at
edu.emory.mathcs.backport.java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:213)
	at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
	at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
	at java.lang.Thread.run(Unknown Source)
2013-06-13 02:52:31,422 [ker: 1430534144] DEBUG FailoverTransport             
- Attempting connect to:
ssl://172.19.48.24:61617?wireFormat.maxInactivityDuration=600000
2013-06-13 02:52:31,511 [.19.48.24:61617] DEBUG TcpTransport                  
- TCP consumer thread starting
2013-06-13 02:52:31,511 [ker: 1430534144] DEBUG WireFormatNegotiator          
- Sending: WireFormatInfo { version=1,
properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
SizePrefixDisabled=false, StackTraceEnabled=true,
MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 02:52:31,947 [.19.48.24:61617] DEBUG WireFormatNegotiator          
- Received WireFormat: WireFormatInfo { version=1,
properties={StackTraceEnabled=true, TightEncodingEnabled=true,
TcpNoDelayEnabled=true, SizePrefixDisabled=false,
MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 02:52:31,947 [.19.48.24:61617] DEBUG WireFormatNegotiator          
- tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 before negotiation:
OpenWireFormat{version=1, cacheEnabled=false, stackTraceEnabled=false,
tightEncodingEnabled=false, sizePrefixDisabled=false}
2013-06-13 02:52:31,947 [.19.48.24:61617] DEBUG WireFormatNegotiator          
- tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 after negotiation:
OpenWireFormat{version=1, cacheEnabled=true, stackTraceEnabled=true,
tightEncodingEnabled=true, sizePrefixDisabled=false}
2013-06-13 02:52:31,947 [ker: 1430534144] DEBUG FailoverTransport             
- Connection established
2013-06-13 02:52:31,947 [ker: 1430534144] INFO  DemandForwardingBridge        
- Outbound transport to avayaiqe1.ivr.wal-mart.com-broker resumed
2013-06-13 02:52:31,947 [.19.48.24:61617] DEBUG FailoverTransport             
- Transport failed, starting up reconnect task
java.net.SocketException: Socket closed
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(Unknown Source)
	at com.sun.net.ssl.internal.ssl.InputRecord.readFully(Unknown Source)
	at com.sun.net.ssl.internal.ssl.InputRecord.read(Unknown Source)
	at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(Unknown Source)
	at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readDataRecord(Unknown
Source)
	at com.sun.net.ssl.internal.ssl.AppInputStream.read(Unknown Source)
	at
org.apache.activemq.transport.tcp.TcpBufferedInputStream.fill(TcpBufferedInputStream.java:48)
	at
org.apache.activemq.transport.tcp.TcpBufferedInputStream.read(TcpBufferedInputStream.java:55)
	at java.io.DataInputStream.readInt(Unknown Source)
	at
org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
	at java.lang.Thread.run(Unknown Source)
2013-06-13 02:52:31,947 [Thread-11      ] DEBUG FailoverTransport             
- Waiting for transport to reconnect.
2013-06-13 02:52:31,947 [ker: 1430534144] DEBUG FailoverTransport             
- Attempting connect to:
ssl://172.19.48.24:61617?wireFormat.maxInactivityDuration=600000
2013-06-13 02:52:31,948 [.19.48.24:61617] WARN  DemandForwardingBridge        
- Outbound transport to avayaiqe1.ivr.wal-mart.com-broker interrupted ...
2013-06-13 02:52:31,948 [.19.48.24:61617] INFO  Service                       
- Async error occurred: java.lang.IllegalStateException: Cannot lookup a
connection that had not been registered:
ID:avayaiq1cr.cam.wal-mart.com-46291-1369884580806-3:7
java.lang.IllegalStateException: Cannot lookup a connection that had not
been registered: ID:avayaiq1cr.cam.wal-mart.com-46291-1369884580806-3:7
	at
org.apache.activemq.broker.AbstractConnection.lookupConnectionState(AbstractConnection.java:241)
	at
org.apache.activemq.broker.AbstractConnection.processRemoveConnection(AbstractConnection.java:519)
	at org.apache.activemq.command.RemoveInfo.visit(RemoveInfo.java:59)
	at
org.apache.activemq.broker.AbstractConnection.service(AbstractConnection.java:201)
	at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:62)
	at
org.apache.activemq.transport.ResponseCorrelator.onCommand(ResponseCorrelator.java:97)
	at
org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:63)
	at org.apache.activemq.transport.vm.VMTransport.oneway(VMTransport.java:76)
	at
org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:44)
	at
org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
	at
org.apache.activemq.network.DemandForwardingBridgeSupport$2.transportInterupted(DemandForwardingBridgeSupport.java:138)
	at
org.apache.activemq.transport.TransportFilter.transportInterupted(TransportFilter.java:98)
	at
org.apache.activemq.transport.TransportFilter.transportInterupted(TransportFilter.java:98)
	at
org.apache.activemq.transport.failover.FailoverTransport.handleTransportFailure(FailoverTransport.java:223)
	at
org.apache.activemq.transport.failover.FailoverTransport.access$300(FailoverTransport.java:53)
	at
org.apache.activemq.transport.failover.FailoverTransport$1.onException(FailoverTransport.java:111)
	at
org.apache.activemq.transport.TransportFilter.onException(TransportFilter.java:94)
	at
org.apache.activemq.transport.WireFormatNegotiator.onException(WireFormatNegotiator.java:120)
	at
org.apache.activemq.transport.InactivityMonitor.onException(InactivityMonitor.java:149)
	at
org.apache.activemq.transport.TransportSupport.onException(TransportSupport.java:100)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:156)
	at java.lang.Thread.run(Unknown Source)
2013-06-13 02:52:31,948 [tcher: 98401221] WARN  DemandForwardingBridge        
- Unexpected local command: ConnectionError {commandId = 1599,
responseRequired = false, connectionId = null, exception =
java.lang.IllegalStateException: Cannot lookup a connection that had not
been registered: ID:avayaiq1cr.cam.wal-mart.com-46291-1369884580806-3:7}
2013-06-13 02:52:32,040 [.19.48.24:61617] DEBUG TcpTransport                  
- TCP consumer thread starting
2013-06-13 02:52:32,040 [ker: 1430534144] DEBUG WireFormatNegotiator          
- Sending: WireFormatInfo { version=1,
properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
SizePrefixDisabled=false, StackTraceEnabled=true,
MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 02:52:32,472 [ker: 1430534144] DEBUG FailoverTransport             
- Connection established
2013-06-13 02:52:32,472 [ker: 1430534144] INFO  DemandForwardingBridge        
- Outbound transport to avayaiqe1.ivr.wal-mart.com-broker resumed
2013-06-13 02:52:32,472 [.19.48.24:61617] DEBUG WireFormatNegotiator          
- Received WireFormat: WireFormatInfo { version=1,
properties={StackTraceEnabled=true, TightEncodingEnabled=true,
TcpNoDelayEnabled=true, SizePrefixDisabled=false,
MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-06-13 02:52:32,472 [.19.48.24:61617] DEBUG WireFormatNegotiator          
- tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 before negotiation:
OpenWireFormat{version=1, cacheEnabled=false, stackTraceEnabled=false,
tightEncodingEnabled=false, sizePrefixDisabled=false}
2013-06-13 02:52:32,472 [.19.48.24:61617] DEBUG WireFormatNegotiator          
- tcp://avayaiqe1.ivr.wal-mart.com/172.19.48.24:61617 after negotiation:
OpenWireFormat{version=1, cacheEnabled=true, stackTraceEnabled=true,
tightEncodingEnabled=true, sizePrefixDisabled=false}
2013-06-13 02:52:32,560 [Thread-12      ] INFO  DemandForwardingBridge        
- Network connection between vm://avayaiq1cr.cam.wal-mart.com-broker#0 and
ssl://172.19.48.24:61617?wireFormat.maxInactivityDuration=600000(avayaiqe1.ivr.wal-mart.com-broker)
has been established.
2013-06-13 02:53:11,614 [eckpoint Worker] DEBUG JournalPersistenceAdapter     
- Checkpoint started.





--
View this message in context: http://activemq.2283324.n4.nabble.com/DemandForwardingBridge-Ignoring-sub-ConsumerInf-tp4668211p4668353.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: DemandForwardingBridge - Ignoring sub ConsumerInf

Posted by Dejan Bosanac <de...@nighttale.net>.
Hi,

EOFException means that client closed connection unexpectedly, so it might
be that clients just closes socket or network connection between brokers
goes away. But as far as I see from your messages you don't experience any
problems, so you should worry about it. Those debug messages from your last
email are no indication of any error.

Regards
--
Dejan Bosanac
----------------------
Red Hat, Inc.
FuseSource is now part of Red Hat
dbosanac@redhat.com
Twitter: @dejanb
Blog: http://sensatic.net
ActiveMQ in Action: http://www.manning.com/snyder/


On Fri, Jun 14, 2013 at 7:41 PM, mmg <ma...@gmail.com> wrote:

> Hi Dejan,
>
> I dont know much about the networking. Could you please explain what do you
> mean by unstable network? Is there any way I can measure/quntify
> "unstability" of the network? What do I need to take care of it?
>
>
> I am also seeing the following DEBUG messages which are identical (except
> the date and time). Does that mean a same message is getting forwarded
> twice? Is it because of the unstable network?
>
> 2013-06-11 13:30:35,920 [tcher: 98401221] DEBUG DemandForwardingBridge
> - bridging avayaiq1cr.cam.wal-mart.com-broker ->
> avayaiqe1.ivr.wal-mart.com-broker: ActiveMQObjectMessage {commandId = 614,
> responseRequired = true, messageId =
> ID:avayaiq1cr.cam.wal-mart.com-45652-1369884935598-1:0:1:1:610,
> originalDestination = null, originalTransactionId = null, producerId =
> ID:avayaiq1cr.cam.wal-mart.com-46291-1369884580806-3:2:1:1, destination =
> topic://com.avaya.ccr.adminrecorder.sourcedatasync, transactionId = null,
> expiration = 0, timestamp = 1370979035920, arrival = 0, correlationId =
> null, replyTo = null, persistent = true, type = null, priority = 4, groupID
> = null, groupSequence = 0, targetConsumerId = null, compressed = false,
> userID = null, content = org.apache.activeio.packet.ByteSequence@3004460d,
> marshalledProperties = org.apache.activeio.packet.ByteSequence@6893181b,
> dataStructure = null, redeliveryCounter = 0, size = 1398, properties =
> {sourceUUID=2c93b098396fb59c01396fcd3693000d}, readOnlyProperties = false,
> readOnlyBody = false}
> 2013-06-11 13:30:35,921 [tcher: 98401221] DEBUG DemandForwardingBridge
> - bridging avayaiq1cr.cam.wal-mart.com-broker ->
> avayaiqe1.ivr.wal-mart.com-broker: ActiveMQObjectMessage {commandId = 614,
> responseRequired = true, messageId =
> ID:avayaiq1cr.cam.wal-mart.com-45652-1369884935598-1:0:1:1:610,
> originalDestination = null, originalTransactionId = null, producerId =
> ID:avayaiq1cr.cam.wal-mart.com-46291-1369884580806-3:2:1:1, destination =
> topic://com.avaya.ccr.adminrecorder.sourcedatasync, transactionId = null,
> expiration = 0, timestamp = 1370979035920, arrival = 0, correlationId =
> null, replyTo = null, persistent = true, type = null, priority = 4, groupID
> = null, groupSequence = 0, targetConsumerId = null, compressed = false,
> userID = null, content = org.apache.activeio.packet.ByteSequence@3004460d,
> marshalledProperties = org.apache.activeio.packet.ByteSequence@6893181b,
> dataStructure = null, redeliveryCounter = 0, size = 1398, properties =
> {sourceUUID=2c93b098396fb59c01396fcd3693000d}, readOnlyProperties = false,
> readOnlyBody = false}
>
>
> Again Thanks for your help.
> -mmg
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/DemandForwardingBridge-Ignoring-sub-ConsumerInf-tp4668211p4668221.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>

Re: DemandForwardingBridge - Ignoring sub ConsumerInf

Posted by mmg <ma...@gmail.com>.
Hi Dejan,

I dont know much about the networking. Could you please explain what do you
mean by unstable network? Is there any way I can measure/quntify
"unstability" of the network? What do I need to take care of it?


I am also seeing the following DEBUG messages which are identical (except
the date and time). Does that mean a same message is getting forwarded
twice? Is it because of the unstable network?

2013-06-11 13:30:35,920 [tcher: 98401221] DEBUG DemandForwardingBridge        
- bridging avayaiq1cr.cam.wal-mart.com-broker ->
avayaiqe1.ivr.wal-mart.com-broker: ActiveMQObjectMessage {commandId = 614,
responseRequired = true, messageId =
ID:avayaiq1cr.cam.wal-mart.com-45652-1369884935598-1:0:1:1:610,
originalDestination = null, originalTransactionId = null, producerId =
ID:avayaiq1cr.cam.wal-mart.com-46291-1369884580806-3:2:1:1, destination =
topic://com.avaya.ccr.adminrecorder.sourcedatasync, transactionId = null,
expiration = 0, timestamp = 1370979035920, arrival = 0, correlationId =
null, replyTo = null, persistent = true, type = null, priority = 4, groupID
= null, groupSequence = 0, targetConsumerId = null, compressed = false,
userID = null, content = org.apache.activeio.packet.ByteSequence@3004460d,
marshalledProperties = org.apache.activeio.packet.ByteSequence@6893181b,
dataStructure = null, redeliveryCounter = 0, size = 1398, properties =
{sourceUUID=2c93b098396fb59c01396fcd3693000d}, readOnlyProperties = false,
readOnlyBody = false}
2013-06-11 13:30:35,921 [tcher: 98401221] DEBUG DemandForwardingBridge        
- bridging avayaiq1cr.cam.wal-mart.com-broker ->
avayaiqe1.ivr.wal-mart.com-broker: ActiveMQObjectMessage {commandId = 614,
responseRequired = true, messageId =
ID:avayaiq1cr.cam.wal-mart.com-45652-1369884935598-1:0:1:1:610,
originalDestination = null, originalTransactionId = null, producerId =
ID:avayaiq1cr.cam.wal-mart.com-46291-1369884580806-3:2:1:1, destination =
topic://com.avaya.ccr.adminrecorder.sourcedatasync, transactionId = null,
expiration = 0, timestamp = 1370979035920, arrival = 0, correlationId =
null, replyTo = null, persistent = true, type = null, priority = 4, groupID
= null, groupSequence = 0, targetConsumerId = null, compressed = false,
userID = null, content = org.apache.activeio.packet.ByteSequence@3004460d,
marshalledProperties = org.apache.activeio.packet.ByteSequence@6893181b,
dataStructure = null, redeliveryCounter = 0, size = 1398, properties =
{sourceUUID=2c93b098396fb59c01396fcd3693000d}, readOnlyProperties = false,
readOnlyBody = false}


Again Thanks for your help.
-mmg



--
View this message in context: http://activemq.2283324.n4.nabble.com/DemandForwardingBridge-Ignoring-sub-ConsumerInf-tp4668211p4668221.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: DemandForwardingBridge - Ignoring sub ConsumerInf

Posted by Dejan Bosanac <de...@nighttale.net>.
Hi,

there will be no any negative effects. Just, as there are only two brokers
in the network there's no any reason to have ttl set to 3 (and debug
message just saying it will ignore unnecessary subs).

>From the exceptions you're seeing looks like you have an unstable network
connection and are not related to this setting.

Regards
--
Dejan Bosanac
----------------------
Red Hat, Inc.
FuseSource is now part of Red Hat
dbosanac@redhat.com
Twitter: @dejanb
Blog: http://sensatic.net
ActiveMQ in Action: http://www.manning.com/snyder/


On Fri, Jun 14, 2013 at 4:39 PM, mmg <ma...@gmail.com> wrote:

> Hi Dejan,
>
> Thanks for a quick reply.
>
> We have two brokers in on two different Linux host and the networkTTL is
> set
> to 3.
>
> Network connector on broker A
> <networkConnector conduitSubscriptions=&quot;false&quot;
> dynamicOnly=&quot;false&quot; failover=&quot;true&quot;
> name=&quot;brokerB&quot; networkTTL=&quot;3&quot;
> uri=&quot;static:(ssl://&lt;IP of host
> B>:61617?wireFormat.maxInactivityDuration=600000)"/>
>
>
> Network connector on broker B
> <networkConnector conduitSubscriptions=&quot;false&quot;
> dynamicOnly=&quot;false&quot; failover=&quot;true&quot;
> name=&quot;brokerA&quot; networkTTL=&quot;3&quot;
> uri=&quot;static:(ssl://&lt;IP of host
> A>:61617?wireFormat.maxInactivityDuration=600000)"/>
>
>
>
> I did not understand what kind of negative effect will be there? Could you
> please give some example?
>
> In this setup, we also observe java.io.EOFException after every hour (below
> are log messages) in activemq.log on host A. What could be possible reasons
> for this exception? Should we be worried about this exception?
>
> 2013-05-29 23:00:04,637 [127.0.0.1:36760] DEBUG WireFormatNegotiator
> - tcp:///127.0.0.1:36760 before negotiation: OpenWireFormat{version=1,
> cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false,
> sizePrefixDisabled=false}
> 2013-05-29 23:00:04,637 [127.0.0.1:36760] DEBUG WireFormatNegotiator
> - tcp:///127.0.0.1:36760 after negotiation: OpenWireFormat{version=1,
> cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true,
> sizePrefixDisabled=false}
> 2013-05-29 23:00:04,698 [127.0.0.1:36760] DEBUG AbstractRegion
> - Adding destination:
> topic://ActiveMQ.Advisory.Producer.Topic.com.avaya.coreservice.um.USERS
> 2013-05-29 23:00:08,738 [127.0.0.1:36760] DEBUG Transport
> - Transport failed: java.io.EOFException
> java.io.EOFException
>         at java.io.DataInputStream.readInt(Unknown Source)
>         at
>
> org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
>         at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
>         at java.lang.Thread.run(Unknown Source)
> 2013-05-29 23:01:01,171 [Duration=600000] DEBUG WireFormatNegotiator
> - Sending: WireFormatInfo { version=1,
> properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
> SizePrefixDisabled=false, StackTraceEnabled=true,
> MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 2013-05-29 23:01:01,171 [127.0.0.1:36910] DEBUG TcpTransport
> - TCP consumer thread starting
> 2013-05-29 23:01:01,171 [127.0.0.1:36910] DEBUG WireFormatNegotiator
> - Received WireFormat: WireFormatInfo { version=1,
> properties={StackTraceEnabled=true, TightEncodingEnabled=true,
> TcpNoDelayEnabled=true, SizePrefixDisabled=false,
> MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
>
>
> Thanks.
>
>
>
>
>
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/DemandForwardingBridge-Ignoring-sub-ConsumerInf-tp4668211p4668215.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>

Re: DemandForwardingBridge - Ignoring sub ConsumerInf

Posted by mmg <ma...@gmail.com>.
Hi Dejan,

Thanks for a quick reply. 

We have two brokers in on two different Linux host and the networkTTL is set
to 3.

Network connector on broker A 
<networkConnector conduitSubscriptions=&quot;false&quot;
dynamicOnly=&quot;false&quot; failover=&quot;true&quot;
name=&quot;brokerB&quot; networkTTL=&quot;3&quot;
uri=&quot;static:(ssl://&lt;IP of host
B>:61617?wireFormat.maxInactivityDuration=600000)"/> 


Network connector on broker B 
<networkConnector conduitSubscriptions=&quot;false&quot;
dynamicOnly=&quot;false&quot; failover=&quot;true&quot;
name=&quot;brokerA&quot; networkTTL=&quot;3&quot;
uri=&quot;static:(ssl://&lt;IP of host
A>:61617?wireFormat.maxInactivityDuration=600000)"/> 



I did not understand what kind of negative effect will be there? Could you
please give some example?

In this setup, we also observe java.io.EOFException after every hour (below
are log messages) in activemq.log on host A. What could be possible reasons
for this exception? Should we be worried about this exception? 

2013-05-29 23:00:04,637 [127.0.0.1:36760] DEBUG WireFormatNegotiator          
- tcp:///127.0.0.1:36760 before negotiation: OpenWireFormat{version=1,
cacheEnabled=false, stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false}
2013-05-29 23:00:04,637 [127.0.0.1:36760] DEBUG WireFormatNegotiator          
- tcp:///127.0.0.1:36760 after negotiation: OpenWireFormat{version=1,
cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true,
sizePrefixDisabled=false}
2013-05-29 23:00:04,698 [127.0.0.1:36760] DEBUG AbstractRegion                
- Adding destination:
topic://ActiveMQ.Advisory.Producer.Topic.com.avaya.coreservice.um.USERS
2013-05-29 23:00:08,738 [127.0.0.1:36760] DEBUG Transport                     
- Transport failed: java.io.EOFException
java.io.EOFException
	at java.io.DataInputStream.readInt(Unknown Source)
	at
org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:274)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:142)
	at java.lang.Thread.run(Unknown Source)
2013-05-29 23:01:01,171 [Duration=600000] DEBUG WireFormatNegotiator          
- Sending: WireFormatInfo { version=1,
properties={TightEncodingEnabled=true, TcpNoDelayEnabled=true,
SizePrefixDisabled=false, StackTraceEnabled=true,
MaxInactivityDuration=600000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-29 23:01:01,171 [127.0.0.1:36910] DEBUG TcpTransport                  
- TCP consumer thread starting
2013-05-29 23:01:01,171 [127.0.0.1:36910] DEBUG WireFormatNegotiator          
- Received WireFormat: WireFormatInfo { version=1,
properties={StackTraceEnabled=true, TightEncodingEnabled=true,
TcpNoDelayEnabled=true, SizePrefixDisabled=false,
MaxInactivityDuration=30000, CacheEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}


Thanks.








--
View this message in context: http://activemq.2283324.n4.nabble.com/DemandForwardingBridge-Ignoring-sub-ConsumerInf-tp4668211p4668215.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: DemandForwardingBridge - Ignoring sub ConsumerInf

Posted by Dejan Bosanac <de...@nighttale.net>.
Hi,

this means that you have a loop in your broker network somewhere. It should
have a negative effect as messages will still be propagated to the remote
broker. You might consider using networkTTL property and set it to the max
number of brokers your message can actually hop.

Regards
--
Dejan Bosanac
----------------------
Red Hat, Inc.
FuseSource is now part of Red Hat
dbosanac@redhat.com
Twitter: @dejanb
Blog: http://sensatic.net
ActiveMQ in Action: http://www.manning.com/snyder/


On Fri, Jun 14, 2013 at 2:24 PM, mmg <ma...@gmail.com> wrote:

> Hi,
>
> Any idea what does the below message mean? Does this have any negative
> effect on communication between producers and consumers like loss of
> messages?
>
>
> DEBUG DemandForwardingBridge         - Ignoring sub ConsumerInfo {commandId
> = 179, responseRequired = false, consumerId =
> ID:avayaiq1cr.cam.wal-mart.com-46291-1369884580806-3:3:1:174, destination =
> queue://ReplyQueue, prefetchSize = 1000, maximumPendingMessageLimit = 0,
> browser = false, dispatchAsync = true, selector = null, subcriptionName =
> null, noLocal = false, exclusive = false, retroactive = false, priority =
> 0,
> brokerPath = [ID:avayaiqe1.ivr.wal-mart.com-47420-1369884669888-1:0],
> optimizedAcknowledge = false, noRangeAcks = false, additionalPredicate =
> org.apache.activemq.command.NetworkBridgeFilter@16fa21a4} already routed
> through this broker once
>
>
> Thanks.
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/DemandForwardingBridge-Ignoring-sub-ConsumerInf-tp4668211.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>