[
https://issues.apache.org/activemq/browse/AMQ-2962?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=62612#action_62612
]
Roelof Naude commented on AMQ-2962:
-----------------------------------
i've found something of interest. the write lock hangs are due to the read lock
being taken. i also added LOG.debug statement before each lock and after each
unlock in KahaDBStore.java as well as those places in MessageDatabase.java as
indicated in the attached thread dumps.
2010-10-15 15:27:16,082 INFO
[org.apache.activemq.store.kahadb.MessageDatabase] KahaDB is version 2
2010-10-15 15:27:16,172 INFO
[org.apache.activemq.store.kahadb.MessageDatabase] Recovering from the journal
...
2010-10-15 15:27:16,180 DEBUG
[org.apache.activemq.store.kahadb.MessageDatabase] process remove -
lock[java.util.concurrent.locks.reentrantreadwritel...@30de3c87[write locks =
2, Read locks = 0]]
2010-10-15 15:27:16,183 DEBUG
[org.apache.activemq.store.kahadb.MessageDatabase] process remove -
unlock[java.util.concurrent.locks.reentrantreadwritel...@30de3c87[write locks =
2, Read locks = 0]]
2010-10-15 15:27:16,183 INFO
[org.apache.activemq.store.kahadb.MessageDatabase] Recovery replayed 3
operations from the journal in 0.081 seconds.
2010-10-15 15:27:16,198 INFO [org.apache.activemq.broker.BrokerService]
ActiveMQ 5.4.1 JMS Message Broker (localhost) is starting
2010-10-15 15:27:16,200 INFO [org.apache.activemq.broker.BrokerService] For
help or more information please see: http://activemq.apache.org/
2010-10-15 15:27:16,358 DEBUG [org.apache.activemq.store.kahadb.KahaDBStore]
getDestinations -
lock[java.util.concurrent.locks.reentrantreadwritel...@30de3c87[write locks =
0, Read locks = 0]]
2010-10-15 15:27:16,360 DEBUG [org.apache.activemq.store.kahadb.KahaDBStore]
getDestinations -
unlock[java.util.concurrent.locks.reentrantreadwritel...@30de3c87[write locks =
0, Read locks = 0]]
2010-10-15 15:27:16,362 DEBUG
[org.apache.activemq.broker.region.AbstractRegion] localhost adding
destination: queue://Consumer.superuser.VirtualTopic.ALARM
2010-10-15 15:27:16,394 DEBUG [org.apache.activemq.store.kahadb.KahaDBStore]
getMessageCount -
lock[java.util.concurrent.locks.reentrantreadwritel...@30de3c87[write locks =
0, Read locks = 0]]
2010-10-15 15:27:16,395 DEBUG [org.apache.activemq.store.kahadb.KahaDBStore]
getMessageCount -
unlock[java.util.concurrent.locks.reentrantreadwritel...@30de3c87[write locks =
0, Read locks = 0]]
2010-10-15 15:27:16,395 DEBUG [org.apache.activemq.store.kahadb.KahaDBStore]
recover - lock[java.util.concurrent.locks.reentrantreadwritel...@30de3c87[write
locks = 0, Read locks = 0]]
2010-10-15 15:27:16,421 DEBUG [org.apache.activemq.broker.region.Queue] message
expired: Message ID:segfault-43426-1287148162735-2:8:1:1:1 dropped=false
acked=false locked=false
2010-10-15 15:27:16,421 DEBUG [org.apache.activemq.broker.region.RegionBroker]
Message expired Message ID:segfault-43426-1287148162735-2:8:1:1:1 dropped=false
acked=false locked=false
2010-10-15 15:27:16,425 DEBUG
[org.apache.activemq.broker.region.AbstractRegion] localhost adding
destination: topic://ActiveMQ.Advisory.MessageDLQd.Topic.VirtualTopic.ALARM
2010-10-15 15:27:16,448 DEBUG
[org.apache.activemq.broker.region.AbstractRegion] localhost adding
destination: topic://ActiveMQ.Advisory.Expired.Topic.VirtualTopic.ALARM
2010-10-15 15:27:16,464 DEBUG
[org.apache.activemq.store.kahadb.MessageDatabase] process remove -
lock[java.util.concurrent.locks.reentrantreadwritel...@30de3c87[write locks =
0, Read locks = 1]]
take note of:
1. recover - lock (no unlock is printed)
2. MessageDatabase] process remove
(1) takes a read lock in KahaDBStore::recover. when (2)
MessageDatabase::process (final KahaRemoveMessageCommand) comes along it
blocks. ditto for MessageDatabase::checkpointCleanup
i guess the next step would be to figure out why KahaDBStore::recover is not
releasing the lock?
> Hanging at startup
> ------------------
>
> Key: AMQ-2962
> URL: https://issues.apache.org/activemq/browse/AMQ-2962
> Project: ActiveMQ
> Issue Type: Bug
> Components: Message Store
> Affects Versions: 5.4.1
> Environment: Fedora Core 12
> Reporter: Roelof Naude
> Priority: Minor
> Attachments: amq.ra.threads.txt, debug_traces_hanging.log,
> debug_traces_startup.log, thread_dump_during_hang.txt
>
>
> Noticed today the activemq was hanging during startup. Investigation revealed
> that it is tied to expiration of messages at startup. The only way to recover
> from this was to kill -9 the VM and delete the kahadb message store.
> Further testing was done whereby message expiry time was set to longer
> period. AMQ started up just fine. Another test was performed whereby:
> 1. subscribe for messages
> 2. send a few messages
> 3. disconnect consumer
> 4. send more messages (1 or 2 will do)
> 5. shutdown AMQ
> 6. wait for a time period exceeded the expiration time of the messages
> 7. start AMQ. at this time it should be hanging
> Logs and thread dumps attached.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
