[
https://issues.apache.org/jira/browse/AMQ-5556?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14300755#comment-14300755
]
Kevin Burton commented on AMQ-5556:
-----------------------------------
Also, I confirmed that in my situation, the reason why this was taking long to
startup was due to LevelDB recover
I used jstack to repeatedly sample the stack and verify that it was in LevelDB
recover:
java.lang.Thread.State: RUNNABLE
at org.iq80.leveldb.table.BlockIterator.next(BlockIterator.java:88)
at
org.iq80.leveldb.util.TableIterator.getNextElement(TableIterator.java:72)
at
org.iq80.leveldb.util.AbstractSeekingIterator.hasNext(AbstractSeekingIterator.java:30)
at
org.iq80.leveldb.util.InternalTableIterator.getNextElement(InternalTableIterator.java:32)
at
org.iq80.leveldb.util.AbstractSeekingIterator.hasNext(AbstractSeekingIterator.java:30)
at
org.iq80.leveldb.util.LevelIterator.getNextElement(LevelIterator.java:90)
at
org.iq80.leveldb.util.AbstractSeekingIterator.hasNext(AbstractSeekingIterator.java:30)
at
org.iq80.leveldb.util.DbIterator$ComparableIterator.next(DbIterator.java:234)
at org.iq80.leveldb.util.DbIterator.getNextElement(DbIterator.java:105)
at
org.iq80.leveldb.util.AbstractSeekingIterator.hasNext(AbstractSeekingIterator.java:30)
at
org.iq80.leveldb.impl.SnapshotSeekingIterator.findNextUserEntry(SnapshotSeekingIterator.java:103)
at
org.iq80.leveldb.impl.SnapshotSeekingIterator.seekInternal(SnapshotSeekingIterator.java:57)
at
org.iq80.leveldb.impl.SnapshotSeekingIterator.seekInternal(SnapshotSeekingIterator.java:28)
at
org.iq80.leveldb.util.AbstractSeekingIterator.seek(AbstractSeekingIterator.java:23)
at
org.iq80.leveldb.impl.SeekingIteratorAdapter.seek(SeekingIteratorAdapter.java:30)
at
org.apache.activemq.leveldb.LevelDBClient$RichDB$$anonfun$cursorPrefixed$1.apply$mcV$sp(LevelDBClient.scala:282)
at
org.apache.activemq.leveldb.LevelDBClient$RichDB$$anonfun$cursorPrefixed$1.apply(LevelDBClient.scala:282)
at
org.apache.activemq.leveldb.LevelDBClient$RichDB$$anonfun$cursorPrefixed$1.apply(LevelDBClient.scala:282)
at
org.apache.activemq.leveldb.LevelDBClient$RichDB.might_trigger_compaction(LevelDBClient.scala:391)
at
org.apache.activemq.leveldb.LevelDBClient$RichDB.cursorPrefixed(LevelDBClient.scala:282)
at
org.apache.activemq.leveldb.LevelDBClient$$anonfun$replay_from$1$$anonfun$apply$mcV$sp$4.apply(LevelDBClient.scala:747)
at
org.apache.activemq.leveldb.LevelDBClient$$anonfun$replay_from$1$$anonfun$apply$mcV$sp$4.apply(LevelDBClient.scala:730)
at scala.Option.map(Option.scala:145)
at
org.apache.activemq.leveldb.LevelDBClient$$anonfun$replay_from$1.apply$mcV$sp(LevelDBClient.scala:730)
at
org.apache.activemq.leveldb.LevelDBClient$$anonfun$replay_from$1.apply(LevelDBClient.scala:697)
at
org.apache.activemq.leveldb.LevelDBClient$$anonfun$replay_from$1.apply(LevelDBClient.scala:697)
at
org.apache.activemq.leveldb.LevelDBClient.might_fail(LevelDBClient.scala:549)
at
org.apache.activemq.leveldb.LevelDBClient.replay_from(LevelDBClient.scala:696)
at
org.apache.activemq.leveldb.LevelDBClient.start(LevelDBClient.scala:562)
at org.apache.activemq.leveldb.DBManager.start(DBManager.scala:648)
at
org.apache.activemq.leveldb.LevelDBStore.doStart(LevelDBStore.scala:235)
at org.apache.activemq.util.ServiceSupport.start(ServiceSupport.java:55)
at
org.apache.activemq.broker.BrokerService.doStartPersistenceAdapter(BrokerService.java:640)
at
org.apache.activemq.broker.BrokerService.startPersistenceAdapter(BrokerService.java:629)
at
org.apache.activemq.broker.BrokerService.start(BrokerService.java:594)
at
org.apache.activemq.xbean.XBeanBrokerService.afterPropertiesSet(XBeanBrokerService.java:73)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeCustomInitMethod(AbstractAutowireCapableBeanFactory.java:1638)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1579)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1509)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:521)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:458)
at
org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:296)
at
org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:223)
- locked <0x00000005cd868d60> (a java.util.concurrent.ConcurrentHashMap)
at
org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:293)
at
org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:194)
at
org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:628)
at
org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:932)
at
org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:479)
- locked <0x00000005cd868e58> (a java.lang.Object)
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:104)
at
org.apache.activemq.xbean.XBeanBrokerFactory.createApplicationContext(XBeanBrokerFactory.java:104)
at
org.apache.activemq.xbean.XBeanBrokerFactory.createBroker(XBeanBrokerFactory.java:67)
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.runTask(StartCommand.java:87)
at
org.apache.activemq.console.command.AbstractCommand.execute(AbstractCommand.java:57)
at
org.apache.activemq.console.command.ShellCommand.runTask(ShellCommand.java:150)
at
org.apache.activemq.console.command.AbstractCommand.execute(AbstractCommand.java:57)
at
org.apache.activemq.console.command.ShellCommand.main(ShellCommand.java:104)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.apache.activemq.console.Main.runTaskClass(Main.java:262)
at org.apache.activemq.console.Main.main(Main.java:115)
> Log that we are doing recovery when in LevelDB
> ----------------------------------------------
>
> Key: AMQ-5556
> URL: https://issues.apache.org/jira/browse/AMQ-5556
> Project: ActiveMQ
> Issue Type: Bug
> Components: activemq-leveldb-store
> Affects Versions: 5.10.0
> Reporter: Kevin Burton
>
> If ActiveMQ is improperly shut down, LevelDB will have to perform recover.
> However, this can take a LONG time and right now is bottlenecked on a single
> core. This means it's not immediately apparent what ActiveMQ is doing during
> this time.
> Printing a message like:
> "ActiveMQ improperly shut down, performing recover, this may take some time."
> Before recovery will be helpful for users trying to figure out what's
> happening in production.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
