You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by Suneel Papineni <Su...@mettoni.com> on 2011/03/03 14:21:33 UTC
Issues with Network of Brokers, when using multicasr:default
Hi,
I am running ActiveMQ on two systems (using default
activemq-dynamic-network-broker.xml config file). Each one is connected
with one application (which is acting both as a publisher and durable
subscriber) present in that system. A topic "SimpleTopic" is defined and
messages are exchanged properly across the systems.
I am facing problem whenever there is network disconnection or when
Ethernet cable is pulled out from one of the systems (here pulled out
from broker 1).
When there is disconnection, both brokers notified that other ActiveMQ
is disconnected. During this time I sent some messages from
applications. Now I tried to reconnect the cable, once it is connected
both ActiveMQ's got updated message that other broker is reconnected.
Same time, all the messages which were sent should be received by the
applications, but this is not happening. Also the messages sent after
reconnection also didn't appear at other party.
When I checked the logs, I could see a failure message as "Transport
failed: java.net.SocketException: Software caused connection abort: recv
failed". Please find attached logs of each broker.
Could you please help me in resolving this and let me know if there is
any issue or is there anything I am missing.
I tried this with ActiveMQ 5.4.2 and also with 5.5 Snapshot, same issue
appears.
Thanks & Regards
Suneel
*************************************************************************
Please consider the environment before printing this e-mail
*************************************************************************
This email and any files transmitted with it are confidential and
intended solely for the use of the individual or entity to whom they
are addressed. If you have received this email in error please notify
the system manager. http://www.mettoni.com
Mettoni Ltd
Registered in England and Wales: 4485956
Ashfords House, Grenadier Road, Exeter, EX1 3LH
*************************************************************************
RE: Issues with Network of Brokers, when using multicasr:default
Posted by Suneel Papineni <Su...@mettoni.com>.
Hi,
Seems logs didn't get attached....
Log of Broker 1:
2011-03-03 12:04:02,061 | DEBUG | stopping dynamic-broker1 bridge to
dynamic-broker2 |
org.apache.activemq.network.DemandForwardingBridgeSupport |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker1]
2011-03-03 12:04:02,063 | DEBUG | Stopping connection:
vm://dynamic-broker1#0 | org.apache.activemq.broker.TransportConnection
| StopAsync:vm://dynamic-broker1#0
2011-03-03 12:04:02,063 | DEBUG | Stopped transport:
vm://dynamic-broker1#0 | org.apache.activemq.broker.TransportConnection
| StopAsync:vm://dynamic-broker1#0
2011-03-03 12:04:02,064 | DEBUG | Cleaning up connection resources:
vm://dynamic-broker1#0 | org.apache.activemq.broker.TransportConnection
| StopAsync:vm://dynamic-broker1#0
2011-03-03 12:04:02,064 | DEBUG | remove connection id:
ID:SuneelP-M6500-57483-1299153760173-2:2 |
org.apache.activemq.broker.TransportConnection |
StopAsync:vm://dynamic-broker1#0
2011-03-03 12:04:02,064 | DEBUG | Stopping transport
tcp://QABaseXPsql/172.22.241.68:61618 |
org.apache.activemq.transport.tcp.TcpTransport |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker1]
2011-03-03 12:04:02,065 | DEBUG | Deactivating
DurableTopicSubscription-NC_dynamic-broker2_inbound_dynamic-broker1:NC-D
S_dynamic-broker1_SimpleTopic,
id=ID:SuneelP-M6500-57483-1299153760173-2:2:1:2, destinations=1,
total=2, pending=0, dispatched=2, inflight=0, prefetchExtension=0 |
org.apache.activemq.broker.region.DurableTopicSubscription |
StopAsync:vm://dynamic-broker1#0
2011-03-03 12:04:02,066 | DEBUG | Connection Stopped:
vm://dynamic-broker1#0 | org.apache.activemq.broker.TransportConnection
| StopAsync:vm://dynamic-broker1#0
2011-03-03 12:04:02,067 | DEBUG | Shutting down VM connectors for
broker: dynamic-broker1 |
org.apache.activemq.transport.vm.VMTransportFactory |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker1]
2011-03-03 12:04:02,067 | INFO | Connector vm://dynamic-broker1 Stopped
| org.apache.activemq.broker.TransportConnector |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker1]
2011-03-03 12:04:02,068 | DEBUG | dynamic-broker1
removeBroker:dynamic-broker2 brokerInfo size : 0 |
org.apache.activemq.broker.region.RegionBroker |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker1]
2011-03-03 12:04:02,069 | INFO | dynamic-broker1 bridge to
dynamic-broker2 stopped |
org.apache.activemq.network.DemandForwardingBridgeSupport |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker1]
2011-03-03 12:04:05,431 | DEBUG | Checkpoint started. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:05,446 | DEBUG | Checkpoint done. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:06,108 | DEBUG | 30000 ms elapsed since last read
check. | org.apache.activemq.transport.InactivityMonitor |
InactivityMonitor ReadCheck
2011-03-03 12:04:06,108 | DEBUG | 10000 ms elapsed since last write
check. | org.apache.activemq.transport.InactivityMonitor |
InactivityMonitor WriteCheck
2011-03-03 12:04:10,446 | DEBUG | Checkpoint started. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:10,498 | DEBUG | Checkpoint done. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:11,593 | DEBUG | 10000 ms elapsed since last write
check. | org.apache.activemq.transport.InactivityMonitor |
InactivityMonitor WriteCheck
2011-03-03 12:04:15,499 | DEBUG | Checkpoint started. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:15,520 | DEBUG | Checkpoint done. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:16,108 | DEBUG | 10000 ms elapsed since last write
check. | org.apache.activemq.transport.InactivityMonitor |
InactivityMonitor WriteCheck
2011-03-03 12:04:20,521 | DEBUG | Checkpoint started. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:20,573 | DEBUG | Checkpoint done. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:21,593 | DEBUG | 10000 ms elapsed since last write
check. | org.apache.activemq.transport.InactivityMonitor |
InactivityMonitor WriteCheck
2011-03-03 12:04:22,378 | DEBUG | Transport failed:
java.net.SocketException: Software caused connection abort: recv failed
| org.apache.activemq.broker.TransportConnection.Transport | ActiveMQ
Transport: tcp:///172.22.241.68:4978
java.net.SocketException: Software caused connection abort: recv failed
at java.net.SocketInputStream.socketRead0(Native Method)
at
java.net.SocketInputStream.read(SocketInputStream.java:129)
at
org.apache.activemq.transport.tcp.TcpBufferedInputStream.fill(TcpBuffere
dInputStream.java:50)
at
org.apache.activemq.transport.tcp.TcpTransport$2.fill(TcpTransport.java:
578)
at
org.apache.activemq.transport.tcp.TcpBufferedInputStream.read(TcpBuffere
dInputStream.java:58)
at
org.apache.activemq.transport.tcp.TcpTransport$2.read(TcpTransport.java:
563)
at
java.io.DataInputStream.readInt(DataInputStream.java:370)
at
org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.jav
a:269)
at
org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.
java:229)
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:2
21)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:204
)
at java.lang.Thread.run(Thread.java:619)
2011-03-03 12:04:22,380 | DEBUG | Stopping connection:
/172.22.241.68:4978 | org.apache.activemq.broker.TransportConnection |
StopAsync:/172.22.241.68:4978
2011-03-03 12:04:22,381 | DEBUG | Stopping transport
tcp:///172.22.241.68:4978 |
org.apache.activemq.transport.tcp.TcpTransport |
StopAsync:/172.22.241.68:4978
2011-03-03 12:04:22,382 | DEBUG | Stopped transport: /172.22.241.68:4978
| org.apache.activemq.broker.TransportConnection |
StopAsync:/172.22.241.68:4978
2011-03-03 12:04:22,382 | DEBUG | Cleaning up connection resources:
/172.22.241.68:4978 | org.apache.activemq.broker.TransportConnection |
StopAsync:/172.22.241.68:4978
2011-03-03 12:04:22,382 | DEBUG | remove connection id:
ID:QABaseXPsql-4977-1299153802734-2:1 |
org.apache.activemq.broker.TransportConnection |
StopAsync:/172.22.241.68:4978
2011-03-03 12:04:22,383 | DEBUG | dynamic-broker1 removing consumer:
ID:QABaseXPsql-4977-1299153802734-2:1:1:1 for destination:
ActiveMQ.Advisory.Consumer.>,topic://ActiveMQ.Advisory.TempQueue,topic:/
/ActiveMQ.Advisory.TempTopic |
org.apache.activemq.broker.region.AbstractRegion |
StopAsync:/172.22.241.68:4978
2011-03-03 12:04:22,384 | DEBUG | Connection Stopped:
/172.22.241.68:4978 | org.apache.activemq.broker.TransportConnection |
StopAsync:/172.22.241.68:4978
2011-03-03 12:04:25,061 | INFO | Establishing network connection from
vm://dynamic-broker1?async=false&network=true to tcp://QABaseXPsql:61618
| org.apache.activemq.network.DiscoveryNetworkConnector |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker1]
2011-03-03 12:04:25,062 | DEBUG | binding to broker: dynamic-broker1 |
org.apache.activemq.transport.vm.VMTransportFactory |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker1]
2011-03-03 12:04:25,063 | INFO | Connector vm://dynamic-broker1 Started
| org.apache.activemq.broker.TransportConnector |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker1]
2011-03-03 12:04:25,071 | DEBUG | Sending: WireFormatInfo { version=6,
properties={CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} |
org.apache.activemq.transport.WireFormatNegotiator |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker1]
2011-03-03 12:04:25,074 | DEBUG | Received WireFormat: WireFormatInfo {
version=6, properties={CacheSize=1024, CacheEnabled=true,
SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000,
TcpNoDelayEnabled=true, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true},
magic=[A,c,t,i,v,e,M,Q]} |
org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport:
tcp://QABaseXPsql/172.22.241.68:61618
2011-03-03 12:04:25,074 | DEBUG | tcp://QABaseXPsql/172.22.241.68:61618
before negotiation: OpenWireFormat{version=6, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false} |
org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport:
tcp://QABaseXPsql/172.22.241.68:61618
2011-03-03 12:04:25,074 | DEBUG | tcp://QABaseXPsql/172.22.241.68:61618
after negotiation: OpenWireFormat{version=6, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true,
sizePrefixDisabled=false} |
org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport:
tcp://QABaseXPsql/172.22.241.68:61618
2011-03-03 12:04:25,122 | DEBUG | dynamic-broker1
addBroker:dynamic-broker2 brokerInfo size : 1 |
org.apache.activemq.broker.region.RegionBroker | ActiveMQ Transport:
tcp://QABaseXPsql/172.22.241.68:61618
2011-03-03 12:04:25,129 | DEBUG | Setting up new connection id:
ID:SuneelP-M6500-57483-1299153760173-3:2, address:
vm://dynamic-broker1#2 | org.apache.activemq.broker.TransportConnection
| StartLocalBridge: localBroker=vm://dynamic-broker1#2
2011-03-03 12:04:25,131 | INFO | Network connection between
vm://dynamic-broker1#2 and
tcp://QABaseXPsql/172.22.241.68:61618(dynamic-broker2) has been
established. | org.apache.activemq.network.DemandForwardingBridgeSupport
| StartLocalBridge: localBroker=vm://dynamic-broker1#2
2011-03-03 12:04:25,136 | DEBUG | dynamic-broker1 using priority :-5 for
subscription: ConsumerInfo {commandId = 4, responseRequired = true,
consumerId = ID:SuneelP-M6500-57483-1299153760173-3:2:1:1, destination =
topic://SimpleTopic, prefetchSize = 1, maximumPendingMessageLimit = 0,
browser = false, dispatchAsync = true, selector = null, subscriptionName
= NC-DS_dynamic-broker1_SimpleTopic, noLocal = false, exclusive = false,
retroactive = false, priority = 0, brokerPath =
[ID:QABaseXPsql-4977-1299153802734-0:1], optimizedAcknowledge = false,
noRangeAcks = false, additionalPredicate = null} |
org.apache.activemq.network.DemandForwardingBridgeSupport | ActiveMQ
Transport: tcp://QABaseXPsql/172.22.241.68:61618
2011-03-03 12:04:25,136 | DEBUG | dynamic-broker1 Ignoring duplicate
subscription from dynamic-broker2, sub: ConsumerInfo {commandId = 4,
responseRequired = true, consumerId =
ID:SuneelP-M6500-57483-1299153760173-3:2:1:2, destination =
topic://SimpleTopic, prefetchSize = 1, maximumPendingMessageLimit = 0,
browser = false, dispatchAsync = true, selector = null, subscriptionName
= NC-DS_dynamic-broker1_SimpleTopic, noLocal = false, exclusive = false,
retroactive = false, priority = -5, brokerPath =
[ID:QABaseXPsql-4977-1299153802734-0:1], optimizedAcknowledge = false,
noRangeAcks = false, additionalPredicate = null} is duplicated by
network subscription with equal or higher network priority: ConsumerInfo
{commandId = 4, responseRequired = false, consumerId =
ID:SuneelP-M6500-57483-1299153760173-2:2:1:2, destination =
topic://SimpleTopic, prefetchSize = 1, maximumPendingMessageLimit = 0,
browser = false, dispatchAsync = true, selector = null, subscriptionName
= NC-DS_dynamic-broker1_SimpleTopic, noLocal = false, exclusive = false,
retroactive = false, priority = -5, brokerPath =
[ID:QABaseXPsql-4977-1299153802734-0:1], optimizedAcknowledge = false,
noRangeAcks = false, additionalPredicate = null}, networkComsumerIds:
[ID:QABaseXPsql-1034-634347506287500000-0:0:1:1] |
org.apache.activemq.network.DemandForwardingBridgeSupport | ActiveMQ
Transport: tcp://QABaseXPsql/172.22.241.68:61618
2011-03-03 12:04:25,137 | DEBUG | dynamic-broker1 Ignoring sub from
dynamic-broker2 as already subscribed to matching destination :
ConsumerInfo {commandId = 4, responseRequired = true, consumerId =
ID:QABaseXPsql-1034-634347506287500000-0:0:1:1, destination =
topic://SimpleTopic, prefetchSize = 1, maximumPendingMessageLimit = 0,
browser = false, dispatchAsync = true, selector = CID NOT LIKE '234' AND
Durability LIKE '1', subscriptionName = 234, noLocal = false, exclusive
= false, retroactive = false, priority = 0, brokerPath = null,
optimizedAcknowledge = false, noRangeAcks = false, additionalPredicate =
null} | org.apache.activemq.network.DemandForwardingBridgeSupport |
ActiveMQ Transport: tcp://QABaseXPsql/172.22.241.68:61618
2011-03-03 12:04:25,574 | DEBUG | Checkpoint started. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:25,593 | DEBUG | Checkpoint done. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:26,108 | DEBUG | 10000 ms elapsed since last write
check. | org.apache.activemq.transport.InactivityMonitor |
InactivityMonitor WriteCheck
2011-03-03 12:04:30,594 | DEBUG | Checkpoint started. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:30,615 | DEBUG | Checkpoint done. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:34,064 | DEBUG | Sending: WireFormatInfo { version=6,
properties={CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} |
org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Task
2011-03-03 12:04:34,066 | DEBUG | Received WireFormat: WireFormatInfo {
version=6, properties={CacheSize=1024, CacheEnabled=true,
SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000,
TcpNoDelayEnabled=true, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true},
magic=[A,c,t,i,v,e,M,Q]} |
org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport:
tcp:///172.22.241.68:1086
2011-03-03 12:04:34,066 | DEBUG | tcp:///172.22.241.68:1086 before
negotiation: OpenWireFormat{version=6, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false} |
org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport:
tcp:///172.22.241.68:1086
2011-03-03 12:04:34,067 | DEBUG | tcp:///172.22.241.68:1086 after
negotiation: OpenWireFormat{version=6, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true,
sizePrefixDisabled=false} |
org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport:
tcp:///172.22.241.68:1086
2011-03-03 12:04:34,102 | DEBUG | Setting up new connection id:
ID:QABaseXPsql-4977-1299153802734-3:1, address: /172.22.241.68:1086 |
org.apache.activemq.broker.TransportConnection | ActiveMQ Transport:
tcp:///172.22.241.68:1086
2011-03-03 12:04:34,104 | DEBUG | dynamic-broker1 adding consumer:
ID:QABaseXPsql-4977-1299153802734-3:1:1:1 for destination:
ActiveMQ.Advisory.Consumer.>,topic://ActiveMQ.Advisory.TempQueue,topic:/
/ActiveMQ.Advisory.TempTopic |
org.apache.activemq.broker.region.AbstractRegion | ActiveMQ Transport:
tcp:///172.22.241.68:1086
2011-03-03 12:04:35,616 | DEBUG | Checkpoint started. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:35,631 | DEBUG | Checkpoint done. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
Logs of Broker 2:
2011-03-03 12:04:34,515 | DEBUG | stopping dynamic-broker2 bridge to
dynamic-broker1 |
org.apache.activemq.network.DemandForwardingBridgeSupport |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker2]
2011-03-03 12:04:34,515 | DEBUG | Stopping connection:
vm://dynamic-broker2#0 | org.apache.activemq.broker.TransportConnection
| StopAsync:vm://dynamic-broker2#0
2011-03-03 12:04:34,515 | DEBUG | Stopped transport:
vm://dynamic-broker2#0 | org.apache.activemq.broker.TransportConnection
| StopAsync:vm://dynamic-broker2#0
2011-03-03 12:04:34,515 | DEBUG | Cleaning up connection resources:
vm://dynamic-broker2#0 | org.apache.activemq.broker.TransportConnection
| StopAsync:vm://dynamic-broker2#0
2011-03-03 12:04:34,515 | DEBUG | remove connection id:
ID:QABaseXPsql-4977-1299153802734-2:2 |
org.apache.activemq.broker.TransportConnection |
StopAsync:vm://dynamic-broker2#0
2011-03-03 12:04:34,515 | DEBUG | Stopping transport
tcp://SuneelP-M6500/172.22.240.6:61616 |
org.apache.activemq.transport.tcp.TcpTransport |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker2]
2011-03-03 12:04:34,515 | DEBUG | Deactivating
DurableTopicSubscription-NC_dynamic-broker1_inbound_dynamic-broker2:NC-D
S_dynamic-broker2_SimpleTopic,
id=ID:QABaseXPsql-4977-1299153802734-2:2:1:2, destinations=1, total=2,
pending=0, dispatched=2, inflight=0, prefetchExtension=0 |
org.apache.activemq.broker.region.DurableTopicSubscription |
StopAsync:vm://dynamic-broker2#0
2011-03-03 12:04:34,515 | DEBUG | Connection Stopped:
vm://dynamic-broker2#0 | org.apache.activemq.broker.TransportConnection
| StopAsync:vm://dynamic-broker2#0
2011-03-03 12:04:34,515 | DEBUG | Shutting down VM connectors for
broker: dynamic-broker2 |
org.apache.activemq.transport.vm.VMTransportFactory |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker2]
2011-03-03 12:04:34,515 | INFO | Connector vm://dynamic-broker2 Stopped
| org.apache.activemq.broker.TransportConnector |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker2]
2011-03-03 12:04:34,515 | DEBUG | dynamic-broker2
removeBroker:dynamic-broker1 brokerInfo size : 0 |
org.apache.activemq.broker.region.RegionBroker |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker2]
2011-03-03 12:04:34,515 | INFO | dynamic-broker2 bridge to
dynamic-broker1 stopped |
org.apache.activemq.network.DemandForwardingBridgeSupport |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker2]
2011-03-03 12:04:37,859 | DEBUG | Checkpoint started. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:37,859 | DEBUG | Checkpoint done. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:38,968 | DEBUG | 10000 ms elapsed since last write
check. | org.apache.activemq.transport.InactivityMonitor |
InactivityMonitor WriteCheck
2011-03-03 12:04:42,859 | DEBUG | Checkpoint started. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:42,875 | DEBUG | Checkpoint done. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:43,343 | DEBUG | 10000 ms elapsed since last write
check. | org.apache.activemq.transport.InactivityMonitor |
InactivityMonitor WriteCheck
2011-03-03 12:04:47,875 | DEBUG | Checkpoint started. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:47,875 | DEBUG | Checkpoint done. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:48,968 | DEBUG | 30000 ms elapsed since last read
check. | org.apache.activemq.transport.InactivityMonitor |
InactivityMonitor ReadCheck
2011-03-03 12:04:48,968 | DEBUG | 10000 ms elapsed since last write
check. | org.apache.activemq.transport.InactivityMonitor |
InactivityMonitor WriteCheck
2011-03-03 12:04:52,875 | DEBUG | Checkpoint started. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:52,875 | DEBUG | Checkpoint done. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:53,343 | DEBUG | 10000 ms elapsed since last write
check. | org.apache.activemq.transport.InactivityMonitor |
InactivityMonitor WriteCheck
2011-03-03 12:04:57,015 | INFO | Establishing network connection from
vm://dynamic-broker2?async=false&network=true to
tcp://SuneelP-M6500:61616 |
org.apache.activemq.network.DiscoveryNetworkConnector |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker2]
2011-03-03 12:04:57,015 | DEBUG | binding to broker: dynamic-broker2 |
org.apache.activemq.transport.vm.VMTransportFactory |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker2]
2011-03-03 12:04:57,015 | INFO | Connector vm://dynamic-broker2 Started
| org.apache.activemq.broker.TransportConnector |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker2]
2011-03-03 12:04:57,015 | DEBUG | Sending: WireFormatInfo { version=6,
properties={CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} |
org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Task
2011-03-03 12:04:57,015 | DEBUG | Received WireFormat: WireFormatInfo {
version=6, properties={CacheSize=1024, CacheEnabled=true,
SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000,
TcpNoDelayEnabled=true, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true},
magic=[A,c,t,i,v,e,M,Q]} |
org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport:
tcp:///172.22.240.6:57498
2011-03-03 12:04:57,015 | DEBUG | tcp:///172.22.240.6:57498 before
negotiation: OpenWireFormat{version=6, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false} |
org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport:
tcp:///172.22.240.6:57498
2011-03-03 12:04:57,015 | DEBUG | tcp:///172.22.240.6:57498 after
negotiation: OpenWireFormat{version=6, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true,
sizePrefixDisabled=false} |
org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport:
tcp:///172.22.240.6:57498
2011-03-03 12:04:57,078 | DEBUG | Setting up new connection id:
ID:SuneelP-M6500-57483-1299153760173-3:1, address: /172.22.240.6:57498 |
org.apache.activemq.broker.TransportConnection | ActiveMQ Transport:
tcp:///172.22.240.6:57498
2011-03-03 12:04:57,078 | WARN | Failed to register MBean:
org.apache.activemq:BrokerName=dynamic-broker2,Type=Connection,Connector
Name=openwire,Connection=NC_dynamic-broker1_outbound |
org.apache.activemq.broker.jmx.ManagedTransportConnection | ActiveMQ
Transport: tcp:///172.22.240.6:57498
2011-03-03 12:04:57,078 | DEBUG | Failure reason:
javax.management.InstanceAlreadyExistsException:
org.apache.activemq:BrokerName=dynamic-broker2,Type=Connection,Connector
Name=openwire,Connection=NC_dynamic-broker1_outbound |
org.apache.activemq.broker.jmx.ManagedTransportConnection | ActiveMQ
Transport: tcp:///172.22.240.6:57498
javax.management.InstanceAlreadyExistsException:
org.apache.activemq:BrokerName=dynamic-broker2,Type=Connection,Connector
Name=openwire,Connection=NC_dynamic-broker1_outbound
at
com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:453)
at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.internal_addObject
(DefaultMBeanServerInterceptor.java:1484)
at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBe
an(DefaultMBeanServerInterceptor.java:963)
at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(Def
aultMBeanServerInterceptor.java:917)
at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(Defa
ultMBeanServerInterceptor.java:312)
at
com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java
:482)
at
org.apache.activemq.broker.jmx.ManagementContext.registerMBean(Managemen
tContext.java:299)
at
org.apache.activemq.broker.jmx.AnnotatedMBean.registerMBean(AnnotatedMBe
an.java:65)
at
org.apache.activemq.broker.jmx.ManagedTransportConnection.registerMBean(
ManagedTransportConnection.java:99)
at
org.apache.activemq.broker.jmx.ManagedTransportConnection.processAddConn
ection(ManagedTransportConnection.java:88)
at
org.apache.activemq.command.ConnectionInfo.visit(ConnectionInfo.java:137
)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnecti
on.java:310)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConn
ection.java:184)
at
org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.
java:69)
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatN
egotiator.java:113)
at
org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMoni
tor.java:227)
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSuppor
t.java:83)
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:2
22)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:204
)
at java.lang.Thread.run(Thread.java:619)
2011-03-03 12:04:57,078 | DEBUG | dynamic-broker2 adding consumer:
ID:SuneelP-M6500-57483-1299153760173-3:1:1:1 for destination:
ActiveMQ.Advisory.Consumer.>,topic://ActiveMQ.Advisory.TempQueue,topic:/
/ActiveMQ.Advisory.TempTopic |
org.apache.activemq.broker.region.AbstractRegion | ActiveMQ Transport:
tcp:///172.22.240.6:57498
2011-03-03 12:04:57,875 | DEBUG | Checkpoint started. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:57,875 | DEBUG | Checkpoint done. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:04:58,968 | DEBUG | 10000 ms elapsed since last write
check. | org.apache.activemq.transport.InactivityMonitor |
InactivityMonitor WriteCheck
2011-03-03 12:05:02,875 | DEBUG | Checkpoint started. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:05:02,875 | DEBUG | Checkpoint done. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:05:03,343 | DEBUG | 30000 ms elapsed since last read
check. | org.apache.activemq.transport.InactivityMonitor |
InactivityMonitor ReadCheck
2011-03-03 12:05:03,343 | DEBUG | 10000 ms elapsed since last write
check. | org.apache.activemq.transport.InactivityMonitor |
InactivityMonitor WriteCheck
2011-03-03 12:05:06,015 | DEBUG | Sending: WireFormatInfo { version=6,
properties={CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} |
org.apache.activemq.transport.WireFormatNegotiator |
Notifier-MulticastDiscoveryAgent-listener:DiscoveryNetworkConnector:NC:B
rokerService[dynamic-broker2]
2011-03-03 12:05:06,015 | DEBUG | Received WireFormat: WireFormatInfo {
version=6, properties={CacheSize=1024, CacheEnabled=true,
SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000,
TcpNoDelayEnabled=true, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true},
magic=[A,c,t,i,v,e,M,Q]} |
org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport:
tcp://SuneelP-M6500/172.22.240.6:61616
2011-03-03 12:05:06,015 | DEBUG | tcp://SuneelP-M6500/172.22.240.6:61616
before negotiation: OpenWireFormat{version=6, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false} |
org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport:
tcp://SuneelP-M6500/172.22.240.6:61616
2011-03-03 12:05:06,015 | DEBUG | tcp://SuneelP-M6500/172.22.240.6:61616
after negotiation: OpenWireFormat{version=6, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true,
sizePrefixDisabled=false} |
org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport:
tcp://SuneelP-M6500/172.22.240.6:61616
2011-03-03 12:05:06,046 | DEBUG | dynamic-broker2
addBroker:dynamic-broker1 brokerInfo size : 1 |
org.apache.activemq.broker.region.RegionBroker | ActiveMQ Transport:
tcp://SuneelP-M6500/172.22.240.6:61616
2011-03-03 12:05:06,046 | DEBUG | Setting up new connection id:
ID:QABaseXPsql-4977-1299153802734-3:2, address: vm://dynamic-broker2#2 |
org.apache.activemq.broker.TransportConnection | StartLocalBridge:
localBroker=vm://dynamic-broker2#2
2011-03-03 12:05:06,046 | INFO | Network connection between
vm://dynamic-broker2#2 and
tcp://SuneelP-M6500/172.22.240.6:61616(dynamic-broker1) has been
established. | org.apache.activemq.network.DemandForwardingBridgeSupport
| StartLocalBridge: localBroker=vm://dynamic-broker2#2
2011-03-03 12:05:06,062 | DEBUG | dynamic-broker2 using priority :-5 for
subscription: ConsumerInfo {commandId = 4, responseRequired = true,
consumerId = ID:QABaseXPsql-4977-1299153802734-3:2:1:1, destination =
topic://SimpleTopic, prefetchSize = 1, maximumPendingMessageLimit = 0,
browser = false, dispatchAsync = true, selector = null, subscriptionName
= NC-DS_dynamic-broker2_SimpleTopic, noLocal = false, exclusive = false,
retroactive = false, priority = 0, brokerPath =
[ID:SuneelP-M6500-57483-1299153760173-0:1], optimizedAcknowledge =
false, noRangeAcks = false, additionalPredicate = null} |
org.apache.activemq.network.DemandForwardingBridgeSupport | ActiveMQ
Transport: tcp://SuneelP-M6500/172.22.240.6:61616
2011-03-03 12:05:06,062 | DEBUG | dynamic-broker2 Ignoring duplicate
subscription from dynamic-broker1, sub: ConsumerInfo {commandId = 4,
responseRequired = true, consumerId =
ID:QABaseXPsql-4977-1299153802734-3:2:1:2, destination =
topic://SimpleTopic, prefetchSize = 1, maximumPendingMessageLimit = 0,
browser = false, dispatchAsync = true, selector = null, subscriptionName
= NC-DS_dynamic-broker2_SimpleTopic, noLocal = false, exclusive = false,
retroactive = false, priority = -5, brokerPath =
[ID:SuneelP-M6500-57483-1299153760173-0:1], optimizedAcknowledge =
false, noRangeAcks = false, additionalPredicate = null} is duplicated by
network subscription with equal or higher network priority: ConsumerInfo
{commandId = 4, responseRequired = false, consumerId =
ID:QABaseXPsql-4977-1299153802734-2:2:1:2, destination =
topic://SimpleTopic, prefetchSize = 1, maximumPendingMessageLimit = 0,
browser = false, dispatchAsync = true, selector = null, subscriptionName
= NC-DS_dynamic-broker2_SimpleTopic, noLocal = false, exclusive = false,
retroactive = false, priority = -5, brokerPath =
[ID:SuneelP-M6500-57483-1299153760173-0:1], optimizedAcknowledge =
false, noRangeAcks = false, additionalPredicate = null},
networkComsumerIds: [ID:SuneelP-M6500-57486-634347505859532286-1:0:1:1]
| org.apache.activemq.network.DemandForwardingBridgeSupport | ActiveMQ
Transport: tcp://SuneelP-M6500/172.22.240.6:61616
2011-03-03 12:05:06,062 | DEBUG | dynamic-broker2 Ignoring sub from
dynamic-broker1 as already subscribed to matching destination :
ConsumerInfo {commandId = 4, responseRequired = true, consumerId =
ID:SuneelP-M6500-57486-634347505859532286-1:0:1:1, destination =
topic://SimpleTopic, prefetchSize = 1, maximumPendingMessageLimit = 0,
browser = false, dispatchAsync = true, selector = CID NOT LIKE '123' AND
Durability LIKE '1', subscriptionName = 123, noLocal = false, exclusive
= false, retroactive = false, priority = 0, brokerPath = null,
optimizedAcknowledge = false, noRangeAcks = false, additionalPredicate =
null} | org.apache.activemq.network.DemandForwardingBridgeSupport |
ActiveMQ Transport: tcp://SuneelP-M6500/172.22.240.6:61616
2011-03-03 12:05:07,875 | DEBUG | Checkpoint started. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:05:07,875 | DEBUG | Checkpoint done. |
org.apache.activemq.store.kahadb.MessageDatabase | ActiveMQ Journal
Checkpoint Worker
2011-03-03 12:05:33,343 | DEBUG | No message received since last read
check for tcp:///172.22.240.6:57484! Throwing InactivityIOException. |
org.apache.activemq.transport.InactivityMonitor | InactivityMonitor
ReadCheck
2011-03-03 12:05:33,343 | DEBUG | Transport failed:
org.apache.activemq.transport.InactivityIOException: Channel was
inactive for too (>30000) long: /172.22.240.6:57484 |
org.apache.activemq.broker.TransportConnection.Transport |
InactivityMonitor Async Task:
java.util.concurrent.ThreadPoolExecutor$Worker@26f9e5
org.apache.activemq.transport.InactivityIOException: Channel was
inactive for too (>30000) long: /172.22.240.6:57484
at
org.apache.activemq.transport.InactivityMonitor$4.run(InactivityMonitor.
java:185)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecuto
r.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
va:908)
at java.lang.Thread.run(Thread.java:619)
2011-03-03 12:05:33,343 | DEBUG | Stopping connection:
/172.22.240.6:57484 | org.apache.activemq.broker.TransportConnection |
StopAsync:/172.22.240.6:57484
2011-03-03 12:05:33,343 | DEBUG | Stopping transport
tcp:///172.22.240.6:57484 |
org.apache.activemq.transport.tcp.TcpTransport |
StopAsync:/172.22.240.6:57484
2011-03-03 12:05:33,343 | DEBUG | Stopped transport: /172.22.240.6:57484
| org.apache.activemq.broker.TransportConnection |
StopAsync:/172.22.240.6:57484
2011-03-03 12:05:33,343 | DEBUG | Cleaning up connection resources:
/172.22.240.6:57484 | org.apache.activemq.broker.TransportConnection |
StopAsync:/172.22.240.6:57484
2011-03-03 12:05:33,343 | DEBUG | remove connection id:
ID:SuneelP-M6500-57483-1299153760173-2:1 |
org.apache.activemq.broker.TransportConnection |
StopAsync:/172.22.240.6:57484
2011-03-03 12:05:33,343 | DEBUG | dynamic-broker2 removing consumer:
ID:SuneelP-M6500-57483-1299153760173-2:1:1:1 for destination:
ActiveMQ.Advisory.Consumer.>,topic://ActiveMQ.Advisory.TempQueue,topic:/
/ActiveMQ.Advisory.TempTopic |
org.apache.activemq.broker.region.AbstractRegion |
StopAsync:/172.22.240.6:57484
2011-03-03 12:05:33,343 | DEBUG | Connection Stopped:
/172.22.240.6:57484 | org.apache.activemq.broker.TransportConnection |
StopAsync:/172.22.240.6:57484
Thanks & Regards
Suneel
From: Suneel Papineni [mailto:Suneel.Papineni@mettoni.com]
Sent: 03 March 2011 13:22
To: users@activemq.apache.org
Subject: Issues with Network of Brokers, when using multicasr:default
Hi,
I am running ActiveMQ on two systems (using default
activemq-dynamic-network-broker.xml config file). Each one is connected
with one application (which is acting both as a publisher and durable
subscriber) present in that system. A topic "SimpleTopic" is defined and
messages are exchanged properly across the systems.
I am facing problem whenever there is network disconnection or when
Ethernet cable is pulled out from one of the systems (here pulled out
from broker 1).
When there is disconnection, both brokers notified that other ActiveMQ
is disconnected. During this time I sent some messages from
applications. Now I tried to reconnect the cable, once it is connected
both ActiveMQ's got updated message that other broker is reconnected.
Same time, all the messages which were sent should be received by the
applications, but this is not happening. Also the messages sent after
reconnection also didn't appear at other party.
When I checked the logs, I could see a failure message as "Transport
failed: java.net.SocketException: Software caused connection abort: recv
failed". Please find attached logs of each broker.
Could you please help me in resolving this and let me know if there is
any issue or is there anything I am missing.
I tried this with ActiveMQ 5.4.2 and also with 5.5 Snapshot, same issue
appears.
Thanks & Regards
Suneel
************************************************************************
*
Please consider the environment before printing this e-mail
************************************************************************
*
This email and any files transmitted with it are confidential and
intended solely for the use of the individual or entity to whom they
are addressed. If you have received this email in error please notify
the system manager. http://www.mettoni.com
Mettoni Ltd
Registered in England and Wales: 4485956
Ashfords House, Grenadier Road, Exeter, EX1 3LH
************************************************************************
*
*************************************************************************
Please consider the environment before printing this e-mail
*************************************************************************
This email and any files transmitted with it are confidential and
intended solely for the use of the individual or entity to whom they
are addressed. If you have received this email in error please notify
the system manager. http://www.mettoni.com
Mettoni Ltd
Registered in England and Wales: 4485956
Ashfords House, Grenadier Road, Exeter, EX1 3LH
*************************************************************************