Return-Path: Delivered-To: apmail-activemq-dev-archive@www.apache.org Received: (qmail 24899 invoked from network); 12 Jun 2008 16:02:52 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (140.211.11.2) by minotaur.apache.org with SMTP; 12 Jun 2008 16:02:52 -0000 Received: (qmail 38557 invoked by uid 500); 12 Jun 2008 16:02:54 -0000 Delivered-To: apmail-activemq-dev-archive@activemq.apache.org Received: (qmail 38533 invoked by uid 500); 12 Jun 2008 16:02:54 -0000 Mailing-List: contact dev-help@activemq.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@activemq.apache.org Delivered-To: mailing list dev@activemq.apache.org Received: (qmail 38522 invoked by uid 99); 12 Jun 2008 16:02:54 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 12 Jun 2008 09:02:54 -0700 X-ASF-Spam-Status: No, hits=-2000.0 required=10.0 tests=ALL_TRUSTED X-Spam-Check-By: apache.org Received: from [140.211.11.140] (HELO brutus.apache.org) (140.211.11.140) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 12 Jun 2008 16:02:13 +0000 Received: from brutus (localhost [127.0.0.1]) by brutus.apache.org (Postfix) with ESMTP id 63DA6234C139 for ; Thu, 12 Jun 2008 09:02:00 -0700 (PDT) Message-ID: <1928843713.1213286520402.JavaMail.jira@brutus> Date: Thu, 12 Jun 2008 09:02:00 -0700 (PDT) From: "Gary Tully (JIRA)" To: dev@activemq.apache.org Subject: [jira] Reopened: (AMQ-1795) in use data files removed from data store under load In-Reply-To: <2057499699.1213280040360.JavaMail.jira@brutus> MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 7bit X-Virus-Checked: Checked by ClamAV on apache.org [ https://issues.apache.org/activemq/browse/AMQ-1795?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ] Gary Tully reopened AMQ-1795: ----------------------------- still needs work > in use data files removed from data store under load > ---------------------------------------------------- > > Key: AMQ-1795 > URL: https://issues.apache.org/activemq/browse/AMQ-1795 > Project: ActiveMQ > Issue Type: Bug > Affects Versions: 5.1.0 > Environment: all > Reporter: Gary Tully > Assignee: Rob Davies > Fix For: 5.2.0 > > Attachments: AMQ-1795.test_and_partial_fix > > > Under load, I see the error below. > the problem is that org.apache.activemq.store.amq.AMQPersistenceAdapter.cleanup() does not capture all of the in use files. > I have made some changes that improves the situation but there is still a window, that seems to be related to spooling messages when a memory limit is reached. > 2008-06-12 14:55:16,689 [main ] INFO BrokerService - Using Persistence Adapter: AMQPersistenceAdapter(activemq-data\localhost) > 2008-06-12 14:55:16,704 [main ] INFO AMQPersistenceAdapter - AMQStore starting using directory: activemq-data\localhost > 2008-06-12 14:55:17,361 [main ] INFO AMQPersistenceAdapter - Journal deleted: > 2008-06-12 14:55:17,361 [main ] INFO KahaStore - Kaha Store successfully deleted data directory activemq-data\localhost\kr-store\data > 2008-06-12 14:55:17,392 [main ] INFO KahaStore - Kaha Store successfully deleted data directory activemq-data\localhost\kr-store\state > 2008-06-12 14:55:17,392 [main ] INFO KahaStore - Kaha Store using data directory activemq-data\localhost\kr-store\state > 2008-06-12 14:55:17,470 [main ] INFO AMQPersistenceAdapter - Active data files: [] > 2008-06-12 14:55:17,705 [main ] INFO BrokerService - ActiveMQ null JMS Message Broker (localhost) is starting > 2008-06-12 14:55:17,705 [main ] INFO BrokerService - For help or more information please see: http://activemq.apache.org/ > 2008-06-12 14:55:17,814 [JMX connector ] INFO ManagementContext - JMX consoles can connect to service:jmx:rmi:///jndi/rmi://localhost:1099/jmxrmi > 2008-06-12 14:55:17,924 [main ] INFO KahaStore - Kaha Store using data directory activemq-data\localhost\kr-store\data > 2008-06-12 14:55:17,939 [main ] INFO TransportServerThreadSupport - Listening for connections at: tcp://salthill:61616 > 2008-06-12 14:55:17,939 [main ] INFO TransportConnector - Connector Default Started > 2008-06-12 14:55:17,939 [main ] INFO BrokerService - ActiveMQ JMS Message Broker (localhost, ID:salthill-2790-1213278917752-0:0) started > 2008-06-12 14:55:17,939 [main ] INFO MissingDataFileTest - Starting broker.. > 2008-06-12 14:55:58,516 [age Thread Pool] ERROR AsyncDataManager - Looking for key 551 but not found in fileMap: {1014=data-1014 number = 1014 , length = 1960 refCount = 6, 607=data-607 number = 607 , length = 1266 refCount = 1, 928=data-928 number = 928 , .. .. 622 , length = 1352 refCount = 2, 328=data-328 number = 328 , length = 1266 refCount = 1, 256=data-256 number = 256 , length = 1264 refCount = 1, 92=data-92 number = 92 , length = 1264 refCount = 1, 404=data-404 number = 404 , length = 1266 refCount = 1} > 2008-06-12 14:55:58,563 [age Thread Pool] ERROR AbstractStoreCursor - Failed to fill batch > java.io.IOException: Failed to read to journal for: offset = 0, file = 551, size = -1, type = 0. Reason: java.io.IOException: Could not locate data file data--551 > at org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:33) > at org.apache.activemq.store.amq.AMQPersistenceAdapter.createReadException(AMQPersistenceAdapter.java:635) > at org.apache.activemq.store.amq.AMQPersistenceAdapter.readCommand(AMQPersistenceAdapter.java:521) > at org.apache.activemq.store.amq.AMQMessageStore.getMessage(AMQMessageStore.java:432) > at org.apache.activemq.store.amq.RecoveryListenerAdapter.recoverMessageReference(RecoveryListenerAdapter.java:54) > at org.apache.activemq.store.kahadaptor.KahaReferenceStore.recoverReference(KahaReferenceStore.java:82) > at org.apache.activemq.store.kahadaptor.KahaReferenceStore.recoverNextMessages(KahaReferenceStore.java:120) > at org.apache.activemq.store.amq.AMQMessageStore.recoverNextMessages(AMQMessageStore.java:530) > at org.apache.activemq.broker.region.cursors.QueueStorePrefetch.doFillBatch(QueueStorePrefetch.java:75) > at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:188) > at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.onUsageChanged(AbstractStoreCursor.java:157) > at org.apache.activemq.usage.Usage$1.run(Usage.java:266) > at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675) > at java.lang.Thread.run(Thread.java:595) > Caused by: java.io.IOException: Could not locate data file data--551 > at org.apache.activemq.kaha.impl.async.AsyncDataManager.getDataFile(AsyncDataManager.java:303) > at org.apache.activemq.kaha.impl.async.AsyncDataManager.read(AsyncDataManager.java:613) > at org.apache.activemq.store.amq.AMQPersistenceAdapter.readCommand(AMQPersistenceAdapter.java:518) > ... 12 more > 2008-06-12 14:55:58,563 [age Thread Pool] ERROR AbstractStoreCursor - Failed to fill batch > java.lang.RuntimeException: java.io.IOException: Failed to read to journal for: offset = 0, file = 551, size = -1, type = 0. Reason: java.io.IOException: Could not locate data file data--551 > at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:191) > at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.onUsageChanged(AbstractStoreCursor.java:157) > at org.apache.activemq.usage.Usage$1.run(Usage.java:266) > at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675) > at java.lang.Thread.run(Thread.java:595) > Caused by: java.io.IOException: Failed to read to journal for: offset = 0, file = 551, size = -1, type = 0. Reason: java.io.IOException: Could not locate data file data--551 > at org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:33) > at org.apache.activemq.store.amq.AMQPersistenceAdapter.createReadException(AMQPersistenceAdapter.java:635) > at org.apache.activemq.store.amq.AMQPersistenceAdapter.readCommand(AMQPersistenceAdapter.java:521) > at org.apache.activemq.store.amq.AMQMessageStore.getMessage(AMQMessageStore.java:432) > at org.apache.activemq.store.amq.RecoveryListenerAdapter.recoverMessageReference(RecoveryListenerAdapter.java:54) > at org.apache.activemq.store.kahadaptor.KahaReferenceStore.recoverReference(KahaReferenceStore.java:82) > at org.apache.activemq.store.kahadaptor.KahaReferenceStore.recoverNextMessages(KahaReferenceStore.java:120) > at org.apache.activemq.store.amq.AMQMessageStore.recoverNextMessages(AMQMessageStore.java:530) > at org.apache.activemq.broker.region.cursors.QueueStorePrefetch.doFillBatch(QueueStorePrefetch.java:75) > at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:188) > ... 5 more > Caused by: java.io.IOException: Could not locate data file data--551 > at org.apache.activemq.kaha.impl.async.AsyncDataManager.getDataFile(AsyncDataManager.java:303) > at org.apache.activemq.kaha.impl.async.AsyncDataManager.read(AsyncDataManager.java:613) > at org.apache.activemq.store.amq.AMQPersistenceAdapter.readCommand(AMQPersistenceAdapter.java:518) > ... 12 more > 2008-06-12 15:00:18,531 [main ] INFO BrokerService - ActiveMQ Message Broker (localhost, ID:salthill-2790-1213278917752-0:0) is shutting down > 2008-06-12 15:00:20,438 [main ] INFO TransportConnector - Connector Default Stopped > 2008-06-12 15:00:20,641 [main ] INFO BrokerService - ActiveMQ JMS Message Broker (localhost, ID:salthill-2790-1213278917752-0:0) stopped -- This message is automatically generated by JIRA. - You can reply to this email to add a comment to the issue online.