Skip to main content

Hot Threads

Posted by brucechapman on March 25, 2008 at 5:02 PM PDT

I'm setting up my new desktop development machine, and netbeans installation is atrociously slow, like several minutes just to display the splash screen. The task manager shows the process consuming 50% CPU (on a dual core). After stuffing around barking up several wrong trees I drag out a JMX based tool I wrote a while back to find hot threads in a running application.

I had previously encountered slow startup with Netbeans 5.5 (itself - not the installer) and based on A. Sundararajan's blog Using Mustang's Attach API I had written a tool to output the stack traces for the three busiest threads in a java process.

Here's the source code. And for those that just need to do the same thing without understanding internals, Download the jar file

The program attaches to the local java process (specified by the PID on the command line), it grabs information about the processing time of all threads, twice 500ms apart, and uses that to find the three busiest threads. It then takes 10 stacktrace snapshots of those three threads at 10ms intervals, and looks for the common parts on those stack traces for each thread. If a thread is busy, normally most of the stack stays the same, and just the top part changes. The program then outputs to common parts of the stack traces. From there you can see which thread is running hot, and where it is.

So I enabled PID display in the Window's task Manager and ran the program. Here's what I saw...

C:\>java -jar C:\projects\experimental\HotThread\dist\HotThread.jar 3544
java.lang.UnsatisfiedLinkError: no attach in java.library.path
Exception in thread "main" no
        at hotthread.Main.main(

That was due to java's installation running the JRE's copy of java.exe, but it doesn't have some of the attach API support files, so you need to run the JDK version of java.exe. Trying again...

C:\>"C:\Program Files\Java\jdk1.6.0_05\bin\java.exe"  -jar C:\projects\experimental\HotThread\dist\HotThread.jar 3544
106.3% CPU Usage by Thread 'Swing-Shell'
  10/10 snapshots sharing following 10 elements Method)$600(Unknown Source)$ Source)$ Source)
    java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source) Source)
    java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
    java.util.concurrent.ThreadPoolExecutor$ Source)$ComInvoker$ Source) Source)

1.6% CPU Usage by Thread 'RMI TCP Connection(9)-'
  10/10 snapshots sharing following 32 elements Method) Source)
    sun.reflect.GeneratedMethodAccessor106.invoke(Unknown Source)
    sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    java.lang.reflect.Method.invoke(Unknown Source)
    com.sun.jmx.mbeanserver.ConvertingMethod.invokeWithOpenReturn(Unknown Source)
    com.sun.jmx.mbeanserver.MXBeanIntrospector.invokeM2(Unknown Source)
    com.sun.jmx.mbeanserver.MXBeanIntrospector.invokeM2(Unknown Source)
    com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(Unknown Source)
    com.sun.jmx.mbeanserver.PerInterface.invoke(Unknown Source)
    com.sun.jmx.mbeanserver.MBeanSupport.invoke(Unknown Source) Source)
    com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(Unknown Source)
    com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(Unknown Source) Source)$200(Unknown Source)$ Source) Source) Source)
    sun.reflect.GeneratedMethodAccessor21.invoke(Unknown Source)
    sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    java.lang.reflect.Method.invoke(Unknown Source)
    sun.rmi.server.UnicastServerRef.dispatch(Unknown Source)
    sun.rmi.transport.Transport$ Source) Method)
    sun.rmi.transport.Transport.serviceCall(Unknown Source)
    sun.rmi.transport.tcp.TCPTransport.handleMessages(Unknown Source)
    sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(Unknown Source)
    sun.rmi.transport.tcp.TCPTransport$ Source)
    java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
    java.util.concurrent.ThreadPoolExecutor$ Source) Source)

0.0% CPU Usage by Thread 'Reference Handler'
  10/10 snapshots sharing following 3 elements
    java.lang.Object.wait(Native Method)
    java.lang.ref.Reference$ Source)

So armed with this information, a quick search of the JDK bug database looking for "" yields Bug ID: 5033747 JFileChooser is very slow on Windows XP but that is about JFileChooser which doesn't seem related to my problem, however the stack trace matches. One of the related bugs is Bug ID: 5050516 JFileChooser very slow in XP if directory contains large zip files and a light turns on. I have some big zip files on my desktop temporarily while I set things up. In that bug it shows how to disable XP's feature of treating zip files as directories which seems like it might be the root cause.

So I disabled XP's horrible ZIP file handling (which would be marvellous if it wasn't so pathetically slow), and ... Drum roll ... netbeans was installed in a couple of minutes.

Thank you JMX. Maybe a hot thread detector would be useful in jconsole and visualVM.

Related Topics >>


is HotThread supposed to detect native code threads?

Bruce, I am using your invaluable tool and it saved me many times already. Thank you so much! Unfortunately I was chasing one elusive endless loop for a over a year now and your HotThread did not detect it. I seem to have hit a JVM bug - HotSpot's CompilerThread is looping. I was able to determine which thread was responsible using the following IBM article: Enlightened by IBM's article I used the fact that java thread on Linux is a process which has its own process id and shows up in top's process list. I noticed that top showed one Java process eating CPU and its pid was different from the one reported by jps, so I converted this pid it to hex and voila - it matched nid for CompilerThread reported by jstack. Btw, this HotSpot bug is sporadic and seems to occur only in Server VM. To sum it up - it would have been much easier if HotThread detected this problem. Could it be that HotThread misses native threads?

For jconsole there is the JTop plugin: Thanks for the link, but JTop seems pretty crappy. First it has a really basic bug so only whole seconds are shown, then it shows the total accumulated CPU use (whole seconds with ".0000" appended) for each thread, whereas what people are interested in is how much it is currently using (but thats not possible so how much in the most recent sample period is an acceptable approximation), shown as a percentage of the total in such situations to make it easily understandable. - Bruce

VisualVM already has a threads window but I played with your code and did a very rough first draft plugin, based on porting your code to a VisualVM plugin which I then installed in VisualVM Beta. I will work on it some more to make it more graphical:

I got further today and also wrote about it at Javalobby:

Should this work on a linux system? [joebob@xyz ~]$ /usr/java/jdk1.6.0_03/bin/java -jar /root/hotthread.jar 26954 Exception in thread "main" java.lang.NoClassDefFoundError: com/sun/tools/attach/VirtualMachine at hotthread.Main.main( Is there something else I need to install?