activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Gary Tully (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (AMQ-3470) Unable to pick up messages anymore, messages are lost - Looking for key xyz but not found in fileMap
Date Wed, 24 Aug 2011 12:11:29 GMT

    [ https://issues.apache.org/jira/browse/AMQ-3470?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13090157#comment-13090157
] 

Gary Tully commented on AMQ-3470:
---------------------------------

Thanks for the detail. We (dejanb and I) had a chat about this issue earlier and may have
found the root cause. If our thoughts are correct, disabling the cache, via xml configuration,
should work around the issue till we get a fix.
{code}<destinationPolicy>
      <policyMap>
        <policyEntries>
          <policyEntry queue=">"  useCache="false" />
        </policyEntries>
      </policyMap>
 </destinationPolicy>{code}

> 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

        

Mime
View raw message