Return-Path: X-Original-To: apmail-activemq-dev-archive@www.apache.org Delivered-To: apmail-activemq-dev-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id D5ED31098F for ; Thu, 18 Dec 2014 22:47:19 +0000 (UTC) Received: (qmail 30780 invoked by uid 500); 18 Dec 2014 22:47:19 -0000 Delivered-To: apmail-activemq-dev-archive@activemq.apache.org Received: (qmail 30605 invoked by uid 500); 18 Dec 2014 22:47:19 -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 30518 invoked by uid 99); 18 Dec 2014 22:47:19 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 18 Dec 2014 22:47:19 +0000 Date: Thu, 18 Dec 2014 22:47:19 +0000 (UTC) From: "Kevin Burton (JIRA)" To: dev@activemq.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (AMQ-5300) Inifinite loop when attempting to replay levelDB logs to rebuild index MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/AMQ-5300?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14252456#comment-14252456 ] Kevin Burton commented on AMQ-5300: ----------------------------------- I'm having similar issues with corruption in AMQ. could you upload your code for testing? I can then test it to see if I have similar behavior. I may be wrong I think your problem is that it CAN NOT recover in your situation because the log has been deleted and it has no index to start from. It should print a better message though. > Inifinite loop when attempting to replay levelDB logs to rebuild index > ---------------------------------------------------------------------- > > Key: AMQ-5300 > URL: https://issues.apache.org/jira/browse/AMQ-5300 > Project: ActiveMQ > Issue Type: Bug > Components: activemq-leveldb-store > Affects Versions: 5.9.1, 5.10.0 > Environment: Linux > Reporter: Vu Le > > While searching for a workaround for issue AMQ-5284, I came across this issue. > To work around the serialization issue (AMQ-5284), I deleted the index snapshots from the LevelDB datastore. This will replay the logs to regenerate the index. However, if a log rotation has already occurred, you will get an infinite loop upon restart. > Here are the steps to reproduce what I am seeing: > Configure ActiveMQ 5.10.0 to use a LevelDB data store with the log size of about 1MB. > {code} > > > > {code} > Then I started up the broker and published 10,000 persistent messages to a queue, causing the log files to rotate (twice in my case). I see the following files in the data store folder: > {code} > -rw-rw-r--. 1 user users 1000071 Jul 30 11:15 0000000000000000.log > -rw-rw-r--. 1 user users 1000009 Jul 30 11:16 00000000000f4287.log > drwxrwxr-x. 2 user users 4096 Jul 30 11:16 00000000001e84d0.index > -rw-rw-r--. 1 user users 1000000 Jul 30 11:17 00000000001e84d0.log > drwxrwxr-x. 2 user users 4096 Jul 30 11:11 dirty.index > -rw-rw-r--. 1 user users 0 Jul 30 11:11 lock > drwxrwxr-x. 2 user users 4096 Jul 30 11:11 plist.index > -rw-rw-r--. 1 user users 24 Jul 30 11:11 store-version.txt > {code} > I then consume 5,000 messages, which causes the first log to be deleted since it is no longer being referenced. I see the following log statements: > {code} > 2014-07-30 11:29:14,960 | DEBUG | Log no longer referenced: 0 | org.apache.activemq.leveldb.LevelDBClient | Thread-2 > 2014-07-30 11:29:14,967 | DEBUG | Deleting log at 0 | org.apache.activemq.leveldb.LevelDBClient | Thread-2 > {code} > And I see the remaining files in the data store folder (notice the 0000000000000000.log is gone): > {code} > -rw-rw-r--. 1 user users 1000009 Jul 30 11:16 00000000000f4287.log > -rw-rw-r--. 1 user users 1000011 Jul 30 11:29 00000000001e84d0.log > drwxrwxr-x. 2 user users 4096 Jul 30 11:29 00000000002dc71b.index > -rw-rw-r--. 1 user users 1000000 Jul 30 11:29 00000000002dc71b.log > drwxrwxr-x. 2 user users 4096 Jul 30 11:11 dirty.index > -rw-rw-r--. 1 user users 0 Jul 30 11:11 lock > drwxrwxr-x. 2 user users 4096 Jul 30 11:11 plist.index > -rw-rw-r--. 1 user users 24 Jul 30 11:11 store-version.txt > {code} > At this point, I shut down the broker and here is the listing of what's left in the data store: > {code} > -rw-rw-r--. 1 user users 1000009 Jul 30 11:16 00000000000f4287.log > -rw-rw-r--. 1 user users 1000011 Jul 30 11:29 00000000001e84d0.log > -rw-rw-r--. 1 user users 1000000 Jul 30 11:29 00000000002dc71b.log > drwxrwxr-x. 2 user users 4096 Jul 30 11:36 0000000000301737.index > drwxrwxr-x. 2 user users 4096 Jul 30 11:11 dirty.index > drwxrwxr-x. 2 user users 4096 Jul 30 11:11 plist.index > -rw-rw-r--. 1 user users 24 Jul 30 11:11 store-version.txt > {code} > I then delete the index folder within the data store (in my case "0000000000301737.index"). I am doing this to force a replay of the logs to regenerate the index (due to the serialization issue I ran into). > And finally, this is the message I am getting once I start the broker back up (infinite loop of this same message, and I have to shut down the broker): > {code} > 2014-07-30 11:40:27,415 | WARN | No reader available for position: 0, log_infos: {1000071=LogInfo(/home/user/apache-activemq-5.10.0/data/leveldb/00000000000f4287.log,1000071,1000009), 2000080=LogInfo(/home/user/apache-activemq-5.10.0/data/leveldb/00000000001e84d0.log,2000080,1000011), 3000091=LogInfo(/home/user/apache-activemq-5.10.0/data/leveldb/00000000002dc71b.log,3000091,0)} | org.apache.activemq.leveldb.RecordLog | main > {code} -- This message was sent by Atlassian JIRA (v6.3.4#6332)