Kevin, This sounds like a reasonable enhancement; can you submit it via JIRA?
Having a log line when you start and finish recovery sounds easy to do, though have you checked that there isn't already one at DEBUG or TRACE? (INFO does seem like the right level, though.) Logging percent complete would be useful, but whether it's possible will depend on how the LevelDB code works. Please make sure your JIRA describes how to recreate the slow behavior you saw, so someone can figure out whether it's possible to get status as it runs. Also suggest what options you think would be useful to control how much logging occurs (to give enough detail without spamming the log). I'd think logging based on time rather than based on hitting some percentage would be most useful, and that there should be a configurable "quiet period" before the first status line so you only give updates for long-running recoveries like yours, but that's just off the cuff and you might have better ideas of what would have been useful to you when this happened. Tim On Jan 31, 2015 4:56 PM, "Kevin Burton" <bur...@spinn3r.com> wrote: > Right now, after a restart, my AMQ server is at 100% CPU and has been so > for about 10 minutes now. > > It should really print that it’s doing recovery and have some sort of > progress indicator ideally. > > Here’s the stack trace where it’s been for a long time now... > > > 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) > > -- > > Founder/CEO Spinn3r.com > Location: *San Francisco, CA* > blog: http://burtonator.wordpress.com > … or check out my Google+ profile > <https://plus.google.com/102718274791889610666/posts> > <http://spinn3r.com> >
