activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Dominic Tootell (Updated) (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (AMQ-3530) Broker (5.5) Deadlock when limiting size of temp store, and using VirtualTopics
Date Sat, 08 Oct 2011 17:16:29 GMT

     [ https://issues.apache.org/jira/browse/AMQ-3530?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Dominic Tootell updated AMQ-3530:
---------------------------------

    Description: 
When using Virtual Topics and attempting to limit the Temp Table space the broker will dead
lock.

I have created a test case the demonstrates the above issue.  The test case has the following
scenario:

- 1 Producer Thread (own connection) writing to VirtualTopic.FooTwo
-- writes 10000 messages
- 2 Consumer Threads (each own connection) consuming from Consumer.X.VirtualTopic.FooTwo
-- consumes message (auto ack - but message ack for good measure - delay of 10ms between consumption)


The dead lock occurs when using the either the KahaDB or ActiveMQPersistence persistence store
is used, and seems more related to the KahaDB implementation used for the Temp storage area.

I shall attach the test case (maven project), which when built (mvn clean package -DskipTests=true)
will create an executable jar (target/5.5.0-deadlock-jar-with-dependencies.jar), from which
the issue can be replicated:

The tests can be run as follows:

{noformat}
java -classpath target/5.5.0-deadlock-jar-with-dependencies.jar bbc.forge.domt.activemq.investigation.KahaDBTempStorageDeadlockReplication55
{noformat}

or 

{noformat}
java -classpath target/5.5.0-deadlock-jar-with-dependencies.jar bbc.forge.domt.activemq.investigation.TempStorageDeadlockReplication55
{noformat}

These classes are also Unit Test Cases, and output the following log files:

- Producer logs to target/producer.log
- Consumes log to target/consumer.log
- A Monitor thread just run in the background that detail the number of messages sent and
consumed... logs to target/monitor.log
- tests write to the dir *{{target/activemq-data}}*

The target/monitor.log can be tailed, upon which you can see the dead lock occur; where the
consumer stops consumering and  the producer stops sending; something like the following:

{noformat}
Dominic-Tootells-MacBook-Pro-2:trunk dominict$ tail -f monitor.log
[2011.10.08 17:15:09] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):0
[2011.10.08 17:15:09] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:0
[2011.10.08 17:15:10] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:10] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:35
[2011.10.08 17:15:11] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:11] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:74
[2011.10.08 17:15:12] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:12] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:114
[2011.10.08 17:15:13] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:13] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:152
[2011.10.08 17:15:14] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:14] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:192
[2011.10.08 17:15:15] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:15] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:232
[2011.10.08 17:15:16] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:16] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:248
[2011.10.08 17:15:17] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:17] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:248
[2011.10.08 17:15:18] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:18] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:248
[2011.10.08 17:15:19] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:19] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:248
{noformat}

To disable limiting the temp storage add the System property *{{limit.temp=false}}*; and you
see that the deadlock no longer occurs:

{noformat}
java -Dlimit.temp=false -classpath target/5.5.0-deadlock-jar-with-dependencies.jar bbc.forge.domt.activemq.investigation.KahaDBTempStorageDeadlockReplication55
{noformat}


----

The tests can be run as maven tests directly:

{noformat}
mvn clean test -Dtest=KahaDBTempStorageDeadlockReplication55Test -Dlimit.temp=true
{noformat}

----


This seems to be a different/additional issue to AMQ-2475

----

The reason why this issue affects our ActiveMQ environment/installation so much, is that we
use a shared infrastructure model.  Meaning that we provision many activemq instances on the
same physcial hardware for different projects/clients.  We limit the disk space assigned to
each broker so that no one application goes wild and consumes all the disk space on the hardware;
and as a result impacts other projects/clients.  Although it theory running more than one
instance of ActiveMQ on a server might seem counter intutitive (with regards to performance
- disk seeking); this is a business model by which we can get the most money out of out physical
hardware and provide a MOM for most projects; for which maximum throughput is a secondary
concern.

Apologies that this issue is a duplicate of AMQ-3061.  However, the reason I'm opening an
additional ticket is the hope that I can actually provide you a patch in here (if possible)
that is coded against the 5.5 apache activemq version.  As in AMQ-3061 I accidentally:

a) provided a faulty patch
b) gave you a patch against a 5.4.1 version of fuse's activemq.

Big appologies for that.  


thanks in advance, let me know if you need any more information.
/dom



  was:
When using Virtual Topics and attempting to limit the Temp Table space the broker will dead
lock.

I have created a test case the demonstrates the above issue.  The test case has the following
scenario:

- 1 Producer Thread (own connection) writing to VirtualTopic.FooTwo
-- writes 10000 messages
- 2 Consumer Threads (each own connection) consuming from Consumer.X.VirtualTopic.FooTwo
-- consumes message (auto ack - but message ack for good measure - delay of 10ms between consumption)


The dead lock occurs when using the either the KahaDB or ActiveMQPersistence persistence store
is used, and seems more related to the KahaDB implementation used for the Temp storage area.

I shall attach the test case (maven project), which when built (mvn clean package -DskipTests=true)
will create an executable jar (target/5.5.0-deadlock-jar-with-dependencies.jar), from which
the issue can be replicated:

The tests can be run as follows:

{noformat}
java -classpath target/5.5.0-deadlock-jar-with-dependencies.jar bbc.forge.domt.activemq.investigation.KahaDBTempStorageDeadlockReplication55
{noformat}

or 

{noformat}
java -classpath target/5.5.0-deadlock-jar-with-dependencies.jar bbc.forge.domt.activemq.investigation.TempStorageDeadlockReplication55
{noformat}

These classes are also Unit Test Cases, and output the following log files:

- Producer logs to target/producer.log
- Consumes log to target/consumer.log
- A Monitor thread just run in the background that detail the number of messages sent and
consumed... logs to target/monitor.log
- tests write to the dir *{{target/activemq-data}}*

The target/monitor.log can be tailed, upon which you can see the dead lock occur; where the
consumer stops consumering and  the producer stops sending; something like the following:

{noformat}
Dominic-Tootells-MacBook-Pro-2:trunk dominict$ tail -f monitor.log
[2011.10.08 17:15:09] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):0
[2011.10.08 17:15:09] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:0
[2011.10.08 17:15:10] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:10] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:35
[2011.10.08 17:15:11] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:11] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:74
[2011.10.08 17:15:12] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:12] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:114
[2011.10.08 17:15:13] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:13] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:152
[2011.10.08 17:15:14] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:14] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:192
[2011.10.08 17:15:15] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:15] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:232
[2011.10.08 17:15:16] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:16] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:248
[2011.10.08 17:15:17] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:17] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:248
[2011.10.08 17:15:18] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:18] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:248
[2011.10.08 17:15:19] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
[2011.10.08 17:15:19] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:248
{noformat}

To disable limiting the temp storage add the System property *{{limit.temp=false}}*; and you
see that the deadlock no longer occurs:

{noformat}
java -Dlimit.temp=false -classpath target/5.5.0-deadlock-jar-with-dependencies.jar bbc.forge.domt.activemq.investigation.KahaDBTempStorageDeadlockReplication55
{noformat}


----

The tests can be run as maven tests directly:

{noformat}
mvn clean test -Dtest=KahaDBTempStorageDeadlockReplication55Test -Dlimit.temp=true
{noformat}

----


This seems to be a different/additional issue to AMQ-2475

----

The reason why this issue affects our ActiveMQ environment/installation so much, is that we
use a shared infrastructure model.  Meaning that we provision many 
activemq instances on the same physcial hardware for different projects/clients.  We limit
the disk space assigned to each broker so that no
one application goes wild and consumes all the disk space on the hardware; and as a result
impacts other projects/clients.  Although it theory
running more than one instance of ActiveMQ on a server might seem counter intutitive (with
regards to performance - disk seeking); this is a 
business model by which we can get the most money out of out physical hardware and provide
a MOM for most projects; for which maximum throughput is a
secondary concern.

Apologies that this issue is a duplicate of AMQ-3061.  However, the reason I'm opening an
additional ticket is the hope that I can actually provide you a patch in here (if possible)
that is coded against the 5.5 apache activemq version.  As in AMQ-3061 I accidentally:

a) provided a faulty patch
b) gave you a patch against a 5.4.1 version of fuse's activemq.

Big appologies for that.  


