Jrockit Thread Dump Analyzer

Understanding Threads

A java application consists of one or more threads that run Java code.

The entire JVM process consists of the Java threads and some JVM internal threads,

for example one or more garbage collection threads, a code optimizer thread and one or more finalizer threads.

From the operating system’s point of view the Java threads are just like any application threads. Scheduling of the threads is handled by the operating system, as well as thread priorities.

Within Java, the Java threads are represented by thread objects. Each thread also has a stack, used for storing runtime data. The thread stack has a specific size. If a thread tries to store more items on the stack than the stack size allows, the thread will throw a stack overflow error.

The following diagram shows the life cycle of a Java Thread.

Thread can sleep, notify, resume, start, stop, suspend, yield and wait, These activities lead the thread from one state to move to another one.

Life Cycle of Thread :

Jrockit Thread Dump

The state of each thread is presented with a so called stack trace, which shows the contents of a thread’s stack. Some of the threads belong to the Java application you are running, while others are JVM internal threads.

A thread dump reveals information about an application’s thread activity that can help you diagnose problems and better optimize application and JVM performance; for example, thread dumps automatically show the occurrence of a deadlock.

Deadlocks bring some or all of an application to a complete halt.

The following subjects are discussed in this chapter:

1. Creating Thread Dumps
2. Reading Thread Dumps
3. Thread Status in Thread Dumps
4. Troubleshooting with Thread Dumps

Creating Thread Dumps

To create a thread dump from a process, do either of the following:

Use jrcmd, simply enter it at the command line, with the appropriate parameters:

bin\jrcmd.exe <jrockit pid> [<command> [<arguments>]] [-l] [-f file] [-p] -h]

where:[<command> [<arguments>]] is any diagnostic command and its associated arguments; for example, version, print_properties, command_line, and so on.

1. -l displays the counters exposed by this process
2. -f reads and execute commands from the file
3. -p lists JRockit JVM processes on the local machine
4. -h shows help

If the PID is 0, commands will be sent to all JRockit JVM processes. If no options are given, default is -p.

Reading Thread Dumps

First, information about the main thread is printed, then all the JVM internal threads,

followed by all other Java application threads (if there are any). Finally, information about lock chains are printed

(Main thread, JVM internal threads, Java application threads and lock Chains are Printer)

The example thread dump is taken from a program that creates three threads that are quickly forced into a deadlock. The application threads Thread-0, Thread-1, and Thread-2 correspond to three different classes in the Java code.

The Beginning of the Thread Dump

------------------------------------------------

The thread dump starts with the date and time of the dump, and the version number of the JRockit JVM used

------------  -------------  ---------------  ----------------- -------------  ------------- ------------- -------------

------------  -------------  ---------------  ----------------- -------------  ------------- ------------- -------------

The initial information of a thread dump

 ===== FULL THREAD DUMP ===============

Wed Feb 21 13:46:45 2007

BEA JRockit(R) R27.1.0-109-73164-1.5.0_08-20061129-1428-windows-ia32

Stack Trace for Main Application Thread

---------------------------------------

The main thread in the thread dump

"Main Thread" id=1 idx=0x2 tid=48652 prio=5 alive, in native, waiting

-- Waiting for notification on: util/repro/Thread1@0x01226528[fat lock]

at jrockit/vm/Threads.waitForSignal(J)Z(Native Method)

at java/lang/Object.wait(J)V(Native Method)

at java/lang/Thread.join(Thread.java:1095)

^-- Lock released while waiting: util/repro/Thread1@0x01226528[fat lock]

at java/lang/Thread.join(Thread.java:1148)

at util/repro/DeadLockExample.main(DeadLockExample.java:23)

at jrockit/vm/RNI.c2java(IIII)V(Native Method)

-- end of trace

After the name and other identification information, the different status messages of the main thread are printed.

The main thread is a running thread (alive), it is either executing JVM internal code or user-defined JNI code (in native), and it is currently waiting for an object to be released (waiting). If a thread is waiting on a notification on a lock (by calling Object.wait()), this is indicated at the top of the stack trace as Waiting for notification on.

Locks and Lock Chains

For each thread, the JRockit JVM prints the following information:

If the thread is trying to take a lock (to enter a synchronized block), but the lock is already held by another thread, this is indicated at the top of the stack trace, as “Blocked trying to get lock”.

If the thread is waiting on a notification on a lock (by calling Object.wait()), this is indicated at the top of the stack trace as “Waiting for notification”.

If the thread has taken any locks, this is shown in the stack trace. After a line in the stack trace describing a function call is a list of the locks taken by the thread in that function. This is described as ^-- Holding lock (where the ^-- serves as a reminder that the lock is taken in the function written above the line with the lock).

