Thursday, September 10, 2009

A programatic implementation of dump stack trace

When you program hangs you can always ask the user to perform a dump stack trace; jstack or run visual vm; but when you are trying to run automated UI tests there isn't a user on hand so you need a programmatic solution. Now you can do something with Threads and ThreadGroup classes; but you can get a much better dump of current thread state using management beans. This sound complicated right, well it turns out that there are nice static methods to get hold of those beans for the current VM.

Here is a simple example using a JFrame to give some interest to the output:

package management;

import java.lang.management.ManagementFactory;
import java.lang.management.ThreadInfo;
import java.lang.management.ThreadMXBean;

import javax.swing.JFrame;


public class DumpStackTrace {

    public static void main(String[] args) {

        JFrame frame = new JFrame();
        frame.setVisible(true);

        new DumpStackTrace().dumpStack();
        
        System.exit(0);
    }
    
    public synchronized void  dumpStack() {
        
        ThreadMXBean theadMxBean = ManagementFactory.getThreadMXBean();
        
        for (ThreadInfo ti : theadMxBean.dumpAllThreads(true, true)) {
            System.out.print(ti.toString());
        }
    }
}

This is the output on the console, note in this form you can even see the result of the synchronized on the dumpStack method.

"AWT-EventQueue-0" Id=14 RUNNABLE (in native)
 at sun.awt.windows.WComponentPeer._requestFocus(Native Method)
 at sun.awt.windows.WComponentPeer.requestFocus(WComponentPeer.java:586)
 at java.awt.Component.requestFocusHelper(Component.java:7260)
 at java.awt.Component.requestFocusInWindow(Component.java:7151)
 at java.awt.DefaultKeyboardFocusManager.dispatchEvent(DefaultKeyboardFocusManager.java:361)
 at java.awt.Component.dispatchEventImpl(Component.java:4373)
 at java.awt.Container.dispatchEventImpl(Container.java:2081)
 at java.awt.Window.dispatchEventImpl(Window.java:2458)
 ...

"AWT-Windows" Id=10 RUNNABLE
 at java.awt.KeyboardFocusManager.shouldNativelyFocusHeavyweight(KeyboardFocusManager.java:2386)
 -  locked java.util.LinkedList@ff057f
 at sun.awt.windows.WToolkit.eventLoop(Native Method)
 at sun.awt.windows.WToolkit.run(WToolkit.java:291)
 at java.lang.Thread.run(Thread.java:619)

"AWT-Shutdown" Id=11 WAITING on java.lang.Object@b8deef
 at java.lang.Object.wait(Native Method)
 -  waiting on java.lang.Object@b8deef
 at java.lang.Object.wait(Object.java:485)
 at sun.awt.AWTAutoShutdown.run(AWTAutoShutdown.java:259)
 at java.lang.Thread.run(Thread.java:619)

"Java2D Disposer" Id=9 WAITING on java.lang.ref.ReferenceQueue$Lock@1342ba4
 at java.lang.Object.wait(Native Method)
 -  waiting on java.lang.ref.ReferenceQueue$Lock@1342ba4
 at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
 at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
 at sun.java2d.Disposer.run(Disposer.java:125)
 at java.lang.Thread.run(Thread.java:619)

"Attach Listener" Id=5 RUNNABLE

"Signal Dispatcher" Id=4 RUNNABLE

"Finalizer" Id=3 WAITING on java.lang.ref.ReferenceQueue$Lock@10a6ae2
 at java.lang.Object.wait(Native Method)
 -  waiting on java.lang.ref.ReferenceQueue$Lock@10a6ae2
 at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
 at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
 at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" Id=2 WAITING on java.lang.ref.Reference$Lock@ef2c60
 at java.lang.Object.wait(Native Method)
 -  waiting on java.lang.ref.Reference$Lock@ef2c60
 at java.lang.Object.wait(Object.java:485)
 at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)

"main" Id=1 RUNNABLE
 at sun.management.ThreadImpl.dumpThreads0(Native Method)
 at sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:374)
 at management.DumpStackTrace.dumpStack(DumpStackTrace.java:26)
 -  locked management.DumpStackTrace@4a6cbf
 at management.DumpStackTrace.main(DumpStackTrace.java:17)

Simple and works a treat, just merging this code into our abbot runner.

Update 27 Jan 2011: One of the annoying problems with this solution is that it only prints out the first 8 items of the stack trace which might not be enough, turns out it is easy enough to trace out the rest

package management;

import java.lang.management.ManagementFactory;
import java.lang.management.ThreadInfo;
import java.lang.management.ThreadMXBean;

import javax.swing.JFrame;


public class DumpStackTrace {

    public static void main(String[] args) {

        JFrame frame = new JFrame();
        frame.setVisible(true);

        new DumpStackTrace().dumpStack(System.out);
        
        System.exit(0);
    }
    
    public synchronized void  dumpStack(PrintStream ps) {
        
        ThreadMXBean theadMxBean = ManagementFactory.getThreadMXBean();
        
        for (ThreadInfo ti : theadMxBean.dumpAllThreads(true, true)) {
            System.out.print(ti.toString());

           // ThreadInfo only prints out the first 8 lines, so make sure
           // we write out the rest
           StackTraceElement ste[] = ti.getStackTrace();
           if (ste.length > 8)
           {
             ps.println("[Extra stack]");
             for (int element = 8; element < ste.length; element++)
             {
                ps.println("\tat " + ste[element]);
                for (MonitorInfo mi : ti.getLockedMonitors()) {
                   if (mi.getLockedStackDepth() == element) {
                       ps.append("\t-  locked " + mi);
                       ps.append('\n');
                   }
                }
             }
             ps.println("[Extra stack]");
           }
        }
    }
}

No comments: