Sorry for the delay in responding. I've got a number of follow-up questions/suggestions:
1. Can you take screenshots sorted by all four non-percentage columns (Self Time, Self Time (CPU), Total Time, Total Time (CPU))? The ones with CPU measure CPU time, while the ones without measure total elapsed time (of which some portion is CPU and some portion is things like sleeps and I/O waits). 2. Can you please take a screenshot of the Monitor tab after ActiveMQ finishes starting up? In particular I want to make sure that GC CPU usage looks reasonable. 3. From your screenshot entitled cpu-total-time.jpg, it's clear that there's a very significant amount of CPU time being spent calling org.apache.karaf.management.internal.MBeanInvocationHandler.invoke(), which is JMX-related. We need to figure out if this is relevant or is a red herring. To do that, please find that method in the Call Tree tab (you should be able to right-click on it in the Hot Spots tab and select something like "Find in Call Tree") and see if you can tell what's calling it and what it's calling and whether those calls are in any way related to ActiveMQ. I suspect that it might actually be related to the use of VisualVM, but we need to make sure before we write it off. 4. From your screenshot entitled cpu-self-time.jpg (which is in fact Self Time, *not* Self Time (CPU) as you said), it's clear that there's a significant amount of time being spent in org.apache.activemq.store.kahadb.MessageDatabase$3.run() as well as in various other ActiveMQ-related methods. You'll need to find those methods in the Call Tree tab and walk down the call stack looking for where the majority of the time (I'd focus on elapsed time rather than just CPU, because disk I/O may be part of your problem) is being spent. You can ignore any thread that doesn't eventually land you in something related to KahaDB or files; not every thread will be relevant to your slow startup time, so ignore the ones that aren't. It looks like a lot of time is being spent in RecoverableRandomAccessFile.readInt(), readFully(), and readByte(), so I suspect that those will be a large portion of where your time is being spent, but you may discover that there are other places where time is being spent that weren't visible from the screenshots you've shown so far. 5. If the time really is primarily spent in those three read*() methods, they simply call the equivalent methods in http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/6-b14/java/io/RandomAccessFile.java while wrapped in try/catch statements, so either you're really spending that long reading the bytes from the files and doing shift-and-add operations on the read bytes (in which case you should probably examine both your NFS performance and your belief that you're only reading 5GB of data) or you're spending a ton of time doing exception-handling (in which case we may need to get a debugger in there to figure out what the exceptions are). I think those things will give us a good set of next steps to get closer to determining what's actually going on. Tim On Wed, Oct 11, 2017 at 7:04 PM, Devlin <rbasmaj...@ofiglobal.com> wrote: > Samples for cpu self-time, total-time, and memory usage: > > <http://activemq.2283324.n4.nabble.com/file/t376407/cpu-self-time.jpg> > > <http://activemq.2283324.n4.nabble.com/file/t376407/cpu-total-time.jpg> > > <http://activemq.2283324.n4.nabble.com/file/t376407/mem-usage.jpg> > > > > -- > Sent from: http://activemq.2283324.n4.nabble.com/ActiveMQ-User- > f2341805.html >