The semantics for waiting (for notification) on an object in Java is somewhat complex. First, to enter a synchronized block, you must take the lock for the object, and then you call wait() on that object. In the wait method, the lock is released before the thread actually goes to sleep waiting for a notification. When it receives a notification, wait re-takes the lock before returning. So, if a thread has taken a lock, and is waiting (for notification) on that lock, the line in the stack trace that describes when the lock was taken is not shown as “Holding lock,” but as “Lock released while waiting.”

All locks are described as Classname@0xLockID[LockType]; for example:

java/lang/Object@0x105BDCC0[thin lock]

Classname@0xLockID describe the object to which the lock belongs. The classname is an exact description, the fully qualified classname of the object. LockID, on the other hand, is a temporary ID which is only valid for a single thread dump. That is, you can trust that if a thread A holds a lock java/lang/Object@0x105BDCC0, and a thread B is waiting for a lock java/lang/Object@0x105BDCC0, in a single thread dump, then it is the same lock. If you do any subsequent thread dumps however, LockID is not comparable and, even if a thread holds the same lock, it might have a different LockID and, conversely, the same LockID does not guarantee that it holds the same lock. LockType describes the JVM internal type of the lock (fat, thin, recursive, or lazy). The status of active locks (monitors) is also shown in stack traces.

Presentation of Locks Out of Order

The lines with the lock information might not always be correct, due to compiler optimizations. This means two things:

If a thread, in the same function, takes lock A first and then lock B, the order in which they are printed is unspecified.

If a thread, in method foo() calls method bar(), and takes a lock A in bar(), the lock might be printed as being taken in foo().

Normally, this should not be a problem. The order of the lock lines should never move much from their correct position. Also, lock lines will never be missing—you can be assured that all locks taken by a thread are shown in the thread dump.

JVM Internal Threads

The threads have been marked as daemon threads, as can be seen by their daemon state indicators. Daemon threads are either JVM internal threads (as in this case) or threads marked as daemon threads by java.lang.Thread.setDaemon().

Example:

The first and last thread in a list of JVM internal Threads

 "(Signal Handler)" id=2 idx=0x4 tid=48668 prio=5 alive, in native, daemon

 [...]

 "(Sensor Event Thread)" id=10 idx=0x1c tid=48404 prio=5 alive, in native, daemon

As you can see, lock information and stack traces are not printed for the JVM internal threads in above Example. This is the default setting.

If you want to see stack traces for the JVM internal threads, then use the parameter nativestack=true when you send the print_threads handler. At the command line, write the following:

bin\jrcmd.exe <pid> print_threads nativestack=true

Other Java Application Threads

Normally, you will primarily be interested in the threads of the Java application you are running (including the main thread). All Java application threads except the main thread are presented near the end of the thread dump. Example below shows the stack traces of three different application threads.

Additional application threads

"Thread-0" id=11 idx=0x1e tid=48408 prio=5 alive, in native, blocked

-- Blocked trying to get lock: java/lang/Object@0x01226300[fat lock]

at jrockit/vm/Threads.waitForSignal(J)Z(Native Method)

at jrockit/vm/Locks.fatLockBlockOrSpin(ILjrockit/vm/ObjectMonitor;II)V(Unknown Source)

at jrockit/vm/Locks.lockFat(Ljava/lang/Object;ILjrockit/vm/ObjectMonitor;Z)Ljava/lang/Object;(Unknown Source)

at

jrockit/vm/Locks.monitorEnterSecondStage(Ljava/lang/Object;I)Ljava/lang/Object;(Unknown Source)

at jrockit/vm/Locks.monitorEnter(Ljava/lang/Object;)Ljava/lang/Object;(Unknown Source)

at util/repro/Thread1.run(DeadLockExample.java:34)

^-- Holding lock: java/lang/Object@0x012262F0[thin lock]

^-- Holding lock: java/lang/Object@0x012262F8[thin lock]

at jrockit/vm/RNI.c2java(IIII)V(Native Method)

-- end of trace

 "Thread-1" id=12 idx=0x20 tid=48412 prio=5 alive, in native, blocked

-- Blocked trying to get lock: java/lang/Object@0x012262F8[thin lock]

at jrockit/vm/Threads.sleep(I)V(Native Method)

at jrockit/vm/Locks.waitForThinRelease(Ljava/lang/Object;I)I(Unknown Source)

at jrockit/vm/Locks.monitorEnterSecondStage(Ljava/lang/Object;I)Ljava/lang/Object;(Unknown Source)

