activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Anton Goncharov (JIRA)" <j...@apache.org>
Subject [jira] [Created] (AMQ-5048) Unexpected message redelivery after KahaDB metadata recovery
Date Thu, 13 Feb 2014 07:12:19 GMT
Anton Goncharov created AMQ-5048:
------------------------------------

             Summary: 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


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)

Mime
View raw message