[AMQ-3530] Broker (5.5) Deadlock when limiting size of temp store, and using VirtualTopics

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Invalid
• Affects Version/s: 5.5.0
• Component/s: Broker
• Labels: activemq nonPersistent storeCursor virtualTopic

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

• Patch Info: Patch Available
• Assignee: Unassigned
• Reporter: Dominic Tootell
• Created: 08/Oct/11 17:11
• Updated: 24/Feb/12 16:01
• Resolved: 24/Feb/12 16:01

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:

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

or

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

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:

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

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

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

---

The tests can be run as maven tests directly:

mvn clean test -Dtest=KahaDBTempStorageDeadlockReplication55Test -Dlimit.temp=true

---

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

Issue Links

• relates to: AMQ-3061 Broker Deadlock when limiting size of temp store, and using VirtualTopics