thanks in advance, let me know if you need any more information.
/dom



    
> Broker (5.5) Deadlock when limiting size of temp store, and using VirtualTopics
> -------------------------------------------------------------------------------
>
>                 Key: AMQ-3530
>                 URL: https://issues.apache.org/jira/browse/AMQ-3530
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.5.0
>         Environment: 10.8.0 Darwin Kernel Version 10.8.0: Tue Jun  7 16:33:36 PDT 2011;
root:xnu-1504.15.3~1/RELEASE_I386 i386
>            Reporter: Dominic Tootell
>         Attachments: deadlock.tar.gz
>
>
> When using Virtual Topics and attempting to limit the Temp Table space the broker will
dead lock.
> I have created a test case the demonstrates the above issue.  The test case has the following
scenario:
> - 1 Producer Thread (own connection) writing to VirtualTopic.FooTwo
> -- writes 10000 messages
> - 2 Consumer Threads (each own connection) consuming from Consumer.X.VirtualTopic.FooTwo
> -- consumes message (auto ack - but message ack for good measure - delay of 10ms between
consumption)
> The dead lock occurs when using the either the KahaDB or ActiveMQPersistence persistence
store is used, and seems more related to the KahaDB implementation used for the Temp storage
area.
> I shall attach the test case (maven project), which when built (mvn clean package -DskipTests=true)
will create an executable jar (target/5.5.0-deadlock-jar-with-dependencies.jar), from which
the issue can be replicated:
> The tests can be run as follows:
> {noformat}
> java -classpath target/5.5.0-deadlock-jar-with-dependencies.jar bbc.forge.domt.activemq.investigation.KahaDBTempStorageDeadlockReplication55
> {noformat}
> or 
> {noformat}
> java -classpath target/5.5.0-deadlock-jar-with-dependencies.jar bbc.forge.domt.activemq.investigation.TempStorageDeadlockReplication55
> {noformat}
> These classes are also Unit Test Cases, and output the following log files:
> - Producer logs to target/producer.log
> - Consumes log to target/consumer.log
> - A Monitor thread just run in the background that detail the number of messages sent
and consumed... logs to target/monitor.log
> - tests write to the dir *{{target/activemq-data}}*
> The target/monitor.log can be tailed, upon which you can see the dead lock occur; where
the consumer stops consumering and  the producer stops sending; something like the following:
> {noformat}
> Dominic-Tootells-MacBook-Pro-2:trunk dominict$ tail -f monitor.log
> [2011.10.08 17:15:09] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):0
> [2011.10.08 17:15:09] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:0
> [2011.10.08 17:15:10] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
> [2011.10.08 17:15:10] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:35
> [2011.10.08 17:15:11] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
> [2011.10.08 17:15:11] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:74
> [2011.10.08 17:15:12] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
> [2011.10.08 17:15:12] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:114
> [2011.10.08 17:15:13] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
> [2011.10.08 17:15:13] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:152
> [2011.10.08 17:15:14] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
> [2011.10.08 17:15:14] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:192
> [2011.10.08 17:15:15] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
> [2011.10.08 17:15:15] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:232
> [2011.10.08 17:15:16] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
> [2011.10.08 17:15:16] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:248
> [2011.10.08 17:15:17] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
> [2011.10.08 17:15:17] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:248
> [2011.10.08 17:15:18] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
> [2011.10.08 17:15:18] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:248
> [2011.10.08 17:15:19] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Sent(Produced):248
> [2011.10.08 17:15:19] [Thread-14] INFO  MonitorConsumerAndProducedThread -  No of Message
Consumed:248
> {noformat}
> To disable limiting the temp storage add the System property *{{limit.temp=false}}*;
and you see that the deadlock no longer occurs:
> {noformat}
> java -Dlimit.temp=false -classpath target/5.5.0-deadlock-jar-with-dependencies.jar bbc.forge.domt.activemq.investigation.KahaDBTempStorageDeadlockReplication55
> {noformat}
> ----
> The tests can be run as maven tests directly:
> {noformat}
> mvn clean test -Dtest=KahaDBTempStorageDeadlockReplication55Test -Dlimit.temp=true
> {noformat}
> ----
> This seems to be a different/additional issue to AMQ-2475
> ----
> The reason why this issue affects our ActiveMQ environment/installation so much, is that
we use a shared infrastructure model.  Meaning that we provision many activemq instances on
the same physcial hardware for different projects/clients.  We limit the disk space assigned
to each broker so that no one application goes wild and consumes all the disk space on the
hardware; and as a result impacts other projects/clients.  Although it theory running more
than one instance of ActiveMQ on a server might seem counter intutitive (with regards to performance
- disk seeking); this is a business model by which we can get the most money out of out physical
hardware and provide a MOM for most projects; for which maximum throughput is a secondary
concern.
> Apologies that this issue is a duplicate of AMQ-3061.  However, the reason I'm opening
an additional ticket is the hope that I can actually provide you a patch in here (if possible)
that is coded against the 5.5 apache activemq version.  As in AMQ-3061 I accidentally:
> a) provided a faulty patch
> b) gave you a patch against a 5.4.1 version of fuse's activemq.
> Big appologies for that.  
> thanks in advance, let me know if you need any more information.
> /dom

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

Mime
View raw message