You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by "Frank Gynnild (JIRA)" <ji...@apache.org> on 2011/08/24 13:53:29 UTC
[jira] [Updated] (AMQ-3470) Unable to pick up messages anymore,
messages are lost - Looking for key xyz but not found in fileMap
[ https://issues.apache.org/jira/browse/AMQ-3470?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Frank Gynnild updated AMQ-3470:
-------------------------------
Affects Version/s: 5.5.0
> Unable to pick up messages anymore, messages are lost - Looking for key xyz but not found in fileMap
> ----------------------------------------------------------------------------------------------------
>
> Key: AMQ-3470
> URL: https://issues.apache.org/jira/browse/AMQ-3470
> Project: ActiveMQ
> Issue Type: Bug
> Affects Versions: 5.5.0
> Environment: Used from .NET 4.0
> Apache.NMS.ActiveMQ.dll - 1.5.1.2341
> Apache.NMS.dll - 1.5.0.2194
> ActiveMQ - 5.5.0
> Reporter: Frank Gynnild
> Priority: Blocker
>
> We've a C# test client that constantly produces and consumes messages of various sizes.
> After successfully sending and receiving about 5.5 million messages, ActiveMQ enters
> a certain state where:
> - No more messages in the queue cannot be dequeued/received.
> - Looking at the ActiveMQ browser, we're no longer able to see the message.
> - The logs get filled up and rotate at a crazy pace.
> - We aren't able to recover after this, restarting the ActiveMQ doesn't help.
> We haven't been able to consistently reproduce this behavior, it can happen after
> any numbers of messages (usually after some million messages). Last it took about 8
> hours before we could come into this stage.
> The tests are very basic.
> I've been able to catch the log when this happens:
> ---
> 2011-08-22 11:13:50,919 | INFO | Refreshing org.apache.activemq.xbean.XBeanBrokerFactory$1@3479e304: startup date [Mon Aug 22 11:13:50 CEST 2011]; root of context hierarchy | org.apache.activemq.xbean.XBeanBrokerFactory$1 | main
> 2011-08-22 11:13:54,638 | WARN | destroyApplicationContextOnStop parameter is deprecated, please use shutdown hooks instead | org.apache.activemq.xbean.XBeanBrokerService | main
> 2011-08-22 11:13:54,645 | INFO | PListStore:C:\ActiveMQ\data\IES_CARMINE\tmp_storage started | org.apache.activemq.store.kahadb.plist.PListStore | main
> 2011-08-22 11:13:54,723 | INFO | Using Persistence Adapter: KahaDBPersistenceAdapter[C:\ActiveMQ\data\kahadb] | org.apache.activemq.broker.BrokerService | main
> 2011-08-22 11:13:54,932 | INFO | ActiveMQ 5.5.0 JMS Message Broker (IES_CARMINE) is starting | org.apache.activemq.broker.BrokerService | main
> 2011-08-22 11:13:54,933 | INFO | For help or more information please see: http://activemq.apache.org/ | org.apache.activemq.broker.BrokerService | main
> 2011-08-22 11:13:55,224 | INFO | Listening for connections at: tcp://Carmine:61616?keepAlive=true&wireFormat.tightEncodingEnabled=false&wireFormat.cacheEnabled=false | org.apache.activemq.transport.TransportServerThreadSupport | main
> 2011-08-22 11:13:55,226 | INFO | Connector openwire Started | org.apache.activemq.broker.TransportConnector | main
> 2011-08-22 11:13:55,233 | INFO | ActiveMQ JMS Message Broker (IES_CARMINE, ID:Carmine-60118-1314004434990-0:1) started | org.apache.activemq.broker.BrokerService | main
> 2011-08-22 11:13:55,390 | INFO | jetty-7.1.6.v20100715 | org.eclipse.jetty.util.log | main
> 2011-08-22 11:13:56,043 | INFO | ActiveMQ WebConsole initialized. | org.apache.activemq.web.WebConsoleStarter | main
> 2011-08-22 11:13:56,367 | INFO | Initializing Spring FrameworkServlet 'dispatcher' | /admin | main
> 2011-08-22 11:13:56,807 | INFO | ActiveMQ Console at http://0.0.0.0:8161/admin | org.eclipse.jetty.util.log | main
> 2011-08-22 11:13:56,852 | INFO | WebApp@280236390 at http://0.0.0.0:8161/console | org.eclipse.jetty.util.log | main
> 2011-08-22 11:13:56,876 | INFO | Started SelectChannelConnector@0.0.0.0:8161 | org.eclipse.jetty.util.log | main
> 2011-08-23 19:45:41,881 | ERROR | Looking for key 11856 but not found in fileMap: {11857=db-11857.log number = 11857 , length = 1949} | org.apache.kahadb.journal.Journal | Queue:TestQueue
> 2011-08-23 19:45:41,935 | ERROR | QueueStorePrefetch314000409 - Failed to fill batch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | Queue:TestQueue
> java.io.IOException: Could not locate data file C:\ActiveMQ\data\kahadb\db-11856.log
> at org.apache.kahadb.journal.Journal.getDataFile(Journal.java:350)
> at org.apache.kahadb.journal.Journal.read(Journal.java:597)
> at org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:817)
> at org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:955)
> at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$5.execute(KahaDBStore.java:493)
> 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:260)
> at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:108)
> at org.apache.activemq.broker.region.cursors.StoreQueueCursor.reset(StoreQueueCursor.java:157)
> at org.apache.activemq.broker.region.Queue.doPageInForDispatch(Queue.java:1712)
> at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1932)
> at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1440)
> at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104)
> at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
> 2011-08-23 19:45:41,939 | ERROR | QueueStorePrefetch314000409 - Failed to fill batch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | Queue:TestQueue
> java.lang.RuntimeException: java.io.IOException: Could not locate data file C:\ActiveMQ\data\kahadb\db-11856.log
> at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:263)
> at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:108)
> at org.apache.activemq.broker.region.cursors.StoreQueueCursor.reset(StoreQueueCursor.java:157)
> at org.apache.activemq.broker.region.Queue.doPageInForDispatch(Queue.java:1712)
> at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1932)
> at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1440)
> at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104)
> at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
> Caused by: java.io.IOException: Could not locate data file C:\ActiveMQ\data\kahadb\db-11856.log
> at org.apache.kahadb.journal.Journal.getDataFile(Journal.java:350)
> at org.apache.kahadb.journal.Journal.read(Journal.java:597)
> at org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:817)
> at org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:955)
> at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$5.execute(KahaDBStore.java:493)
> 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:260)
> ... 7 more
> 2011-08-23 19:45:41,940 | ERROR | Failed to page in more queue messages | org.apache.activemq.broker.region.Queue | Queue:TestQueue
> java.lang.RuntimeException: java.lang.RuntimeException: java.io.IOException: Could not locate data file C:\ActiveMQ\data\kahadb\db-11856.log
> at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:111)
> at org.apache.activemq.broker.region.cursors.StoreQueueCursor.reset(StoreQueueCursor.java:157)
> at org.apache.activemq.broker.region.Queue.doPageInForDispatch(Queue.java:1712)
> at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1932)
> at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1440)
> at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104)
> at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
> Caused by: java.lang.RuntimeException: java.io.IOException: Could not locate data file C:\ActiveMQ\data\kahadb\db-11856.log
> at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:263)
> at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:108)
> ... 6 more
> Caused by: java.io.IOException: Could not locate data file C:\ActiveMQ\data\kahadb\db-11856.log
> at org.apache.kahadb.journal.Journal.getDataFile(Journal.java:350)
> at org.apache.kahadb.journal.Journal.read(Journal.java:597)
> at org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:817)
> at org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:955)
> at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$5.execute(KahaDBStore.java:493)
> 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:260)
> ... 7 more
> 2011-08-23 19:45:41,942 | ERROR | Looking for key 11856 but not found in fileMap: {11857=db-11857.log number = 11857 , length = 19540} | org.apache.kahadb.journal.Journal | Queue:TestQueue
> 2011-08-23 19:45:41,943 | ERROR | QueueStorePrefetch314000409 - Failed to fill batch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | Queue:TestQueue
> java.io.IOException: Could not locate data file C:\ActiveMQ\data\kahadb\db-11856.log
> at org.apache.kahadb.journal.Journal.getDataFile(Journal.java:350)
> at org.apache.kahadb.journal.Journal.read(Journal.java:597)
> at org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:817)
> at org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:955)
> at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$5.execute(KahaDBStore.java:493)
> 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:260)
> at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:108)
> at org.apache.activemq.broker.region.cursors.StoreQueueCursor.reset(StoreQueueCursor.java:157)
> at org.apache.activemq.broker.region.Queue.doPageInForDispatch(Queue.java:1712)
> at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1932)
> at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1440)
> at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104)
> at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
> 2011-08-23 19:45:41,944 | ERROR | QueueStorePrefetch314000409 - Failed to fill batch | org.apache.activemq.broker.region.cursors.AbstractStoreCursor | Queue:TestQueue
> java.lang.RuntimeException: java.io.IOException: Could not locate data file C:\ActiveMQ\data\kahadb\db-11856.log
> at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:263)
> at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:108)
> at org.apache.activemq.broker.region.cursors.StoreQueueCursor.reset(StoreQueueCursor.java:157)
> at org.apache.activemq.broker.region.Queue.doPageInForDispatch(Queue.java:1712)
> at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1932)
> at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1440)
> at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104)
> at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
> Caused by: java.io.IOException: Could not locate data file C:\ActiveMQ\data\kahadb\db-11856.log
> at org.apache.kahadb.journal.Journal.getDataFile(Journal.java:350)
> at org.apache.kahadb.journal.Journal.read(Journal.java:597)
> at org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:817)
> at org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:955)
> at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$5.execute(KahaDBStore.java:493)
> 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:260)
> ... 7 more
> 2011-08-23 19:45:41,945 | ERROR | Failed to page in more queue messages | org.apache.activemq.broker.region.Queue | Queue:TestQueue
> java.lang.RuntimeException: java.lang.RuntimeException: java.io.IOException: Could not locate data file C:\ActiveMQ\data\kahadb\db-11856.log
> at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:111)
> at org.apache.activemq.broker.region.cursors.StoreQueueCursor.reset(StoreQueueCursor.java:157)
> at org.apache.activemq.broker.region.Queue.doPageInForDispatch(Queue.java:1712)
> at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1932)
> at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1440)
> at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:104)
> at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:42)
> Caused by: java.lang.RuntimeException: java.io.IOException: Could not locate data file C:\ActiveMQ\data\kahadb\db-11856.log
> at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:263)
> at org.apa
> ---
> The logs repeat in an endless matter.
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira