|
|
This chapter describes how to get and use Oracle JRockit JVM thread dumps. For basic background information about threads and thread synchronization, see Understanding Threads and Locks.
A thread dump is a snapshot of the state of all threads that are part of the process. 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:
To create a thread dump from a process, do either of the following:
The thread dump appears at the command line.
| Note: | For more information about jrcmd and Ctrl-Break handlers, see Running Diagnostic Commands. |
This section describes the typical contents of a thread dump by going through an example thread dump from the beginning to end. First, an example thread dump, broken up into its components is presented (see Listing 20-1, Listing 20-2, Listing 20-3, Listing 20-4 and Listing 20-5). 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.
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 thread dump starts with the date and time of the dump, and the version number of the JRockit JVM used (see Listing 20-1).
===== 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
Listing 20-2 shows the stack trace of the main application thread. There is a thread information line, followed by information about locks and a trace of the thread’s stack at the moment of 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 in Listing 20-2 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.
For each thread, the JRockit JVM prints the following information:
Object.wait()), this is indicated at the top of the stack trace as “Waiting for notification”.^-- 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.
The lines with the lock information might not always be correct, due to compiler optimizations. This means two things:
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.
Listing 20-3 shows the traces of 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().
"(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 Listing 20-3. 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
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. Listing 20-4 shows the stack traces of three different 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.
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 Listing 20-5 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)
This section describes the different statuses or states a thread can show in a thread dump. There are three types of states:
Table 20-1 describes the life states a thread can show in a thread dump.
Table 20-2 describes the run states a thread can show in a thread dump.
Table 20-3 describes the special states a thread can show in a thread dump. Note that all these states are not mutually exclusive.
This section contains information on about how to use thread dumps for troubleshooting and diagnostics.
To use thread dumps for troubleshooting, beyond detecting deadlocks, you need to take several thread dumps from the same process. However, if you want to do long time analysis of behavior you will likely be more helped by combining occasional thread dumps with other diagnostics tools, such as the JRockit Runtime Analyzer, which is part of Oracle JRockit Mission Control (see Using Oracle JRockit Mission Control Tools for more information).
The Oracle JRockit JVM automatically analyzes the thread dump information and detects whether there exists any circular (deadlocked) or blocked lock chains in it.
For detecting more than deadlocks in your threads, you have to make several consecutive thread dumps. This lets you detect the occurrence of contention, where multiple threads are trying to get the same lock. Contention might create long open lock chains that, while not deadlocked, will degrade performance.
If you discover (in a set of consecutive thread dumps) that one or more threads in your application is temporarily stuck waiting for a lock to be released, then you might have reason to look over the code of your Java application to see if the synchronization (serialization) is necessary or if the threads can be organized differently.
By making several consecutive thread dumps, you might quickly get an overview of which parts of your Java application that are most heavily used. However, you should consult the Threads tab in JRockit Management Console for more detailed information about the workload on the different parts of your application.
|