[A-MQ 6, kahadb, recovery] Broker failure when deleting files can cause missing journal errors on restart

Known Workaround:

• If the journals *are* being archived; retrieve the missing journal file from the archive and manually add it back to the kahadb directory. The broker should start and GC the file correctly.

• if the journals *are* not been archived; create an empty journal file in the kahadb directly that corresponds to the name of the missing journal. The broker should start and GC the empty file.

Unfortunately I haven't been able to condense this to a unit test. The following steps to manipulate the thread model and abruptly kill the broker are required.

• Use the following kahadb configation:

   <kahaDB directory="${karaf.data}/amqdb/kahadb" concurrentStoreAndDispatchQueues="false"   journalMaxFileLength=“10 mb" useLock="true"  enableJournalDiskSyncs="true" indexCacheSize="102400" checksumJournalFiles="true" checkForCorruptJournalFiles="true"  />
  

• set break point at

   org.apache.activemq.store.kahadb.disk.journal.Journal.forceRemoveDataFile(Journal.java:762)
  

• use a test client to load messages into a destination, enough to create 4 journal files in kahadb.

• use a test client to consumer enough messages so 2 of these journal files will be GC'd by kahadb

• after a few moment this should trigger the break point above. Resume application running and wait for the breakpoint to be triggered again. ( this will occur just before the second file is deleted)

• when the the breakpoint it triggered the second time, do a "kill -9" on the broker process.

• restart the broker and you should see the following exception

  2017-01-12 21:56:04,429 | INFO  | FelixStartLevel  | HttpServiceFactoryImpl           | 127 - org.ops4j.pax.web.pax-web-runtime - 4.3.0 | Binding bundle: [io.hawt.hawtio-redhat-amq-branding [189]] to http service
  2017-01-12 21:56:04,455 | INFO  | lixDispatchQueue | patch-management                 | 1 - io.fabric8.patch.patch-management - 1.2.0.redhat-630187 | Configuring patch management system
  2017-01-12 21:56:05,300 | INFO  | AMQ-1-thread-1   | MessageDatabase                  | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | KahaDB is version 5
  2017-01-12 21:56:05,347 | INFO  | AMQ-1-thread-1   | MessageDatabase                  | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | Recovering from the journal @11:954448
  2017-01-12 21:56:05,743 | INFO  | AMQ-1-thread-1   | MessageDatabase                  | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | Recovery replayed 3012 operations from the journal in 0.428 seconds.
  2017-01-12 21:56:05,756 | WARN  | AMQ-1-thread-1   | MessageDatabase                  | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | Some journal files are missing: [1]
  2017-01-12 21:56:05,773 | ERROR | AMQ-1-thread-1   | MessageDatabase                  | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | Detected missing journal files. [1]
  2017-01-12 21:56:05,773 | ERROR | AMQ-1-thread-1   | BrokerService                    | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | Failed to start Apache ActiveMQ ([amq, null], java.io.IOException: Detected missing journal files. [1])
  2017-01-12 21:56:05,775 | INFO  | AMQ-1-thread-1   | BrokerService                    | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | Apache ActiveMQ 5.11.0.redhat-630187 (amq, null) is shutting down
  2017-01-12 21:56:05,777 | INFO  | AMQ-1-thread-1   | TransportConnector               | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | Connector openwire stopped
  2017-01-12 21:56:05,777 | INFO  | AMQ-1-thread-1   | TransportConnector               | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | Connector amqp stopped
  2017-01-12 21:56:05,778 | INFO  | AMQ-1-thread-1   | TransportConnector               | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | Connector mqtt stopped
  2017-01-12 21:56:05,779 | INFO  | AMQ-1-thread-1   | TransportConnector               | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | Connector ws stopped
  2017-01-12 21:56:05,782 | INFO  | AMQ-1-thread-1   | PListStoreImpl                   | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | PListStore:[/apps/fusebin/jboss-a-mq-6.3.0.redhat-187/data/amq/amq/tmp_storage] stopped
  2017-01-12 21:56:05,783 | INFO  | AMQ-1-thread-1   | KahaDBStore                      | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | Stopping async queue tasks
  2017-01-12 21:56:05,784 | INFO  | AMQ-1-thread-1   | KahaDBStore                      | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | Stopping async topic tasks
  2017-01-12 21:56:05,784 | INFO  | AMQ-1-thread-1   | KahaDBStore                      | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | Stopped KahaDB
  2017-01-12 21:56:05,820 | INFO  | AMQ-1-thread-1   | BrokerService                    | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | Apache ActiveMQ 5.11.0.redhat-630187 (amq, null) uptime 1.537 seconds
  2017-01-12 21:56:05,821 | INFO  | AMQ-1-thread-1   | BrokerService                    | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630187 | Apache ActiveMQ 5.11.0.redhat-630187 (amq, null) is shutdown
  2017-01-12 21:56:05,821 | INFO  | AMQ-1-thread-1   | ActiveMQServiceFactory           | 176 - io.fabric8.mq.mq-fabric - 1.2.0.redhat-630187 | Broker amq failed to start.  Will try again in 10 seconds
  2017-01-12 21:56:05,823 | ERROR | AMQ-1-thread-1   | ActiveMQServiceFactory           | 176 - io.fabric8.mq.mq-fabric - 1.2.0.redhat-630187 | Exception on start: java.io.IOException: Detected missing journal files. [1]
  java.io.IOException: Detected missing journal files. [1]
  	at org.apache.activemq.store.kahadb.MessageDatabase.recoverIndex(MessageDatabase.java:935)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630187]
  	at org.apache.activemq.store.kahadb.MessageDatabase$5.execute(MessageDatabase.java:676)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630187]
  	at org.apache.activemq.store.kahadb.disk.page.Transaction.execute(Transaction.java:779)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630187]
  	at org.apache.activemq.store.kahadb.MessageDatabase.recover(MessageDatabase.java:673)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630187]
  	at org.apache.activemq.store.kahadb.MessageDatabase.open(MessageDatabase.java:429)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630187]
  	at org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:447)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630187]
  	at org.apache.activemq.store.kahadb.MessageDatabase.doStart(MessageDatabase.java:283)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630187]
  	at org.apache.activemq.store.kahadb.KahaDBStore.doStart(KahaDBStore.java:205)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630187]
  	at org.apache.activemq.util.ServiceSupport.start(ServiceSupport.java:55)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630187]
  	at org.apache.activemq.store.kahadb.KahaDBPersistenceAdapter.doStart(KahaDBPersistenceAdapter.java:223)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630187]
  	at org.apache.activemq.util.ServiceSupport.start(ServiceSupport.java:55)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630187]
  	at org.apache.activemq.broker.BrokerService.doStartPersistenceAdapter(BrokerService.java:658)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630187]
  	at org.apache.activemq.broker.BrokerService.startPersistenceAdapter(BrokerService.java:642)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630187]
  	at org.apache.activemq.broker.BrokerService.start(BrokerService.java:607)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630187]
  	at io.fabric8.mq.fabric.ActiveMQServiceFactory$ClusteredConfiguration.doStart(ActiveMQServiceFactory.java:549)[176:io.fabric8.mq.mq-fabric:1.2.0.redhat-630187]
  	at io.fabric8.mq.fabric.ActiveMQServiceFactory$ClusteredConfiguration.access$400(ActiveMQServiceFactory.java:359)[176:io.fabric8.mq.mq-fabric:1.2.0.redhat-630187]
  	at io.fabric8.mq.fabric.ActiveMQServiceFactory$ClusteredConfiguration$1.run(ActiveMQServiceFactory.java:490)[176:io.fabric8.mq.mq-fabric:1.2.0.redhat-630187]
  	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)[:1.7.0_75]
  	at java.util.concurrent.FutureTask.run(FutureTask.java:262)[:1.7.0_75]
  	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)[:1.7.0_75]
  	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)[:1.7.0_75]
  	at java.lang.Thread.run(Thread.java:745)[:1.7.0_75]