Understanding
which Thread is waiting and which Thread is blocking
Finding
the root cause of a block in java may be difficult sometimes, as
thread dumps may be difficult to follow, and is hard to understand which thread is
waiting and which thread is locking it.
Unfortunately,
I have not seen any tools that can represent clearly a lock tree of a
Threads running in a java process. This is the reason I thought to
build a tool that can help to determine BLOCKER and WAITER threads
from a java thread dump.
The
idea is to take a thread dump and store the output to a file, then
process that file using a perl script which I called “thread_lock_tree.pl”. The script will represent a list of
threads and its status grouping the threads that a BLOCKING together with the ones that are WAITING. All this is done in a visual way using indentation, so that everyone can understand and see.
You start by taking a thread dump, using your favorite tool, for Example jstack.
$JAVA_HOME/bin/jstack
8978 > thread_dump_pid8978.tdump
As you can see from the below, it is difficult to determine which threads are waiting for which thread to finish.
$
cat thread_dump_pid8978.tdump
"AJPRequestHandler-HTTPThreadGroup-2744"
prio=10 tid=0x36f92000 nid=0x6206 waiting for monitor entry
[0x18621000]
java.lang.Thread.State: BLOCKED
(on object monitor)
-
waiting to lock <0x84095160> (a
oracle.jdbc.driver.T4CConnection)
-
locked <0xe2447c99> (a java.lang.Byte)
"AJPRequestHandler-HTTPThreadGroup-2743"
prio=10 tid=0x36f98c00 nid=0x6177 waiting for monitor entry
[0x18255000]
java.lang.Thread.State: BLOCKED
(on object monitor)
-
waiting to lock <0x779ce6b8> (a java.lang.Byte)
-
locked <0xe2447c59> (a java.lang.Byte)
"AJPRequestHandler-HTTPThreadGroup-2742"
prio=10 tid=0x36f92800 nid=0x60d7 runnable [0x182f6000]
java.lang.Thread.State:
RUNNABLE
-
locked <0x84095160> (a oracle.jdbc.driver.T4CConnection)
-
locked <0xe2447c58> (a java.lang.Byte)
-
locked <0x779ce6b8> (a java.lang.Byte)
"AJPRequestHandler-HTTPThreadGroup-2749"
prio=10 tid=0x36f92000 nid=0x6206 waiting for monitor entry
[0x18621000]
java.lang.Thread.State: BLOCKED
(on object monitor)
-
waiting to lock <0xe2447c59> (a java.lang.Byte)
-
waiting to lock <0xe2447c99> (a java.lang.Byte)
-
locked <0xe2457c99> (a java.lang.Byte)
"AJPRequestHandler-HTTPThreadGroup-4749"
prio=10 tid=0x36f92000 nid=0x6206 waiting for monitor entry
[0x18621000]
java.lang.Thread.State: BLOCKED
(on object monitor)
-
waiting to lock <0xe2447c59> (a java.lang.Byte)
-
waiting to lock <0xe2447c99> (a java.lang.Byte)
"AJPRequestHandler-HTTPThreadGroup-5749"
prio=10 tid=0x36f92000 nid=0x6206 waiting for monitor entry
[0x18621000]
java.lang.Thread.State: BLOCKED
(on object monitor)
-
waiting to lock <0xe2457c99> (a java.lang.Byte)
To understand the lock situation, you can parse “tdump” file using the script.
Usage: perl
thread_lock_tree.pl <file.tdump>
$
perl thread_lock_tree.pl thread_dump_pid8978.tdump
~~
Analyzing thread lock tree in thread dump file:
thread_dump_pid8978.tdump ~~
AJPRequestHandler-HTTPThreadGroup-2742(RUNNABLE)
(2)
|_AJPRequestHandler-HTTPThreadGroup-2744(BLOCKED)
(2)
|_AJPRequestHandler-HTTPThreadGroup-2749(BLOCKED)
(1)
|_AJPRequestHandler-HTTPThreadGroup-5749(BLOCKED)
(0)
|_AJPRequestHandler-HTTPThreadGroup-4749(BLOCKED)
(0)
|_AJPRequestHandler-HTTPThreadGroup-2743(BLOCKED)
(2)
|_AJPRequestHandler-HTTPThreadGroup-2749(BLOCKED)
(1)
|_AJPRequestHandler-HTTPThreadGroup-5749(BLOCKED)
(0)
|_AJPRequestHandler-HTTPThreadGroup-4749(BLOCKED)
(0)
As
you can see in the above output, you can easily see which threads are
locking and which ones are waiting in a simple locking tree format.