Glassfish v3 - How to Get/Analyze Thread Dump?

Question

I'm trying to get/analyze a thread dump for my app that's running in Glassfish 3.1.1 on a Linux box. I've come across two ways to do it.

1. Run kill -QUIT <pid> on the command line
2. In the Glassfish admin console, go to Common Tasks -> server (Admin Server) -> General tab. Click on "JVM Report" and choose "Thread Dump" from the "View" drop-down box.

The results from both of these thread dumps are different. The kill method generates a file (/domains/domain1/logs/jvm.log) that is XML (hotspot_log) and has this structure:

<?xml version='1.0' encoding='UTF-8'?>
<hotspot_log version='160 1' process='9426' time_ms='1328662710633'>
    <vm_version>
        <name>Java HotSpot(TM) 64-Bit Server VM</name>
        <release>17.0-b16</release>
        <info>
            Java HotSpot(TM) 64-Bit Server VM (17.0-b16) for linux-amd64 JRE (1.6.0_21-b06),
            built on Jun 22 2010 01:10:00 by &quot;java_re&quot; with gcc 3.2.2
            (SuSE Linux)
        </info>
    </vm_version>
    <vm_arguments>
        <args>
            -XX:+UnlockDiagnosticVMOptions -XX:MaxPermSize=192m -XX:NewRatio=2 -XX:+LogVMOutput

            ... SNIP ...

        </args>
        <command>

            ... SNIP ...

        </command>
        <launcher>
            SUN_STANDARD
        </launcher>
        <properties>
            java.vm.specification.version=1.0

            ... SNIP ...

        </properties>
    </vm_arguments>
    <tty>
        <writer thread='1085897024' />
        <dependency_failed type='unique_concrete_method'
            x='java/lang/ThreadLocal getMap (Ljava/lang/Thread;)Ljava/lang/ThreadLocal$ThreadLocalMap;'
            witness='java/lang/InheritableThreadLocal' stamp='1.955' />
        <dependency_failed type='unique_concrete_method'
            x='java/lang/ThreadLocal getMap (Ljava/lang/Thread;)Ljava/lang/ThreadLocal$ThreadLocalMap;'
            witness='java/lang/InheritableThreadLocal' stamp='1.955' />
        <dependency_failed type='unique_concrete_method'
            x='java/lang/ThreadLocal getMap (Ljava/lang/Thread;)Ljava/lang/ThreadLocal$ThreadLocalMap;'
            witness='java/lang/InheritableThreadLocal' stamp='1.955' />
        <dependency_failed type='unique_concrete_method'
            x='java/lang/ThreadLocal getMap (Ljava/lang/Thread;)Ljava/lang/ThreadLocal$ThreadLocalMap;'
            witness='java/lang/InheritableThreadLocal' stamp='1.955' />

        ... SNIP ...

        <writer thread='1106913600' />
        2012-02-08 09:54:18
        Full thread dump Java HotSpot(TM) 64-Bit Server VM (17.0-b16 mixed mode):

        &quot;pool-28-thread-1&quot; prio=10 tid=0x00002aaae959c800 nid=0x28d5
        runnable [0x0000000049da0000]
        java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:129)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
        at java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
        - locked &lt;0x00002aaab547d7f0&gt; (a java.io.BufferedInputStream)
        at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:687)
        at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:632)
        at

    ... SNIP ...

Note that the closing tags

    </tty>
</hotspot_log>

are missing from the file. Anyone know why?

The dump done via the admin console generates a report with this format:

server

View:

Full Java Thread Dump Java HotSpot(TM) 64-Bit Server VM 17.0-b16 Sun Microsystems Inc.
Number of threads: 97
Number of daemon threads: 83
Peak live thread count since the Java virtual machine started or peak was reset: 116
Is support for thread contention monitoring available on this JVM? [true]
Is thread contention monitoring enabled? [false]. If false, some thread synchronization statistics are not be available.
Is support for CPU time measurement for any thread available on this JVM? [true]
Is thread CPU time measurement enabled? [true]. If false, thread execution times are not available for any thread.
--------------------------------------------------------------------------------
Thread Execution Information:
-----------------------
Thread "Ejb-Timer-Thread-103" thread-id: 616 thread-state: TIMED_WAITING Waiting on lock: java.util.concurrent.SynchronousQueue$TransferStack@28ee94c8
     at: sun.misc.Unsafe.park(Native Method)
     at: java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
     at: java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:424)
     at: java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:323)
     at: java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:874)
     at: java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:945)
     at: java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
     at: java.lang.Thread.run(Thread.java:619)
Thread Synchronization Statistics:
-----------------------
Number of times this thread was blocked (to enter/reenter a Monitor): 0
Number of times this thread waited for a notification (i.e. it was in WAITING or TIMED_WAITING state): 20
Total CPU time for this thread: 0 seconds 0 nanoseconds.
User-level CPU time for this thread: 0 seconds 0 nanoseconds.
Object Monitors currently held or requested by this thread: []
Ownable Synchronizers (e.g. ReentrantLock and ReentrantReadWriteLock) held by this thread: []
--------------------------------------------------------------------------------
Thread Execution Information:
-----------------------
Thread "RMI TCP Connection(206)-127.0.0.1" thread-id: 613 thread-state: RUNNABLE Running in native
     at: java.net.SocketInputStream.socketRead0(Native Method)
     at: java.net.SocketInputStream.read(SocketInputStream.java:129)
     at: java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
     at: java.io.BufferedInputStream.read(BufferedInputStream.java:237)
     at: java.io.DataInputStream.readUnsignedShort(DataInputStream.java:320)
     at: java.io.DataInputStream.readUTF(DataInputStream.java:572)
     at: java.io.DataInputStream.readUTF(DataInputStream.java:547)
     at: sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:774)
     at: sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649)
     at: java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
     at: java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
     at: java.lang.Thread.run(Thread.java:619)
Thread Synchronization Statistics:
-----------------------
Number of times this thread was blocked (to enter/reenter a Monitor): 0
Number of times this thread waited for a notification (i.e. it was in WAITING or TIMED_WAITING state): 0
Total CPU time for this thread: 0 seconds 0 nanoseconds.
User-level CPU time for this thread: 0 seconds 0 nanoseconds.
Object Monitors currently held or requested by this thread: []
Ownable Synchronizers (e.g. ReentrantLock and ReentrantReadWriteLock) held by this thread: []
--------------------------------------------------------------------------------

... SNIP ...

No deadlock found

To analyze the dumps, I have tried TDA - Thread Dump Analyzer (http://java.net/projects/tda/) and have discovered that it will open the XML version, but it won't display in the UI until I open a non-XML version as well (then both are displayed).

Why are the formats so different? Is one preferred over the other for analysis? Does it matter?

Answer 1

you can use the following command to generate thread dump report in glassfish v3.1:

asadmin generate-jvm-report --type=thread

ref:

http://docs.oracle.com/cd/E18930_01/html/821-2436/ghuvy.html

Answer 2

Both the dump formats are odd. I'm going to guess Glassfish is doing something specific for these dump requests.

Try, jstack , comes with the JDK. That is the format that is commonly posted here for questions.

The dump should look more like this:

012-02-04 18:00:01
Full thread dump Java HotSpot(TM) 64-Bit Server VM (16.3-b01 mixed mode):

"pool-2-thread-1143" prio=3 tid=0x0000000105419000 nid=0x1fe0 waiting on condition   xfffffffb43dfe000]
  java.lang.Thread.State: TIMED_WAITING (parking)
  at sun.misc.Unsafe.park(Native Method)