You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by drvillo <f....@gmail.com> on 2006/12/23 11:44:56 UTC

Another deadlock showing up

Hi all

This one happens systematically after a while I run my service (not during
an isolated test).
I have still to figure out if I can reproduce it with a stub.
Anyway it always appear to be the same.

The only thing that I find relevant in the logs is that at some point the
broker seems to be unreachable a moment,
but after that clients reconnect and everything goes on normally.
I have attached an excerpt of the log to make things clearer.
http://www.nabble.com/file/5096/deadlock.log deadlock.log 

I'm using an embedded broker, over tcp and connecting through 
tcp://localhost:61617?jms.dispatchAsync=true&amp;jms.dispatchAsync=true


with ActiveMQ-4.2-incubator-SNAPSHOT.
I'm pretty sure this wasn't happening with 4.0.1

I hope someone can help me on this, right now I'm pretty much stuck.

Thanks everybody, and merry christmas!
Francesco


Found one Java-level deadlock:
=============================
"ActiveMQ Task":
  waiting to lock monitor 0x080e4f3c (object 0x92b60db0, a
java.util.LinkedList),
  which is held by "ActiveMQ Transport: tcp:///127.0.0.1:37496"
"ActiveMQ Transport: tcp:///127.0.0.1:37496":
  waiting to lock monitor 0x080e4f7c (object 0x92b60d98, a
org.apache.activemq.broker.region.cursors.VMPendingMessageCursor),
  which is held by "ActiveMQ Task"

Java stack information for the threads listed above:
===================================================
"ActiveMQ Task":
        at
org.apache.activemq.broker.region.PrefetchSubscription.dispatch(PrefetchSubscription.java:414)
        - waiting to lock <0x92b60db0> (a java.util.LinkedList)
        at
org.apache.activemq.broker.region.QueueSubscription.dispatch(QueueSubscription.java:172)
        at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchMatched(PrefetchSubscription.java:397)
        - locked <0x92b60d98> (a
org.apache.activemq.broker.region.cursors.VMPendingMessageCursor)
        at
org.apache.activemq.broker.region.PrefetchSubscription.onDispatch(PrefetchSubscription.java:451)
        at
org.apache.activemq.broker.region.QueueSubscription.onDispatch(QueueSubscription.java:192)
        at
org.apache.activemq.broker.region.PrefetchSubscription$3.run(PrefetchSubscription.java:429)
        at
org.apache.activemq.broker.TransportConnection.processDispatch(TransportConnection.java:778)
        at
org.apache.activemq.broker.TransportConnection.iterate(TransportConnection.java:791)
        at
org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:111)
        at
org.apache.activemq.thread.PooledTaskRunner.access$100(PooledTaskRunner.java:26)
        at
org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:44)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
        at java.lang.Thread.run(Thread.java:595)
"ActiveMQ Transport: tcp:///127.0.0.1:37496":
        at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchMatched(PrefetchSubscription.java:383)
        - waiting to lock <0x92b60d98> (a
org.apache.activemq.broker.region.cursors.VMPendingMessageCursor)
        at
org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:219)
        - locked <0x92b60db0> (a java.util.LinkedList)
        at
org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:299)
        at
org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:397)
        at
org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:177)
        at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:74)
        at
org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:74)
        at
org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:88)
        at
org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:491)
        at org.apache.activemq.command.MessageAck.visit(MessageAck.java:179)
        at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:287)
        at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:178)
        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)

Found 1 deadlock.




-- 
View this message in context: http://www.nabble.com/Another-deadlock-showing-up-tf2874106.html#a8033006
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: Another deadlock showing up

Posted by Rob Davies <ra...@gmail.com>.
Hi Francesco,

http://issues.apache.org/activemq/browse/AMQ-1108 is now fixed in SVN  
trunk

cheers,

Rob
On 23 Dec 2006, at 18:41, drvillo wrote:

