Search code examples
javaanalysisjvm-hotspot

jstack Format Change

We have been using jstack to output thread dumps from our JVMs and for years we have been using the IBM Thread Analyzer to analyze the threads and monitors. Below is an example jstack (jstack -l PID > jstack.out) output that the analyzer parses.

Wed Oct  5 00:28:56 EDT 2016
2016-10-05 00:29:04
Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.55-b03 mixed mode):

"Attach Listener" daemon prio=10 tid=0x00000000131e3800 nid=0x7654 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
    - None

"Keep-Alive-Timer" daemon prio=10 tid=0x00002ad5b81c1000 nid=0x717f waiting on condition [0x00002ad5d3d7e000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at sun.net.www.http.KeepAliveCache.run(KeepAliveCache.java:172)
    at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
    - None

But some systems output a thread dump with the format below that the analyzer will not parse due to the format change of using dashes for the trace instead of white space. I have also tried to parse the file below with TDA and Samurai with no luck.

Attaching to process ID 31283, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.91-b14
Deadlock Detection:

No deadlocks found.

Thread 21765: (state = BLOCKED)
 - sun.misc.Unsafe.park(boolean, long) @bci=0 (Compiled frame; information may be imprecise)
 - java.util.concurrent.locks.LockSupport.parkNanos(java.lang.Object, long) @bci=20, line=215 (Compiled frame)
 - java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(java.util.concurrent.SynchronousQueue$TransferStack$SNode, boolean, long) @bci=160, line=460 (Compiled frame)
 - java.util.concurrent.SynchronousQueue$TransferStack.transfer(java.lang.Object, boolean, long) @bci=102, line=362 (Compiled frame)
 - java.util.concurrent.SynchronousQueue.poll(long, java.util.concurrent.TimeUnit) @bci=11, line=941 (Compiled frame)
 - java.util.concurrent.ThreadPoolExecutor.getTask() @bci=134, line=1066 (Compiled frame)
 - java.util.concurrent.ThreadPoolExecutor.runWorker(java.util.concurrent.ThreadPoolExecutor$Worker) @bci=26, line=1127 (Compiled frame)
 - java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=5, line=617 (Compiled frame)
 - java.lang.Thread.run() @bci=11, line=745 (Compiled frame)

My questions are:

  1. Why is the format different? Is it the change from JVM version 24 to 25 (shown at the top of each output).
  2. Is there a tool that will parse the new format or an undocumented jstack command that will output in the old format?
Solution

  • Most probably one of the dumps you took is with -F and the other is without. They are taken using the different mechanisms so outputs may vary.

    Here's an example with -F

    $ jstack -F 75540
Attaching to process ID 75540, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.45-b02
Deadlock Detection:

No deadlocks found.

Thread 14611: (state = BLOCKED)


Thread 13571: (state = BLOCKED)
 - java.lang.Object.wait(long) @bci=0 (Interpreted frame)
 - java.lang.ref.ReferenceQueue.remove(long) @bci=59, line=143 (Interpreted frame)
 - java.lang.ref.ReferenceQueue.remove() @bci=2, line=164 (Interpreted frame)
 - java.lang.ref.Finalizer$FinalizerThread.run() @bci=36, line=209 (Interpreted frame)

    And without

    $ jstack 75540
2016-11-09 09:03:31
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.45-b02 mixed mode):

"Attach Listener" #10 daemon prio=9 os_prio=31 tid=0x00007f81e4000000 nid=0x5503 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Service Thread" #9 daemon prio=9 os_prio=31 tid=0x00007f81e2815800 nid=0x5103 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

    If you're curious, you can read more on the differences in Running jmap getting Unable to open socket file. (Differences in output are just a consequence of that)