activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Edwin Yu (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (AMQ-4051) IOException: Could not locate data file .\db-10.log
Date Wed, 17 Oct 2012 00:54:03 GMT

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

Edwin Yu commented on AMQ-4051:
-------------------------------

Hi Claudio,

Thanks for looking into this issue.  To answer your questions:

1) You can ignore carinaIOExceptionHandler for the purpose of this jira issue.  We needed
it because we need to cleanly shut down the JVM when the persistent directory is filled up,
or when the persistent directory is on a network drive that becomes unreachable.  I don't
think it's involved for this issue.

2) In our use case, there were two nodes, each of which embedded an ActiveMQ broker with persistent
storage.  A mule jms outbound connector heavily sent messages to a queue on the first node,
which defined a network connector that dynamically included the destination to a second node.
 A mule jms inbound connector on the second node listened to this queue.  This jms inbound
connector is the only consumer of this queue.  It permanently connected.  In the healthy operation,
this consumer was able to keep up consuming the incoming messages.  The queue size stayed
under 2 most of the time.  When this error occurred, messages from the first node were still
being delivered to the second node just fine.  It was the second node that complained about
the missing data file, and the queue size started increasing and the dequeue count stayed
flat.

3) The mule jms inbound connector used the vm protocol.  It was defined like below.
    <jms:activemq-connector
            name="jmsExternalConnector"
            specification="1.1"
            disableTemporaryReplyToDestinations="true"
            brokerURL="vm://xps-amq-broker_HPC-HAIFA-HAIFA-HAIFA"
            numberOfConsumers="1"
            maxRedelivery="1"
            persistentDelivery="true">
    </jms:activemq-connector>


4) We're planning to do upgrade to v5.7, but it'll take couple months before we roll out to
our performance lab to do load testing.  Plus, it may take few weeks of operation to see it
happen again.

Lastly, I still have the remaining journal data in the persistent folder from the error case.
 If they are useful for your investigation, I can try to upload to this jira issue.  It's
about 100MB in total.  They are named:

db.data
db.redo
db-11.log
db-12.log
db-13.log
lock

Thanks,
-Edwin
                
> IOException: Could not locate data file .\db-10.log
> ---------------------------------------------------
>
>                 Key: AMQ-4051
>                 URL: https://issues.apache.org/jira/browse/AMQ-4051
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.6.0
>         Environment: Windows Server 2008 R2, 8GB, Intel Core 2 Duo CPU 64 bit
> JDK 1.6.0_26, 64 bit
>            Reporter: Edwin Yu
>            Priority: Critical
>             Fix For: 5.8.0
>
>         Attachments: activemq.xml
>
>
> We're doing load testing on the ActiveMQ 5.6.0 broker-to-broker connection, pumping in
about 80,000 messages per hour into the queue.  One of the brokers stops dequeueing messages
to the consumer while its queue size increases.  The log contains repeating errors about "could
not locate the data file."
> We encountered this same issue couple weeks ago.  I found AMQ-3120 and added ignoreMissingJouralFiles="true"
like that issue suggested.  After many more days of testing, today we countered this same
problem again.  Our disk space is plenty.  The log is listed below.  I attached our activemq
configuration from the troubled broker to this issue.
> ------------------------------------------------------------------
> 2012-09-14 16:01:47,354 ERROR | BrokerService[xps-amq-broker_HPC-HAIFA-HAIFA-HAIFA] Task-18
| [Journal:352] Looking for key 10 but not found in fileMap: {11=db-11.log number = 11 , length
= 499163}
> 2012-09-14 16:01:47,354 ERROR | BrokerService[xps-amq-broker_HPC-HAIFA-HAIFA-HAIFA] Task-18
| [AbstractStoreCursor:279] org.apache.activemq.broker.region.cursors.QueueStorePrefetch@5fae7502:n4.HPC/HAIFA/HAIFA/HAIFA,batchResetNeeded=false,storeHasMessages=true,size=100,cacheEnabled=false
- Failed to fill batch
> java.io.IOException: Could not locate data file .\esb\amq_N4-PERFORM70\db-10.log
> 	at org.apache.kahadb.journal.Journal.getDataFile(Journal.java:353)
> 	at org.apache.kahadb.journal.Journal.read(Journal.java:600)
> 	at org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:924)
> 	at org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:1015)
> 	at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$4.execute(KahaDBStore.java:556)
> 	at org.apache.kahadb.page.Transaction.execute(Transaction.java:769)
> 	at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.recoverNextMessages(KahaDBStore.java:545)
> 	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:277)
> 	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:1766)
> 	at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1995)
> 	at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1488)
> 	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:662)
> 2012-09-14 16:01:47,354 ERROR | BrokerService[xps-amq-broker_HPC-HAIFA-HAIFA-HAIFA] Task-18
| [AbstractStoreCursor:115] org.apache.activemq.broker.region.cursors.QueueStorePrefetch@5fae7502:n4.HPC/HAIFA/HAIFA/HAIFA,batchResetNeeded=false,storeHasMessages=true,size=100,cacheEnabled=false
- Failed to fill batch
> java.lang.RuntimeException: java.io.IOException: Could not locate data file .\esb\amq_N4-PERFORM70\db-10.log
> 	at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:280)
> 	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:1766)
> 	at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1995)
> 	at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1488)
> 	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:662)
> Caused by: java.io.IOException: Could not locate data file .\esb\amq_N4-PERFORM70\db-10.log
> 	at org.apache.kahadb.journal.Journal.getDataFile(Journal.java:353)
> 	at org.apache.kahadb.journal.Journal.read(Journal.java:600)
> 	at org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:924)
> 	at org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:1015)
> 	at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$4.execute(KahaDBStore.java:556)
> 	at org.apache.kahadb.page.Transaction.execute(Transaction.java:769)
> 	at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.recoverNextMessages(KahaDBStore.java:545)
> 	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:277)
> 	... 10 more
> 2012-09-14 16:01:47,354 ERROR | BrokerService[xps-amq-broker_HPC-HAIFA-HAIFA-HAIFA] Task-18
| [Queue:1491] Failed to page in more queue messages 
> java.lang.RuntimeException: java.lang.RuntimeException: java.io.IOException: Could not
locate data file .\esb\amq_N4-PERFORM70\db-10.log
> 	at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:116)
> 	at org.apache.activemq.broker.region.cursors.StoreQueueCursor.reset(StoreQueueCursor.java:157)
> 	at org.apache.activemq.broker.region.Queue.doPageInForDispatch(Queue.java:1766)
> 	at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1995)
> 	at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1488)
> 	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:662)
> Caused by: java.lang.RuntimeException: java.io.IOException: Could not locate data file
.\esb\amq_N4-PERFORM70\db-10.log
> 	at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:280)
> 	at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:113)
> 	... 9 more
> Caused by: java.io.IOException: Could not locate data file .\esb\amq_N4-PERFORM70\db-10.log
> 	at org.apache.kahadb.journal.Journal.getDataFile(Journal.java:353)
> 	at org.apache.kahadb.journal.Journal.read(Journal.java:600)
> 	at org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:924)
> 	at org.apache.activemq.store.kahadb.KahaDBStore.loadMessage(KahaDBStore.java:1015)
> 	at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore$4.execute(KahaDBStore.java:556)
> 	at org.apache.kahadb.page.Transaction.execute(Transaction.java:769)
> 	at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.recoverNextMessages(KahaDBStore.java:545)
> 	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:277)
> 	... 10 more
> 2012-09-14 16:01:47,354 INFO  | ActiveMQ Session Task-26 | [LogComponent:41] 
> --------------------------------------------------------------------------

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message