>
> If it can help, it happens when a consumer start sending a pretty
> high volume of messages (~100k) back into the beginning of a
> pipelined system, i.e there is recursion of still uncommitted  
> transaction.
>
> Cheers
> Francesco
>
>
> rajdavies wrote:
>>
>> I've created a jira issue for this:  http://issues.apache.org/
>> activemq/browse/AMQ-1108
>>
>> cheers,
>>
>> Rob
>> On 23 Dec 2006, at 10:44, drvillo wrote:
>>
>>> Found one Java-level deadlock:
>>> =============================
>>> "ActiveMQ Task":
>>>   waiting to lock monitor 0x080e4f3c (object 0x92b60db0, a
>>> java.util.LinkedList),
>>>   which is held by "ActiveMQ Transport: tcp:///127.0.0.1:37496"
>>> "ActiveMQ Transport: tcp:///127.0.0.1:37496":
>>>   waiting to lock monitor 0x080e4f7c (object 0x92b60d98, a
>>> org.apache.activemq.broker.region.cursors.VMPendingMessageCursor),
>>>   which is held by "ActiveMQ Task"
>>>
>>> Java stack information for the threads listed above:
>>> ===================================================
>>> "ActiveMQ Task":
>>>         at
>>> org.apache.activemq.broker.region.PrefetchSubscription.dispatch
>>> (PrefetchSubscription.java:414)
>>>         - waiting to lock <0x92b60db0> (a java.util.LinkedList)
>>>         at
>>> org.apache.activemq.broker.region.QueueSubscription.dispatch
>>> (QueueSubscription.java:172)
>>>         at
>>> org.apache.activemq.broker.region.PrefetchSubscription.dispatchMatch 
>>> ed
>>> (PrefetchSubscription.java:397)
>>>         - locked <0x92b60d98> (a
>>> org.apache.activemq.broker.region.cursors.VMPendingMessageCursor)
>>>         at
>>> org.apache.activemq.broker.region.PrefetchSubscription.onDispatch
>>> (PrefetchSubscription.java:451)
>>>         at
>>> org.apache.activemq.broker.region.QueueSubscription.onDispatch
>>> (QueueSubscription.java:192)
>>>         at
>>> org.apache.activemq.broker.region.PrefetchSubscription$3.run
>>> (PrefetchSubscription.java:429)
>>>         at
>>> org.apache.activemq.broker.TransportConnection.processDispatch
>>> (TransportConnection.java:778)
>>>         at
>>> org.apache.activemq.broker.TransportConnection.iterate
>>> (TransportConnection.java:791)
>>>         at
>>> org.apache.activemq.thread.PooledTaskRunner.runTask
>>> (PooledTaskRunner.java:111)
>>>         at
>>> org.apache.activemq.thread.PooledTaskRunner.access$100
>>> (PooledTaskRunner.java:26)
>>>         at
>>> org.apache.activemq.thread.PooledTaskRunner$1.run
>>> (PooledTaskRunner.java:44)
>>>         at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask
>>> (ThreadPoolExecutor.java:650)
>>>         at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run
>>> (ThreadPoolExecutor.java:675)
>>>         at java.lang.Thread.run(Thread.java:595)
>>> "ActiveMQ Transport: tcp:///127.0.0.1:37496":
>>>         at
>>> org.apache.activemq.broker.region.PrefetchSubscription.dispatchMatch 
>>> ed
>>> (PrefetchSubscription.java:383)
>>>         - waiting to lock <0x92b60d98> (a
>>> org.apache.activemq.broker.region.cursors.VMPendingMessageCursor)
>>>         at
>>> org.apache.activemq.broker.region.PrefetchSubscription.acknowledge
>>> (PrefetchSubscription.java:219)
>>>         - locked <0x92b60db0> (a java.util.LinkedList)
>>>         at
>>> org.apache.activemq.broker.region.AbstractRegion.acknowledge
>>> (AbstractRegion.java:299)
>>>         at
>>> org.apache.activemq.broker.region.RegionBroker.acknowledge
>>> (RegionBroker.java:397)
>>>         at
>>> org.apache.activemq.broker.TransactionBroker.acknowledge
>>> (TransactionBroker.java:177)
>>>         at
>>> org.apache.activemq.broker.BrokerFilter.acknowledge
>>> (BrokerFilter.java:74)
>>>         at
>>> org.apache.activemq.broker.BrokerFilter.acknowledge
>>> (BrokerFilter.java:74)
>>>         at
>>> org.apache.activemq.broker.MutableBrokerFilter.acknowledge
>>> (MutableBrokerFilter.java:88)
>>>         at
>>> org.apache.activemq.broker.TransportConnection.processMessageAck
>>> (TransportConnection.java:491)
>>>         at org.apache.activemq.command.MessageAck.visit
>>> (MessageAck.java:179)
>>>         at
>>> org.apache.activemq.broker.TransportConnection.service
>>> (TransportConnection.java:287)
>>>         at
>>> org.apache.activemq.broker.TransportConnection$1.onCommand
>>> (TransportConnection.java:178)
>>>         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)
>>>
>>> Found 1 deadlock.
>>>
>>
>>
>>
>
> -- 
> View this message in context: http://www.nabble.com/Another- 
> deadlock-showing-up-tf2874106.html#a8035799
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>

Re: Another deadlock showing up

Posted by drvillo <f....@gmail.com>.
If it can help, it happens when a consumer start sending a pretty 
high volume of messages (~100k) back into the beginning of a 
pipelined system, i.e there is recursion of still uncommitted transaction.

