[
https://issues.apache.org/jira/browse/AMQ-3120?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12985329#action_12985329
]
Dan Checkoway commented on AMQ-3120:
------------------------------------
@Patrick, I just wanted to say THANK YOU for the
ignoreMissingJournalfiles="true" trick. That saved us from losing about 350k
messages today on one of our producer nodes. Its embedded broker's KahaDB
(5.4.2) started freaking out again with:
ERROR; Jan 23, 2011 13:22:33 PM; tid:BrokerService[localhost] Task;
AbstractStoreCursor - Failed to fill batch
java.io.IOException: Could not locate data file
/usr/local/mycompany/activemq-data/db-2426.log
at org.apache.kahadb.journal.Journal.getDataFile(Journal.java:345)
at org.apache.kahadb.journal.Journal.read(Journal.java:592)
at
org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:786)
at
org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:956)
at
org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$5.execute(KahaDBStore.java:494)
at org.apache.kahadb.page.Transaction.execute(Transaction.java:728)
at
org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.recoverNextMessages(KahaDBStore.java:485)
at
org.apache.activemq.store.ProxyMessageStore.recoverNextMessages(ProxyMessageStore.java:88)
at
org.apache.activemq.broker.region.cursors.QueueStorePrefetch.doFillBatch(QueueStorePrefetch.java:97)
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:262)
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
at
org.apache.activemq.broker.region.cursors.StoreQueueCursor.reset(StoreQueueCursor.java:157)
at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1678)
at
org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1898)
at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1425)
at
org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
at
org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
ERROR; Jan 23, 2011 13:22:33 PM; tid:BrokerService[localhost] Task;
AbstractStoreCursor - Failed to fill batch
java.lang.RuntimeException: java.io.IOException: Could not locate data file
/usr/local/mycompany/activemq-data/db-2426.log
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:265)
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
at
org.apache.activemq.broker.region.cursors.StoreQueueCursor.reset(StoreQueueCursor.java:157)
at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1678)
at
org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1898)
at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1425)
at
org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
at
org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.io.IOException: Could not locate data file
/usr/local/mycompany/activemq-data/db-2426.log
at org.apache.kahadb.journal.Journal.getDataFile(Journal.java:345)
at org.apache.kahadb.journal.Journal.read(Journal.java:592)
at
org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:786)
at
org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:956)
at
org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$5.execute(KahaDBStore.java:494)
at org.apache.kahadb.page.Transaction.execute(Transaction.java:728)
at
org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.recoverNextMessages(KahaDBStore.java:485)
at
org.apache.activemq.store.ProxyMessageStore.recoverNextMessages(ProxyMessageStore.java:88)
at
org.apache.activemq.broker.region.cursors.QueueStorePrefetch.doFillBatch(QueueStorePrefetch.java:97)
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:262)
... 10 more
ERROR; Jan 23, 2011 13:22:33 PM; tid:BrokerService[localhost] Task; Queue -
Failed to page in more queue messages
java.lang.RuntimeException: java.lang.RuntimeException: java.io.IOException:
Could not locate data file /usr/local/mycompany/activemq-data/db-2426.log
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:113)
at
org.apache.activemq.broker.region.cursors.StoreQueueCursor.reset(StoreQueueCursor.java:157)
at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1678)
at
org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1898)
at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1425)
at
org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
at
org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.RuntimeException: java.io.IOException: Could not locate
data file /usr/local/mycompany/activemq-data/db-2426.log
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:265)
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
... 9 more
Caused by: java.io.IOException: Could not locate data file
/usr/local/mycompany/activemq-data/db-2426.log
at org.apache.kahadb.journal.Journal.getDataFile(Journal.java:345)
at org.apache.kahadb.journal.Journal.read(Journal.java:592)
at
org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:786)
at
org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:956)
at
org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$5.execute(KahaDBStore.java:494)
at org.apache.kahadb.page.Transaction.execute(Transaction.java:728)
at
org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.recoverNextMessages(KahaDBStore.java:485)
at
org.apache.activemq.store.ProxyMessageStore.recoverNextMessages(ProxyMessageStore.java:88)
at
org.apache.activemq.broker.region.cursors.QueueStorePrefetch.doFillBatch(QueueStorePrefetch.java:97)
at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:262)
... 10 more
ERROR; Jan 23, 2011 13:22:33 PM; tid:BrokerService[localhost] Task; Journal -
Looking for key 2426 but not found in fileMap: {2443=db-2443.log number = 2443
, length = 33556647, 2442=db-2442.log number = 2442 , length = 33555394,
2441=db-2441.log number = 2441 , length = 33556656, 2440=db-2440.log number =
2440 , length = 33554618, 2444=db-2444.log number = 2444 , length = 31211881,
2435=db-2435.log number = 2435 , length = 33555525, 2434=db-2434.log number =
2434 , length = 33556971, 2433=db-2433.log number = 2433 , length = 33554878,
2432=db-2432.log number = 2432 , length = 33554516, 2439=db-2439.log number =
2439 , length = 33555167, 2438=db-2438.log number = 2438 , length = 33555794,
2437=db-2437.log number = 2437 , length = 33555470, 2436=db-2436.log number =
2436 , length = 33555079, 2335=db-2335.log number = 2335 , length = 33555466,
2334=db-2334.log number = 2334 , length = 33555013, 2333=db-2333.log number =
2333 , length = 33555566, 2336=db-2336.log number = 2336 , length = 33583503,
2337=db-2337.log number = 2337 , length = 33556154, 2338=db-2338.log number =
2338 , length = 33556881, 2339=db-2339.log number = 2339 , length = 33554898,
2340=db-2340.log number = 2340 , length = 33555842, 2341=db-2341.log number =
2341 , length = 33556432, 2342=db-2342.log number = 2342 , length = 33554605,
2429=db-2429.log number = 2429 , length = 33555998, 2428=db-2428.log number =
2428 , length = 33555914, 2431=db-2431.log number = 2431 , length = 33556386,
2430=db-2430.log number = 2430 , length = 33554851, 2427=db-2427.log number =
2427 , length = 33556238}
5.5 can't come quickly enough! :-)
> KahaDB error: "Could not locate data file"
> ------------------------------------------
>
> Key: AMQ-3120
> URL: https://issues.apache.org/jira/browse/AMQ-3120
> Project: ActiveMQ
> Issue Type: Bug
> Components: Broker
> Affects Versions: 5.4.2
> Environment: linux: CentOS 5.5
> happens on both dual- and quad-cpu boxes, 4gb ram
> java version "1.6.0_21"
> Java(TM) SE Runtime Environment (build 1.6.0_21-b06)
> Java HotSpot(TM) 64-Bit Server VM (build 17.0-b16, mixed mode)
> Reporter: Dan Checkoway
>
> I'm using an embedded broker (version 5.4.2) with persistence enabled. We're
> pumping hundreds of millions of messages per day through this thing. Every
> once in a while, all of a sudden the KahaDB directory starts growing
> uncontrollably, and these errors start spewing out in the log over and over...
> --------------------------
> ERROR; Jan 5, 2011 16:37:57 PM; tid:BrokerService[localhost] Task;
> AbstractStoreCursor - Failed to fill batch
> java.lang.RuntimeException: java.io.IOException: Could not locate data file
> /usr/local/embedded/activemq-data/localhost/KahaDB/db-28098.log
> at
> org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:265)
> at
> org.apache.activemq.broker.region.cursors.AbstractStoreCursor.hasNext(AbstractStoreCursor.java:148)
> at
> org.apache.activemq.broker.region.cursors.StoreQueueCursor.hasNext(StoreQueueCursor.java:131)
> at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1679)
> at
> org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1898)
> at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1425)
> at
> org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
> at
> org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:619)
> Caused by: java.io.IOException: Could not locate data file
> /usr/local/embedded/activemq-data/localhost/KahaDB/db-28098.log
> at org.apache.kahadb.journal.Journal.getDataFile(Journal.java:345)
> at org.apache.kahadb.journal.Journal.read(Journal.java:592)
> at
> org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:786)
> at
> org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:956)
> at
> org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$5.execute(KahaDBStore.java:494)
> at org.apache.kahadb.page.Transaction.execute(Transaction.java:728)
> at
> org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.recoverNextMessages(KahaDBStore.java:485)
> at
> org.apache.activemq.store.ProxyMessageStore.recoverNextMessages(ProxyMessageStore.java:88)
> at
> org.apache.activemq.broker.region.cursors.QueueStorePrefetch.doFillBatch(QueueStorePrefetch.java:97)
> at
> org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:262)
> ... 10 more
> ERROR; Jan 5, 2011 16:37:57 PM; tid:BrokerService[localhost] Task; Queue -
> Failed to page in more queue messages
> java.lang.RuntimeException: java.lang.RuntimeException: java.io.IOException:
> Could not locate data file
> /usr/local/embedded/activemq-data/localhost/KahaDB/db-28098.log
> at
> org.apache.activemq.broker.region.cursors.AbstractStoreCursor.hasNext(AbstractStoreCursor.java:151)
> at
> org.apache.activemq.broker.region.cursors.StoreQueueCursor.hasNext(StoreQueueCursor.java:131)
> at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1679)
> at
> org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1898)
> at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1425)
> at
> org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
> at
> org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:619)
> Caused by: java.lang.RuntimeException: java.io.IOException: Could not locate
> data file /usr/local/embedded/activemq-data/localhost/KahaDB/db-28098.log
> at
> org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:265)
> at
> org.apache.activemq.broker.region.cursors.AbstractStoreCursor.hasNext(AbstractStoreCursor.java:148)
> ... 9 more
> Caused by: java.io.IOException: Could not locate data file
> /usr/local/embedded/activemq-data/localhost/KahaDB/db-28098.log
> at org.apache.kahadb.journal.Journal.getDataFile(Journal.java:345)
> at org.apache.kahadb.journal.Journal.read(Journal.java:592)
> at
> org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:786)
> at
> org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:956)
> at
> org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$5.execute(KahaDBStore.java:494)
> at org.apache.kahadb.page.Transaction.execute(Transaction.java:728)
> at
> org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.recoverNextMessages(KahaDBStore.java:485)
> at
> org.apache.activemq.store.ProxyMessageStore.recoverNextMessages(ProxyMessageStore.java:88)
> at
> org.apache.activemq.broker.region.cursors.QueueStorePrefetch.doFillBatch(QueueStorePrefetch.java:97)
> at
> org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:262)
> ... 10 more
> --------------------------
> It doesn't happen consistently, but it has happened numerous times. The only
> way to "fix" it is to kill the app, blow away the KahaDB data directory, and
> restart (ugh).
> Unfortunately this issue is not reproduceable.
> Here's the embedded broker config, fwiw:
> --------------------------
> <broker xmlns="http://activemq.apache.org/schema/core"
> id="embeddedActivemqBroker"
> useJmx="false"
> persistent="true"
> dataDirectory="/usr/local/embedded/activemq-data"
> schedulerSupport="false"
> advisorySupport="false"
> enableStatistics="true">
> <destinationPolicy>
> <policyMap>
> <policyEntries>
> <policyEntry queue=">" producerFlowControl="false"
> memoryLimit="20mb"/>
> </policyEntries>
> </policyMap>
> </destinationPolicy>
> </broker>
> --------------------------
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.