Uploaded image for project: 'ActiveMQ'
  1. ActiveMQ
  2. AMQ-5300

Inifinite loop when attempting to replay levelDB logs to rebuild index

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 5.9.1, 5.10.0
    • Fix Version/s: 5.11.0
    • Component/s: LevelDB
    • Labels:
      None
    • Environment:

      Linux

      Description

      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.

      <persistenceAdapter>
          <levelDB directory="${activemq.data}/leveldb" logSize="1000000" />
      </persistenceAdapter>
      

      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:

      -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
      

      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:

      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
      

      And I see the remaining files in the data store folder (notice the 0000000000000000.log is gone):

      -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
      

      At this point, I shut down the broker and here is the listing of what's left in the data store:

      -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
      

      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):

      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
      

        Attachments

          Activity

            People

            • Assignee:
              gtully Gary Tully
              Reporter:
              vhle01 Vu Le
            • Votes:
              3 Vote for this issue
              Watchers:
              12 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: