Alexander Vallens created AMQ-3866:
--------------------------------------

             Summary: kahadb log files not getting cleaned up
                 Key: AMQ-3866
                 URL: https://issues.apache.org/jira/browse/AMQ-3866
             Project: ActiveMQ
          Issue Type: Bug
          Components: Message Store
    Affects Versions: 5.6.0, 5.5.1
            Reporter: Alexander Vallens
            Priority: Critical


A few weeks ago we experienced an event where several hundred thousand messages 
were posted to a queue and slowly consumed over several days until accidentally 
purged. Ever since then our kahadb has been growing on the order of 12-20 
bytes/10 seconds, corresponding to additional entries being added to the kahadb 
log files that are not being cleaned up (this is even the case in an isolated 
test environment with no subscribers/consumers/activity). Having searched and 
found AMQ-3131, AMQ-3736, AMQ-3424, we attempted an upgrade on a clone of the 
affected system from 5.5.1 to 5.6.0, with no luck. Along the way here are the 
steps we took:

1)      I cloned our ActiveMQ virtual machine “hot” (i.e. without shutdown) and 
was able to get an isolated (different hostname, IP, VLAN), but functioning, 
“copy” of the production ActiveMQ instance
2)      startup is slow, given the sheer size of the kahadb, as shown in the 
startup logging:
2012-05-29 19:59:11,780 | INFO  | Recovering from the journal ... | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 20:05:28,352 | WARN  | Duplicate message add attempt rejected. 
Destination: Consumer.SchedulerEvents.VirtualTopic.scheduler/events, Message 
id: ID:<FQDN>-55381-1337386136713-0:18:1:1:1 | org.apache.a
ctivemq.store.kahadb.MessageDatabase | main
2012-05-29 20:05:28,494 | WARN  | Duplicate message add attempt rejected. 
Destination: Consumer.SchedulerEvents.VirtualTopic.scheduler/events, Message 
id: ID:<FQDN>-55381-1337386136713-0:25:1:1:1 | org.apache.a
ctivemq.store.kahadb.MessageDatabase | main
2012-05-29 20:05:28,528 | WARN  | Duplicate message add attempt rejected. 
Destination: Consumer.SchedulerEvents.VirtualTopic.scheduler/events, Message 
id: ID:<FQDN>-55381-1337386136713-0:32:1:1:1 | org.apache.a
ctivemq.store.kahadb.MessageDatabase | main
2012-05-29 20:05:34,513 | INFO  | Recovery replayed 2325747 operations from the 
journal in 382.795 seconds. | org.apache.activemq.store.kahadb.MessageDatabase 
| main
3)      I was able to eliminate the 3 “duplicate message” warnings by purging 
the “Consumer.SchedulerEvents.VirtualTopic.scheduler/events” queue (I suspect 
there were unconsumed messages, perhaps partially uploaded, in that queue at 
time of clone)
4)      after the above steps, I was able to observe that kahadb continued to 
grow at the same rate as the actual production ActiveMQ instancw, ~12-20 bytes 
every 10s
5)      during the first normal shutdown of activemq, I observed the following 
errors:
java.lang.IllegalStateException: PageFile is not loaded
        at org.apache.kahadb.page.PageFile.assertLoaded(PageFile.java:715)
        at org.apache.kahadb.page.PageFile.tx(PageFile.java:239)
        at 
org.apache.activemq.store.kahadb.KahaDBStore$KahaDBMessageStore.resetBatching(KahaDBStore.java:510)
        at 
org.apache.activemq.store.ProxyMessageStore.resetBatching(ProxyMessageStore.java:93)
        at 
org.apache.activemq.broker.region.cursors.QueueStorePrefetch.resetBatch(QueueStorePrefetch.java:85)
        at 
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.stop(AbstractStoreCursor.java:67)
        at 
org.apache.activemq.broker.region.cursors.StoreQueueCursor.stop(StoreQueueCursor.java:84)
        at org.apache.activemq.broker.region.Queue.stop(Queue.java:872)
        at 
org.apache.activemq.broker.region.AbstractRegion.stop(AbstractRegion.java:110)
        at org.apache.activemq.util.ServiceStopper.stop(ServiceStopper.java:41)
        at 
org.apache.activemq.broker.region.RegionBroker.doStop(RegionBroker.java:729)
        at 
org.apache.activemq.broker.jmx.ManagedRegionBroker.doStop(ManagedRegionBroker.java:113)
        at 
org.apache.activemq.broker.region.RegionBroker.stop(RegionBroker.java:213)
        at org.apache.activemq.broker.BrokerFilter.stop(BrokerFilter.java:161)
        at 
org.apache.activemq.broker.scheduler.SchedulerBroker.stop(SchedulerBroker.java:104)
        at org.apache.activemq.broker.BrokerFilter.stop(BrokerFilter.java:161)
        at org.apache.activemq.broker.BrokerFilter.stop(BrokerFilter.java:161)
        at 
org.apache.activemq.broker.TransactionBroker.stop(TransactionBroker.java:114)
        at 
org.apache.activemq.broker.BrokerService$3.stop(BrokerService.java:1795)
        at org.apache.activemq.util.ServiceStopper.stop(ServiceStopper.java:41)
        at org.apache.activemq.broker.BrokerService.stop(BrokerService.java:587)
        at 
org.apache.activemq.console.command.StartCommand$1.run(StartCommand.java:135)
2012-05-29 20:22:09,112 | ERROR | Failed to reset batching | 
org.apache.activemq.store.kahadb.KahaDBStore | Thread-45
6)      subsequent shutdowns, however, operated normally without error
7)      even after various attempts at shutdown and start back up, the 
aforementioned journal recovery was time consuming:
2012-05-29 20:25:06,780 | INFO  | Recovering from the journal ... | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 20:31:39,821 | INFO  | Recovery replayed 2325954 operations from the 
journal in 393.074 seconds. | org.apache.activemq.store.kahadb.MessageDatabase 
| main
8)      and the kahadb growth issue persisted
9)      I went ahead and successfully upgraded to ActiveMQ v5.6.0 (verified 
queues & messages in scheduled queue survived upgrade)
10)     first attempt to start activemq after 5.6.0 upgrade included following 
errors:
2012-05-29 20:55:36,825 | ERROR | Failed to start ActiveMQ JMS Message Broker 
(localhost, null). Reason: java.lang.NegativeArraySizeException | 
org.apache.activemq.broker.BrokerService | main
java.lang.NegativeArraySizeException
        at 
org.apache.kahadb.index.BTreeNode$Marshaller.readPayload(BTreeNode.java:188)
        at 
org.apache.kahadb.index.BTreeNode$Marshaller.readPayload(BTreeNode.java:147)
        at org.apache.kahadb.page.Transaction.load(Transaction.java:412)
        at org.apache.kahadb.page.Transaction.load(Transaction.java:367)
        at org.apache.kahadb.index.BTreeIndex.loadNode(BTreeIndex.java:262)
        at org.apache.kahadb.index.BTreeIndex.getRoot(BTreeIndex.java:174)
        at org.apache.kahadb.index.BTreeIndex.iterator(BTreeIndex.java:228)
        at 
org.apache.activemq.store.kahadb.MessageDatabase$StoredDestinationMarshaller$1.execute(MessageDatabase.java:1654)
        at org.apache.kahadb.page.Transaction.execute(Transaction.java:769)
        at 
org.apache.activemq.store.kahadb.MessageDatabase$StoredDestinationMarshaller.readPayload(MessageDatabase.java:1642)
        at 
org.apache.activemq.store.kahadb.MessageDatabase$StoredDestinationMarshaller.readPayload(MessageDatabase.java:1627)
        at 
org.apache.kahadb.index.BTreeNode$Marshaller.readPayload(BTreeNode.java:201)
        at 
org.apache.kahadb.index.BTreeNode$Marshaller.readPayload(BTreeNode.java:147)
        at org.apache.kahadb.page.Transaction.load(Transaction.java:412)
        at org.apache.kahadb.page.Transaction.load(Transaction.java:367)
        at org.apache.kahadb.index.BTreeIndex.loadNode(BTreeIndex.java:262)
        at org.apache.kahadb.index.BTreeIndex.getRoot(BTreeIndex.java:174)
        at org.apache.kahadb.index.BTreeIndex.iterator(BTreeIndex.java:228)
        at 
org.apache.activemq.store.kahadb.KahaDBStore$6.execute(KahaDBStore.java:943)
        at org.apache.kahadb.page.Transaction.execute(Transaction.java:769)
        at 
org.apache.activemq.store.kahadb.KahaDBStore.getDestinations(KahaDBStore.java:941)
        at 
org.apache.activemq.store.kahadb.KahaDBPersistenceAdapter.getDestinations(KahaDBPersistenceAdapter.java:122)
 
        at 
org.apache.activemq.broker.region.DestinationFactoryImpl.getDestinations(DestinationFactoryImpl.java:68)
        at 
org.apache.activemq.broker.BrokerService.startVirtualConsumerDestinations(BrokerService.java:2369)
        at 
org.apache.activemq.broker.BrokerService.startDestinations(BrokerService.java:2198)
        at 
org.apache.activemq.broker.BrokerService.start(BrokerService.java:527)
        at 
org.apache.activemq.xbean.XBeanBrokerService.afterPropertiesSet(XBeanBrokerService.java:60)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at 
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeCustomInitMethod(AbstractAutowireCapableBeanFactory.java:1544)
        at 
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1485)
        at 
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1417)
        at 
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:519)
        at 
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:456)
        at 
org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:293)
        at 
org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222)
        at 
org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:290)
        at 
org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:192)
        at 
org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:585)
        at 
org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:895)
        at 
org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:425)
        at 
org.apache.xbean.spring.context.ResourceXmlApplicationContext.<init>(ResourceXmlApplicationContext.java:64)
        at 
org.apache.xbean.spring.context.ResourceXmlApplicationContext.<init>(ResourceXmlApplicationContext.java:52)
 
        at 
org.apache.activemq.xbean.XBeanBrokerFactory$1.<init>(XBeanBrokerFactory.java:108)
        at 
org.apache.activemq.xbean.XBeanBrokerFactory.createApplicationContext(XBeanBrokerFactory.java:108)
        at 
org.apache.activemq.xbean.XBeanBrokerFactory.createBroker(XBeanBrokerFactory.java:72)
        at 
org.apache.activemq.broker.BrokerFactory.createBroker(BrokerFactory.java:71)
        at 
org.apache.activemq.broker.BrokerFactory.createBroker(BrokerFactory.java:54)
        at 
org.apache.activemq.console.command.StartCommand.startBroker(StartCommand.java:115)
        at 
org.apache.activemq.console.command.StartCommand.runTask(StartCommand.java:74)
        at 
org.apache.activemq.console.command.AbstractCommand.execute(AbstractCommand.java:57)
        at 
org.apache.activemq.console.command.ShellCommand.runTask(ShellCommand.java:148)
        at 
org.apache.activemq.console.command.AbstractCommand.execute(AbstractCommand.java:57)
        at 
org.apache.activemq.console.command.ShellCommand.main(ShellCommand.java:90)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.apache.activemq.console.Main.runTaskClass(Main.java:257)
        at org.apache.activemq.console.Main.main(Main.java:111)
2012-05-29 20:55:36,873 | INFO  | ActiveMQ Message Broker (localhost, null) is 
shutting down | org.apache.activemq.broker.BrokerService | main
2012-05-29 20:55:36,873 | INFO  | Connector openwire Stopped | 
org.apache.activemq.broker.TransportConnector | main
2012-05-29 20:55:36,873 | INFO  | Connector stomp Stopped | 
org.apache.activemq.broker.TransportConnector | main
2012-05-29 20:55:36,897 | INFO  | 
PListStore:[/opt/activemq/data/localhost/tmp_storage ] stopped | 
org.apache.activemq.store.kahadb.plist.PListStore | main
2012-05-29 20:55:36,897 | INFO  | Stopping async queue tasks | 
org.apache.activemq.store.kahadb.KahaDBStore | main
2012-05-29 20:55:36,897 | INFO  | Stopping async topic tasks | 
org.apache.activemq.store.kahadb.KahaDBStore | main 
2012-05-29 20:55:36,897 | INFO  | Stopped KahaDB | 
org.apache.activemq.store.kahadb.KahaDBStore | main
2012-05-29 20:55:37,297 | INFO  | ActiveMQ JMS Message Broker (localhost, null) 
stopped | org.apache.activemq.broker.BrokerService | main
2012-05-29 20:55:37,300 | ERROR | Failed to load: class path resource 
[activemq.xml], reason: Error creating bean with name 
'org.apache.activemq.xbean.XBeanBrokerService#0' defined in class path resource 
[activemq.xml]: Invoc
ation of init method failed; nested exception is 
java.lang.NegativeArraySizeException | 
org.apache.activemq.xbean.XBeanBrokerFactory | main
org.springframework.beans.factory.BeanCreationException: Error creating bean 
with name 'org.apache.activemq.xbean.XBeanBrokerService#0' defined in class 
path resource [activemq.xml]: Invocation of init method failed; nested e
xception is java.lang.NegativeArraySizeException
        at 
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1420)
        at 
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:519)
        at 
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:456)
        at 
org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:293)
        at 
org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222)
        at 
org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:290)
        at 
org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:192)
        at 
org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:585)
        at 
org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:895)
        at 
org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:425)
        at 
org.apache.xbean.spring.context.ResourceXmlApplicationContext.<init>(ResourceXmlApplicationContext.java:64)
        at 
org.apache.xbean.spring.context.ResourceXmlApplicationContext.<init>(ResourceXmlApplicationContext.java:52)
        at 
org.apache.activemq.xbean.XBeanBrokerFactory$1.<init>(XBeanBrokerFactory.java:108)
        at 
org.apache.activemq.xbean.XBeanBrokerFactory.createApplicationContext(XBeanBrokerFactory.java:108)
        at 
org.apache.activemq.xbean.XBeanBrokerFactory.createBroker(XBeanBrokerFactory.java:72)
        at 
org.apache.activemq.broker.BrokerFactory.createBroker(BrokerFactory.java:71)
        at 
org.apache.activemq.broker.BrokerFactory.createBroker(BrokerFactory.java:54) 
        at 
org.apache.activemq.console.command.StartCommand.startBroker(StartCommand.java:115)
        at 
org.apache.activemq.console.command.StartCommand.runTask(StartCommand.java:74)
        at 
org.apache.activemq.console.command.AbstractCommand.execute(AbstractCommand.java:57)
        at 
org.apache.activemq.console.command.ShellCommand.runTask(ShellCommand.java:148)
        at 
org.apache.activemq.console.command.AbstractCommand.execute(AbstractCommand.java:57)
        at 
org.apache.activemq.console.command.ShellCommand.main(ShellCommand.java:90)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.apache.activemq.console.Main.runTaskClass(Main.java:257)
        at org.apache.activemq.console.Main.main(Main.java:111)
Caused by: java.lang.NegativeArraySizeException
        at 
org.apache.kahadb.index.BTreeNode$Marshaller.readPayload(BTreeNode.java:188)
        at 
org.apache.kahadb.index.BTreeNode$Marshaller.readPayload(BTreeNode.java:147)
        at org.apache.kahadb.page.Transaction.load(Transaction.java:412)
        at org.apache.kahadb.page.Transaction.load(Transaction.java:367)
        at org.apache.kahadb.index.BTreeIndex.loadNode(BTreeIndex.java:262)
        at org.apache.kahadb.index.BTreeIndex.getRoot(BTreeIndex.java:174)
        at org.apache.kahadb.index.BTreeIndex.iterator(BTreeIndex.java:228)
        at 
org.apache.activemq.store.kahadb.MessageDatabase$StoredDestinationMarshaller$1.execute(MessageDatabase.java:1654)
        at org.apache.kahadb.page.Transaction.execute(Transaction.java:769)
        at 
org.apache.activemq.store.kahadb.MessageDatabase$StoredDestinationMarshaller.readPayload(MessageDatabase.java:1642)
 
        at 
org.apache.activemq.store.kahadb.MessageDatabase$StoredDestinationMarshaller.readPayload(MessageDatabase.java:1627)
        at 
org.apache.kahadb.index.BTreeNode$Marshaller.readPayload(BTreeNode.java:201)
        at 
org.apache.kahadb.index.BTreeNode$Marshaller.readPayload(BTreeNode.java:147)
        at org.apache.kahadb.page.Transaction.load(Transaction.java:412)
        at org.apache.kahadb.page.Transaction.load(Transaction.java:367)
        at org.apache.kahadb.index.BTreeIndex.loadNode(BTreeIndex.java:262)
        at org.apache.kahadb.index.BTreeIndex.getRoot(BTreeIndex.java:174)
        at org.apache.kahadb.index.BTreeIndex.iterator(BTreeIndex.java:228)
        at 
org.apache.activemq.store.kahadb.KahaDBStore$6.execute(KahaDBStore.java:943)
        at org.apache.kahadb.page.Transaction.execute(Transaction.java:769)
        at 
org.apache.activemq.store.kahadb.KahaDBStore.getDestinations(KahaDBStore.java:941)
        at 
org.apache.activemq.store.kahadb.KahaDBPersistenceAdapter.getDestinations(KahaDBPersistenceAdapter.java:122)
        at 
org.apache.activemq.broker.region.DestinationFactoryImpl.getDestinations(DestinationFactoryImpl.java:68)
        at 
org.apache.activemq.broker.BrokerService.startVirtualConsumerDestinations(BrokerService.java:2369)
        at 
org.apache.activemq.broker.BrokerService.startDestinations(BrokerService.java:2198)
        at 
org.apache.activemq.broker.BrokerService.start(BrokerService.java:527)
        at 
org.apache.activemq.xbean.XBeanBrokerService.afterPropertiesSet(XBeanBrokerService.java:60)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at 
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeCustomInitMethod(AbstractAutowireCapableBeanFactory.java:1544)
        at 
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1485)
 
        at 
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1417)
        ... 28 more
11)     after the above errors, ActiveMQ was dead; another attempt to start 
worked, yielding the following (also logged in previous attempt):
2012-05-29 21:58:01,317 | INFO  | KahaDB is version 4 | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 21:58:01,396 | INFO  | Recovering from the journal ... | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 21:58:27,601 | INFO  | @2207:10939359, 100000 entries recovered .. | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 21:58:42,788 | INFO  | @2222:10328575, 200000 entries recovered .. | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 21:58:59,234 | INFO  | @2242:14360209, 300000 entries recovered .. | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 21:59:13,628 | INFO  | @2254:1365404, 400000 entries recovered .. | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 21:59:27,466 | INFO  | @2264:30387363, 500000 entries recovered .. | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 21:59:43,739 | INFO  | @2281:28756842, 600000 entries recovered .. | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:00:13,389 | INFO  | @2320:26490711, 700000 entries recovered .. | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:00:47,350 | INFO  | @2371:21837918, 800000 entries recovered .. | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:01:17,752 | INFO  | @2412:10702462, 900000 entries recovered .. | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:01:51,288 | INFO  | @2465:32070937, 1000000 entries recovered .. 
| org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:02:25,203 | INFO  | @2519:21797589, 1100000 entries recovered .. 
| org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:02:55,188 | INFO  | @2564:13289299, 1200000 entries recovered .. 
| org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:03:05,786 | INFO  | @2572:23712519, 1300000 entries recovered .. 
| org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:03:15,375 | INFO  | @2578:22618226, 1400000 entries recovered .. 
| org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:03:27,246 | INFO  | @2585:31399538, 1500000 entries recovered .. 
| org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:03:38,213 | INFO  | @2593:7102179, 1600000 entries recovered .. | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:03:48,285 | INFO  | @2600:11040885, 1700000 entries recovered .. 
| org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:03:55,053 | INFO  | @2602:28573821, 1800000 entries recovered .. 
| org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:04:01,331 | INFO  | @2603:32850602, 1900000 entries recovered .. 
| org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:04:06,689 | INFO  | @2605:3582539, 2000000 entries recovered .. | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:04:12,435 | INFO  | @2606:7920235, 2100000 entries recovered .. | 
org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:04:17,500 | INFO  | @2607:12248010, 2200000 entries recovered .. 
| org.apache.activemq.store.kahadb.MessageDatabase | main 
2012-05-29 22:04:25,521 | INFO  | @2617:28414362, 2300000 entries recovered .. 
| org.apache.activemq.store.kahadb.MessageDatabase | main
2012-05-29 22:04:28,459 | INFO  | Recovery replayed 2326036 operations from the 
journal in 387.094 seconds. | org.apache.activemq.store.kahadb.MessageDatabase 
| main
12)     unfortunately, I confirmed that even after upgrade, kahadb continues to 
grow at about the same rate as before
13) I then applied the logging parameters as described in 
http://activemq.apache.org/why-do-kahadb-log-files-remain-after-cleanup.html. . 
With debugging spun up we see A LOT (I can’t get a count because log files 
rotate too fast, but in the 6 logs that remain I get 31,978 entries) of the 
following:
2012-05-29 23:18:41,925 | DEBUG | message not found in sequence id index: 
ID:<FQDN>-59596-1337475432262-0:35:1:1:1202 | 
org.apache.activemq.store.kahadb.MessageDatabase | main

Google and a search on issues.apache.org reveal nothing on this.


--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: 
https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira


Reply via email to