You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by "Maxim Gurin (JIRA)" <ji...@apache.org> on 2014/02/13 10:21:19 UTC

[jira] [Issue Comment Deleted] (AMQ-5048) Unexpected message redelivery after KahaDB metadata recovery

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

Maxim Gurin updated AMQ-5048:
-----------------------------

    Comment: was deleted

(was: same shit, bro)

> Unexpected message redelivery after KahaDB metadata recovery
> ------------------------------------------------------------
>
>                 Key: AMQ-5048
>                 URL: https://issues.apache.org/jira/browse/AMQ-5048
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker, Message Store
>    Affects Versions: 5.8.0
>         Environment: Linux version 2.6.18-274.7.1.el5 (mockbuild@builder10.centos.org) (gcc version 4.1.2 20080704 (Red Hat 4.1.2-51)) #1 SMP Thu Oct 20 16:21:01 EDT 2011
> Java(TM) SE Runtime Environment (build 1.6.0_45-b06)
> Java HotSpot(TM) 64-Bit Server VM (build 20.45-b01, mixed mode)
>            Reporter: Anton Goncharov
>              Labels: newbie
>
> It was an accident when our system ran out of free disk space. ActiveMQ broker was shut down but after disk clean it failed to start with throwing an exception:
> 2014-01-31 07:59:46,297 | ERROR | Failed to page in more queue messages  | org.apache.activemq.broker.region.Queue | ActiveMQ BrokerService[CORE_FuseMQ] Task-149
> java.lang.RuntimeException: java.lang.RuntimeException: java.io.IOException: Could not locate data file /opt/broker/data/kahadb/db-97203.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.doPageInForDispatch(Queue.java:1775)
>         at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:2003)
>         at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1491)
>         at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:129)
>         at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:47)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
>         at java.lang.Thread.run(Thread.java:662)st
> Caused by: java.lang.RuntimeException: java.io.IOException: Could not locate data file /opt/broker/data/kahadb/db-97203.log
>         at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:277)
>         at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
>         ... 9 more
> Caused by: java.io.IOException: Could not locate data file /opt/broker/data/kahadb/db-97203.log
>         at org.apache.activemq.store.kahadb.disk.journal.Journal.getDataFile(Journal.java:353)
>         at org.apache.activemq.store.kahadb.disk.journal.Journal.read(Journal.java:600)
>         at org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:939)
>         at org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:1029)
>         at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$4.execute(KahaDBStore.java:557)
>         at org.apache.activemq.store.kahadb.disk.page.Transaction.execute(Transaction.java:779)
>         at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.recoverNextMessages(KahaDBStore.java:546)
>         at org.apache.activemq.store.ProxyMessageStore.recoverNextMessages(ProxyMessageStore.java:106)
>         at org.apache.activemq.broker.region.cursors.QueueStorePrefetch.doFillBatch(QueueStorePrefetch.java:97)
>         at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:274)
>         ... 10 more
> 2014-01-31 07:59:47,305 | ERROR | Looking for key 97203 but not found in fileMap: {55354=db-55354.log number = 55354 , length = 33563112, 93728=db-93728.log number = 93728 , length = 33554796, 9373
> 2014-01-31 07:59:47,307 | ERROR | org.apache.activemq.broker.region.cursors.QueueStorePrefetch@3a252a17:mdm.kis,batchResetNeeded=false,storeHasMessages=true,size=157,cacheEnabled=false,maxBatchSize
> java.io.IOException: Could not locate data file /opt/broker/data/kahadb/db-97203.log
>         at org.apache.activemq.store.kahadb.disk.journal.Journal.getDataFile(Journal.java:353)
>         at org.apache.activemq.store.kahadb.disk.journal.Journal.read(Journal.java:600)
>         at org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:939)
>         at org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:1029)
>         at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$4.execute(KahaDBStore.java:557)
>         at org.apache.activemq.store.kahadb.disk.page.Transaction.execute(Transaction.java:779)
>         at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.recoverNextMessages(KahaDBStore.java:546)
>         at org.apache.activemq.store.ProxyMessageStore.recoverNextMessages(ProxyMessageStore.java:106)
>         at org.apache.activemq.broker.region.cursors.QueueStorePrefetch.doFillBatch(QueueStorePrefetch.java:97)
>         at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:274)
>         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.doPageInForDispatch(Queue.java:1775)
>         at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:2003)
>         at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1491)
>         at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:129)
>         at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:47)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
> [...]
> We rebuilt metadata as described here: https://access.redhat.com/site/documentation/en-US/Fuse_MQ_Enterprise/7.1/html/Configuring_Broker_Persistence/files/KahaDB-Recovery.html 
> Performed steps to rebuild:
> 1. Stop broker
> 2. Delete db.data
> 3. Start broker
> Afterwards broker started correctly without exceptions. Problem is that some new messages appeared in queues. Those queues had zero messages before metadata recovery. Appeared messages were quite outdated and already delivered several months ago. This is dangerous behaviour because unexpected redelivery in some cases may bring harm to consumers. 



--
This message was sent by Atlassian JIRA
(v6.1.5#6160)