Hi all,
We have 2 amq servers, in a master-slave setup. Recently, I observed
this in the master's log file (see attached). Basically, there were
quite a few debug messages about stopping master bridge and "negociation
timeout". Later, followed by a out of memory exception.
The master server continued to run, even after the memory exception,
but reading messages from a specific topic, froze the consumer.
I had a durable subscription to a topic, but the subscriber had
disconnected for a while and the subscription had collected around
40,000 messages (at a guess). Here is my activemq.xml
--------
<memoryManager>
<usageManager id="memory-manager" limit="2048 MB"/>
</memoryManager>
<destinationPolicy>
<policyMap><policyEntries>
<policyEntry topic="wss.>">
<dispatchPolicy>
<strictOrderDispatchPolicy />
</dispatchPolicy>
<subscriptionRecoveryPolicy>
<lastImageSubscriptionRecoveryPolicy />
</subscriptionRecoveryPolicy>
<pendingMessageLimitStrategy>
<constantPendingMessageLimitStrategy limit="50000"/>
</pendingMessageLimitStrategy>
</policyEntry>
</policyEntries></policyMap>
</destinationPolicy>
-------------
with both "usageManager" and the "message limit strategy", I expected
activemq to drop old messages on a durable subscription, once the limit
was hit. In a separate test on one of the dev servers, I observed , via
the jmx console, on a durable subscription the messages were never
dropped, even after crossing the limit.
we are running ActiveMQ 4.1 (stable), with 64bit Java v1.5.0. Any help
is appreciated. Thanks.
- Sandeep
2007-01-17 01:00:18,501 [.24.37.58:37599] DEBUG TransportConnection
- Setting up new connection: [EMAIL PROTECTED]
2007-01-17 01:00:19,783 [.24.37.58:37600] DEBUG TransportConnection
- Setting up new connection: [EMAIL PROTECTED]
.....
2007-01-17 01:01:32,886 [ource.com:61613] WARN ManagedTransportConnection
- Failed to register MBean:
org.apache.activemq:BrokerName=master,Type=Connection,ConnectorName=stomp,ViewType=address,Name=/172.24.37.58_37699
2007-01-17 01:01:32,886 [ource.com:61613] DEBUG ManagedTransportConnection
- Failure reason: javax.management.InstanceAlreadyExistsException:
org.apache.activemq:BrokerName=master,Type=Connection,ConnectorName=stomp,ViewType=address,Name=/i.p.address_37699
javax.management.InstanceAlreadyExistsException:
org.apache.activemq:BrokerName=master,Type=Connection,ConnectorName=stomp,ViewType=address,Name=/i.p.address_37699
at
com.sun.jmx.mbeanserver.RepositorySupport.addMBean(RepositorySupport.java:452)
at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.internal_addObject(DefaultMBeanServerInterceptor.java:1410)
at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:936)
at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:337)
at
com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:497)
at
org.apache.activemq.broker.jmx.ManagedTransportConnection.registerMBean(ManagedTransportConnection.java:102)
at
org.apache.activemq.broker.jmx.ManagedTransportConnection.<init>(ManagedTransportConnection.java:60)
at
org.apache.activemq.broker.jmx.ManagedTransportConnector.createConnection(ManagedTransportConnector.java:56)
at
org.apache.activemq.broker.TransportConnector$1.onAccept(TransportConnector.java:147)
at
org.apache.activemq.transport.tcp.TcpTransportServer.run(TcpTransportServer.java:167)
at java.lang.Thread.run(Thread.java:595)
....
2007-01-17 01:11:14,246 [.24.37.55:55440] DEBUG TransportConnection
- Stopping connection: /172.24.37.55:55440
2007-01-17 01:11:18,340 [.24.37.55:55443] DEBUG WireFormatNegotiator
- tcp:///172.24.37.55:55443 after negotiation: OpenWireFormat{version=2,
cacheEnabled=true, stackTraceEnabled=true, tightEncodingEnabled=true,
sizePrefixDisabled=false}
2007-01-17 01:11:18,341 [.24.37.55:55443] DEBUG TransportConnection
- Setting up new connection: [EMAIL PROTECTED]
2007-01-17 01:11:18,341 [.24.37.55:55443] DEBUG Service
- Async error occurred: javax.jms.InvalidClientIDException: Broker: master -
Client: NC_slave_outboundslave already connected
javax.jms.InvalidClientIDException: Broker: master - Client:
NC_slave_outboundslave already connected
at
org.apache.activemq.broker.region.RegionBroker.addConnection(RegionBroker.java:205)
at
org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:82)
at
org.apache.activemq.advisory.AdvisoryBroker.addConnection(AdvisoryBroker.java:70)
at
org.apache.activemq.broker.BrokerFilter.addConnection(BrokerFilter.java:82)
at
org.apache.activemq.broker.MutableBrokerFilter.addConnection(MutableBrokerFilter.java:92)
at
org.apache.activemq.broker.TransportConnection.processAddConnection(TransportConnection.java:687)
at
org.apache.activemq.broker.jmx.ManagedTransportConnection.processAddConnection(ManagedTransportConnection.java:86)
at
org.apache.activemq.command.ConnectionInfo.visit(ConnectionInfo.java:121)
at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:284)
at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:177)
at
org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:65)
at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:133)
at
org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:122)
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:137)
at java.lang.Thread.run(Thread.java:595
.....
2007-01-17 01:11:24,528 [.24.37.58:38309] DEBUG TransportConnection
- Setting up new connection: [EMAIL PROTECTED]
2007-01-17 01:11:24,529 [ource.com:61616] DEBUG WireFormatNegotiator
- Sending: WireFormatInfo { version=2, properties={TightEncodingEnabled=true,
CacheSize=1024, TcpNoDelayEnabled=true, SizePrefixDisabled=false,
StackTraceEnabled=true, MaxInactivityDuration=30000, CacheEnabled=true},
magic=[A,c,t,i,v,e,M,Q]}
2007-01-17 01:11:26,438 [ception Handler] DEBUG Transport
- Transport failed: java.net.SocketException: Broken pipe
java.net.SocketException: Broken pipe
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
at
org.apache.activemq.transport.tcp.TcpBufferedOutputStream.flush(TcpBufferedOutputStream.java:109)
at java.io.DataOutputStream.flush(DataOutputStream.java:106)
at
org.apache.activemq.transport.tcp.TcpTransport.oneway(TcpTransport.java:119)
at
org.apache.activemq.transport.InactivityMonitor.oneway(InactivityMonitor.java:141)
at
org.apache.activemq.transport.TransportFilter.oneway(TransportFilter.java:80)
at
org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:93)
at
org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:43)
at
org.apache.activemq.broker.TransportConnection.dispatch(TransportConnection.java:1051)
at
org.apache.activemq.broker.TransportConnection.processDispatch(TransportConnection.java:779)
at
org.apache.activemq.broker.TransportConnection.iterate(TransportConnection.java:788)
at
org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:88)
at
org.apache.activemq.thread.DedicatedTaskRunner.access$000(DedicatedTaskRunner.java:25)
at
org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:39)
.....
2007-01-17 01:12:39,857 [ Agent Notifier] INFO NetworkConnector
- Establishing network connection between from vm://master?network=true to
tcp://slave:61616
2007-01-17 01:12:41,791 [.24.37.55:55452] DEBUG Transport
- Transport failed: java.io.EOFException
java.io.EOFException
at java.io.DataInputStream.readInt(DataInputStream.java:358)
at
org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:267)
at
org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:156)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:136)
at java.lang.Thread.run(Thread.java:595)
2007-01-17 01:12:43,720 [ception Handler] DEBUG Transport
- Transport failed: java.net.SocketException: Socket closed
java.net.SocketException: Socket closed
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:99)
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
at
org.apache.activemq.transport.tcp.TcpBufferedOutputStream.flush(TcpBufferedOutputStream.java:109)
at java.io.DataOutputStream.flush(DataOutputStream.java:106)
at
org.apache.activemq.transport.tcp.TcpTransport.oneway(TcpTransport.java:119)
at
org.apache.activemq.transport.InactivityMonitor.oneway(InactivityMonitor.java:141)
at
org.apache.activemq.transport.TransportFilter.oneway(TransportFilter.java:80)
at
org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:93)
at
org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:43)
at
org.apache.activemq.broker.TransportConnection.dispatch(TransportConnection.java:1051)
at
org.apache.activemq.broker.TransportConnection.processDispatch(TransportConnection.java:779)
at
org.apache.activemq.broker.TransportConnection.start(TransportConnection.java:818)
at
org.apache.activemq.broker.TransportConnector$1.onAccept(TransportConnector.java:148)
at
org.apache.activemq.transport.tcp.TcpTransportServer.run(TcpTransportServer.java:167)
at java.lang.Thread.run(Thread.java:595)
....
2007-01-17 01:18:03,157 [ Agent Notifier] INFO TransportConnector
- Connector vm://master Started
2007-01-17 01:21:38,112 [ Agent Notifier] DEBUG DemandForwardingBridge
- stopping master bridge to Unknown is disposed already ? false
2007-01-17 01:22:12,921 [ Agent Notifier] DEBUG TransportConnection
- Stopping connection: vm://master#14
2007-01-17 01:22:49,518 [ Agent Notifier] DEBUG TransportConnection
- Stopped connection: vm://master#14
2007-01-17 01:23:32,721 [ Agent Notifier] DEBUG DemandForwardingBridge
- Caught exception stopping
java.io.IOException: Wire format negociation timeout: peer did not send his
wire format.
at
org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:88)
at
org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:43)
at
org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
at
org.apache.activemq.network.DemandForwardingBridgeSupport.stop(DemandForwardingBridgeSupport.java:302)
at
org.apache.activemq.util.ServiceSupport.dispose(ServiceSupport.java:40)
at
org.apache.activemq.network.DiscoveryNetworkConnector.onServiceRemove(DiscoveryNetworkConnector.java:155)
at
org.apache.activemq.transport.discovery.multicast.MulticastDiscoveryAgent$3.run(MulticastDiscoveryAgent.java:371)
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(Thread.java:595)
....
2007-01-17 01:36:43,038 [eckpoint Worker] ERROR JournalPersistenceAdapter
- Failed to checkpoint a message store:
edu.emory.mathcs.backport.java.util.concurrent.ExecutionException:
java.lang.OutOfMemoryError: Java heap space
edu.emory.mathcs.backport.java.util.concurrent.ExecutionException:
java.lang.OutOfMemoryError: Java heap space
at
edu.emory.mathcs.backport.java.util.concurrent.FutureTask.getResult(FutureTask.java:299)
at
edu.emory.mathcs.backport.java.util.concurrent.FutureTask.get(FutureTask.java:118)
at
org.apache.activemq.store.journal.JournalPersistenceAdapter.doCheckpoint(JournalPersistenceAdapter.java:386)
at
org.apache.activemq.store.journal.JournalPersistenceAdapter$2.iterate(JournalPersistenceAdapter.java:129)
at
org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:88)
at
org.apache.activemq.thread.DedicatedTaskRunner.access$000(DedicatedTaskRunner.java:25)
at
org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:39)
Caused by: java.lang.OutOfMemoryError: Java heap space
