activemq-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Suneel Papineni" <Suneel.Papin...@mettoni.com>
Subject RE: Issues with Network of Brokers, when using multicasr:default
Date Thu, 03 Mar 2011 13:29:47 GMT
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
*************************************************************************


Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message