Cheers
Francesco


rajdavies wrote:
> 
> I've created a jira issue for this:  http://issues.apache.org/ 
> activemq/browse/AMQ-1108
> 
> cheers,
> 
> Rob
> On 23 Dec 2006, at 10:44, drvillo wrote:
> 
>> Found one Java-level deadlock:
>> =============================
>> "ActiveMQ Task":
>>   waiting to lock monitor 0x080e4f3c (object 0x92b60db0, a
>> java.util.LinkedList),
>>   which is held by "ActiveMQ Transport: tcp:///127.0.0.1:37496"
>> "ActiveMQ Transport: tcp:///127.0.0.1:37496":
>>   waiting to lock monitor 0x080e4f7c (object 0x92b60d98, a
>> org.apache.activemq.broker.region.cursors.VMPendingMessageCursor),
>>   which is held by "ActiveMQ Task"
>>
>> Java stack information for the threads listed above:
>> ===================================================
>> "ActiveMQ Task":
>>         at
>> org.apache.activemq.broker.region.PrefetchSubscription.dispatch 
>> (PrefetchSubscription.java:414)
>>         - waiting to lock <0x92b60db0> (a java.util.LinkedList)
>>         at
>> org.apache.activemq.broker.region.QueueSubscription.dispatch 
>> (QueueSubscription.java:172)
>>         at
>> org.apache.activemq.broker.region.PrefetchSubscription.dispatchMatched 
>> (PrefetchSubscription.java:397)
>>         - locked <0x92b60d98> (a
>> org.apache.activemq.broker.region.cursors.VMPendingMessageCursor)
>>         at
>> org.apache.activemq.broker.region.PrefetchSubscription.onDispatch 
>> (PrefetchSubscription.java:451)
>>         at
>> org.apache.activemq.broker.region.QueueSubscription.onDispatch 
>> (QueueSubscription.java:192)
>>         at
>> org.apache.activemq.broker.region.PrefetchSubscription$3.run 
>> (PrefetchSubscription.java:429)
>>         at
>> org.apache.activemq.broker.TransportConnection.processDispatch 
>> (TransportConnection.java:778)
>>         at
>> org.apache.activemq.broker.TransportConnection.iterate 
>> (TransportConnection.java:791)
>>         at
>> org.apache.activemq.thread.PooledTaskRunner.runTask 
>> (PooledTaskRunner.java:111)
>>         at
>> org.apache.activemq.thread.PooledTaskRunner.access$100 
>> (PooledTaskRunner.java:26)
>>         at
>> org.apache.activemq.thread.PooledTaskRunner$1.run 
>> (PooledTaskRunner.java:44)
>>         at
>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask 
>> (ThreadPoolExecutor.java:650)
>>         at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run 
>> (ThreadPoolExecutor.java:675)
>>         at java.lang.Thread.run(Thread.java:595)
>> "ActiveMQ Transport: tcp:///127.0.0.1:37496":
>>         at
>> org.apache.activemq.broker.region.PrefetchSubscription.dispatchMatched 
>> (PrefetchSubscription.java:383)
>>         - waiting to lock <0x92b60d98> (a
>> org.apache.activemq.broker.region.cursors.VMPendingMessageCursor)
>>         at
>> org.apache.activemq.broker.region.PrefetchSubscription.acknowledge 
>> (PrefetchSubscription.java:219)
>>         - locked <0x92b60db0> (a java.util.LinkedList)
>>         at
>> org.apache.activemq.broker.region.AbstractRegion.acknowledge 
>> (AbstractRegion.java:299)
>>         at
>> org.apache.activemq.broker.region.RegionBroker.acknowledge 
>> (RegionBroker.java:397)
>>         at
>> org.apache.activemq.broker.TransactionBroker.acknowledge 
>> (TransactionBroker.java:177)
>>         at
>> org.apache.activemq.broker.BrokerFilter.acknowledge 
>> (BrokerFilter.java:74)
>>         at
>> org.apache.activemq.broker.BrokerFilter.acknowledge 
>> (BrokerFilter.java:74)
>>         at
>> org.apache.activemq.broker.MutableBrokerFilter.acknowledge 
>> (MutableBrokerFilter.java:88)
>>         at
>> org.apache.activemq.broker.TransportConnection.processMessageAck 
>> (TransportConnection.java:491)
>>         at org.apache.activemq.command.MessageAck.visit 
>> (MessageAck.java:179)
>>         at
>> org.apache.activemq.broker.TransportConnection.service 
>> (TransportConnection.java:287)
>>         at
>> org.apache.activemq.broker.TransportConnection$1.onCommand 
>> (TransportConnection.java:178)
>>         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)
>>
>> Found 1 deadlock.
>>
> 
> 
> 