at jrockit/vm/Locks.monitorEnter(Ljava/lang/Object;)Ljava/lang/Object;(Unknown Source)

at util/repro/Thread2.run(DeadLockExample.java:48)

at jrockit/vm/RNI.c2java(IIII)V(Native Method)

end of trace

"Thread-2" id=13 idx=0x22 tid=48416 prio=5 alive, in native, blocked

-- Blocked trying to get lock: java/lang/Object@0x012262F8[thin lock]

at jrockit/vm/Threads.sleep(I)V(Native Method)

at jrockit/vm/Locks.waitForThinRelease(Ljava/lang/Object;I)I(Unknown Source)

at jrockit/vm/Locks.monitorEnterSecondStage(Ljava/lang/Object;I)Ljava/lang/Object;(Unknown Source)

at jrockit/vm/Locks.monitorEnter(Ljava/lang/Object;)Ljava/lang/Object;(Unknown Source)

at util/repro/Thread3.run(DeadLockExample.java:65)

^-- Holding lock: java/lang/Object@0x01226300[fat lock]

at jrockit/vm/RNI.c2java(IIII)V(Native Method)

-- end of trace

All three threads are in a blocked state (indicated by blocked), which means that they are all trying to enter synchronized blocks. Thread-0 is trying to take Object@0x01226300[fat lock] but this is held by Thread-2. Both Thread-2 and Thread-1 are trying to take Object@0x012262F8[thin lock] but this lock is held by Thread-0. This means that Thread-0 and Thread-2 form a deadlock, while Thread-1 is blocked.

Lock Chains

One prominent feature of the JRockit JVM is that it automatically detects deadlocked, blocked and open lock chains among the running threads.

The analysis in presents the all the lock chains created by the threads T1, T2, T3, T4 and T5.  This information can be used to tune and troubleshoot your Java code.

Circular (deadlocked) lock chains

Chain 6:

"Dead T1" id=16 idx=0x48 tid=3648 waiting for java/lang/Object@0x01225018 held by:

"Dead T3" id=18 idx=0x50 tid=900 waiting for java/lang/Object@0x01225010 held by:

"Dead T2" id=17 idx=0x4c tid=3272 waiting for java/lang/Object@0x01225008 held by:

"Dead T1" id=16 idx=0x48 tid=3648

Blocked lock chains

Chain 7:

"Blocked T2" id=20 idx=0x58 tid=3612 waiting for java/lang/Object@0x01225310 held by:

"Blocked T1" id=19 idx=0x54 tid=2500 waiting for java/lang/Object@0x01224B60 held by:

"Open T3" id=13 idx=0x3c tid=1124 in chain 1

Open lock chains

Chain 1:

"Open T5" id=15 idx=0x44 tid=4048 waiting for java/lang/Object@0x01224B68 held by:

"Open T4" id=14 idx=0x40 tid=3380 waiting for java/lang/Object@0x01224B60 held by:

"Open T3" id=13 idx=0x3c tid=1124 waiting for java/lang/Object@0x01224B58 held by:

"Open T2" id=12 idx=0x38 tid=3564 waiting for java/lang/Object@0x01224B50 held by:

"Open T1" id=11 idx=0x34 tid=2876 (active)

Thread Status in Thread Dumps

This section describes the different statuses or states a thread can show in a thread dump. There are three types of states:

1. Life States
2. Run States

Life States

Thread Life States
State	Description
alive	This is a normal, running thread. Virtually all threads in the thread dump will be alive.
not started	The thread has been requested to start running by java.lang.Thread.start(), but the actual OS process has not yet started, or executed far enough to pass control to the JRockit JVM. It is extremely unlikely to see this value. A java.lang.Thread object that is created, but not has had start() executed, will not show up in the thread dump.
terminated	This thread has finished its run() method and has also notified any threads joining on it, but it is still kept in the JVM internal thread structure for running threads. It is extremely unlikely to see this value. A thread that has been terminated for a time longer than a few milliseconds will not show up in the thread dump.

 

Run States

Thread Run States
State	Description
blocked	This thread has tried to enter a synchronized block, but the lock was taken by another thread. This thread is blocked until the lock gets released.
blocked (on thin lock)	This is the same state as blocked, but with the additional information that the lock in question is a thin lock.
waiting	This thread has called Object.wait() on an object. The thread will remain there until some other thread sends a notification on that object.
sleeping	This thread has called java.lang.Thread.sleep().
parked	This thread has called java.util.concurrent.locks.LockSupport.park().
suspended	The thread’s execution has been suspended by java.lang.Thread.suspend() or a JVMTI/JVMPI agent call

Thanks
Sathya