ActiveMQ hangs on SocketWrite0() with fast producer / slow consumer after
MemoryLimit is reached
------------------------------------------------------------------------------------------------
Key: AMQ-2389
URL: https://issues.apache.org/activemq/browse/AMQ-2389
Project: ActiveMQ
Issue Type: Bug
Affects Versions: 5.2.0
Environment: $ cat /proc/version
Linux version 2.6.18-6-amd64 (Debian 2.6.18.dfsg.1-23etch1) (da...@debian.org)
(gcc version 4.1.2 20061115 (prerelease) (Debian 4.1.1-21)) #1 SMP Fri Dec 12
05:49:32 UTC 2008
OS X
Reporter: Chad Showalter
Fix For: 5.2.0
When persistent=true for the broker, a fast producer / slow consumer may cause
ActiveMQ to block on a SocketWrite0() call. The following thread dump
signature results:
...
"ActiveMQ Transport: tcp://localhost/127.0.0.1:61610" prio=5
tid=0x0000000101942000 nid=0x1548c4000 waiting for monitor entry
[0x00000001548c3000..0x00000001548c3a50]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.activemq.transport.InactivityMonitor.oneway(InactivityMonitor.java:220)
- waiting to lock <0x0000000107d29848> (a
java.util.concurrent.atomic.AtomicBoolean)
at
org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:185)
at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:203)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:185)
at java.lang.Thread.run(Thread.java:637)
...
"main" prio=5 tid=0x0000000101805000 nid=0x101201000 runnable
[0x0000000101200000..0x0000000101200ba0]
java.lang.Thread.State: RUNNABLE
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:115)
at java.io.DataOutputStream.flush(DataOutputStream.java:106)
at
org.apache.activemq.transport.tcp.TcpTransport.oneway(TcpTransport.java:167)
at
org.apache.activemq.transport.InactivityMonitor.oneway(InactivityMonitor.java:233)
- locked <0x0000000107d29848> (a
java.util.concurrent.atomic.AtomicBoolean)
at
org.apache.activemq.transport.TransportFilter.oneway(TransportFilter.java:83)
at
org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:100)
at
org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:40)
- locked <0x0000000107d299b0> (a java.lang.Object)
at
org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
at
org.apache.activemq.ActiveMQConnection.doAsyncSendPacket(ActiveMQConnection.java:1214)
at
org.apache.activemq.ActiveMQConnection.asyncSendPacket(ActiveMQConnection.java:1208)
at org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1643)
- locked <0x0000000107d35a68> (a java.lang.Object)
at
org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:227)
at
org.apache.activemq.ActiveMQMessageProducerSupport.send(ActiveMQMessageProducerSupport.java:300)
at com.chad.test.ActiveMQSpamTest1.runTest(ActiveMQSpamTest1.java:73)
- locked <0x0000000107ca6680> (a
org.apache.activemq.ActiveMQMessageProducer)
at com.chad.test.ActiveMQSpamTest1.main(ActiveMQSpamTest1.java:117)
The attached test instantiates an embedded broker and consistently duplicates
the problem on my machine (Macbook Pro running Leopard). The test duplicates
behavior we see in production code, which is running an embedded broker on
Debian Linux.
I run the test in Eclipse with -Xmx1100mb. The output I see (after a minute or
so) is:
...
SENT a (mod 10000) message: i=0
SENT a (mod 10000) message: i=10000
SENT a (mod 10000) message: i=20000
SENT a (mod 10000) message: i=30000
SENT a (mod 10000) message: i=40000
SENT a (mod 10000) message: i=50000
Sep 11, 2009 3:28:13 PM org.apache.activemq.kaha.impl.KahaStore initialize
INFO: Kaha Store using data directory activemq-data/localhost/tmp_storage
RECEIVED a (mod 10000) message: i=10000
RECEIVED a (mod 10000) message: i=20000
RECEIVED a (mod 10000) message: i=30000
RECEIVED a (mod 10000) message: i=40000
RECEIVED a (mod 10000) message: i=50000
after which no further messages are processed, and a thread dump includes the
signature shown above. Uncommenting the line
broker.setPersistent(false);
results in the test running to completion (all messages are sent/consumed),
with the following output:
SENT a (mod 10000) message: i=0
SENT a (mod 10000) message: i=10000
SENT a (mod 10000) message: i=20000
SENT a (mod 10000) message: i=30000
SENT a (mod 10000) message: i=40000
SENT a (mod 10000) message: i=50000
SENT a (mod 10000) message: i=60000
RECEIVED a (mod 10000) message: i=10000
DONE sending messages
RECEIVED a (mod 10000) message: i=20000
RECEIVED a (mod 10000) message: i=30000
RECEIVED a (mod 10000) message: i=40000
RECEIVED a (mod 10000) message: i=50000
RECEIVED a (mod 10000) message: i=60000
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