-- 
View this message in context: http://www.nabble.com/Another-deadlock-showing-up-tf2874106.html#a8035799
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: Another deadlock showing up

Posted by Rob Davies <ra...@gmail.com>.
I've created a jira issue for this:  http://issues.apache.org/ 
activemq/browse/AMQ-1108

cheers,

Rob
On 23 Dec 2006, at 10:44, drvillo wrote:

> Found one Java-level deadlock:
> =============================
> "ActiveMQ Task":
>   waiting to lock monitor 0x080e4f3c (object 0x92b60db0, a
> java.util.LinkedList),
>   which is held by "ActiveMQ Transport: tcp:///127.0.0.1:37496"
> "ActiveMQ Transport: tcp:///127.0.0.1:37496":
>   waiting to lock monitor 0x080e4f7c (object 0x92b60d98, a
> org.apache.activemq.broker.region.cursors.VMPendingMessageCursor),
>   which is held by "ActiveMQ Task"
>
> Java stack information for the threads listed above:
> ===================================================
> "ActiveMQ Task":
>         at
> org.apache.activemq.broker.region.PrefetchSubscription.dispatch 
> (PrefetchSubscription.java:414)
>         - waiting to lock <0x92b60db0> (a java.util.LinkedList)
>         at
> org.apache.activemq.broker.region.QueueSubscription.dispatch 
> (QueueSubscription.java:172)
>         at
> org.apache.activemq.broker.region.PrefetchSubscription.dispatchMatched 
> (PrefetchSubscription.java:397)
>         - locked <0x92b60d98> (a
> org.apache.activemq.broker.region.cursors.VMPendingMessageCursor)
>         at
> org.apache.activemq.broker.region.PrefetchSubscription.onDispatch 
> (PrefetchSubscription.java:451)
>         at
> org.apache.activemq.broker.region.QueueSubscription.onDispatch 
> (QueueSubscription.java:192)
>         at
> org.apache.activemq.broker.region.PrefetchSubscription$3.run 
> (PrefetchSubscription.java:429)
>         at
> org.apache.activemq.broker.TransportConnection.processDispatch 
> (TransportConnection.java:778)
>         at
> org.apache.activemq.broker.TransportConnection.iterate 
> (TransportConnection.java:791)
>         at
> org.apache.activemq.thread.PooledTaskRunner.runTask 
> (PooledTaskRunner.java:111)
>         at
> org.apache.activemq.thread.PooledTaskRunner.access$100 
> (PooledTaskRunner.java:26)
>         at
> org.apache.activemq.thread.PooledTaskRunner$1.run 
> (PooledTaskRunner.java:44)
>         at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask 
> (ThreadPoolExecutor.java:650)
>         at
> java.util.concurrent.ThreadPoolExecutor$Worker.run 
> (ThreadPoolExecutor.java:675)
>         at java.lang.Thread.run(Thread.java:595)
> "ActiveMQ Transport: tcp:///127.0.0.1:37496":
>         at
> org.apache.activemq.broker.region.PrefetchSubscription.dispatchMatched 
> (PrefetchSubscription.java:383)
>         - waiting to lock <0x92b60d98> (a
> org.apache.activemq.broker.region.cursors.VMPendingMessageCursor)
>         at
> org.apache.activemq.broker.region.PrefetchSubscription.acknowledge 
> (PrefetchSubscription.java:219)
>         - locked <0x92b60db0> (a java.util.LinkedList)
>         at
> org.apache.activemq.broker.region.AbstractRegion.acknowledge 
> (AbstractRegion.java:299)
>         at
> org.apache.activemq.broker.region.RegionBroker.acknowledge 
> (RegionBroker.java:397)
>         at
> org.apache.activemq.broker.TransactionBroker.acknowledge 
> (TransactionBroker.java:177)
>         at
> org.apache.activemq.broker.BrokerFilter.acknowledge 
> (BrokerFilter.java:74)
>         at
> org.apache.activemq.broker.BrokerFilter.acknowledge 
> (BrokerFilter.java:74)
>         at
> org.apache.activemq.broker.MutableBrokerFilter.acknowledge 
> (MutableBrokerFilter.java:88)
>         at
> org.apache.activemq.broker.TransportConnection.processMessageAck 
> (TransportConnection.java:491)
>         at org.apache.activemq.command.MessageAck.visit 
> (MessageAck.java:179)
>         at
> org.apache.activemq.broker.TransportConnection.service 
> (TransportConnection.java:287)
>         at
> org.apache.activemq.broker.TransportConnection$1.onCommand 
> (TransportConnection.java:178)
>         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)
>
> Found 1 deadlock.
>