-
Enhancement
-
Resolution: Fixed
-
P4
-
11
-
b20
-
generic
-
generic
Issue | Fix Version | Assignee | Priority | Status | Resolution | Resolved In Build |
---|---|---|---|---|---|---|
JDK-8206792 | 12 | Gunter Haug | P4 | Resolved | Fixed | team |
JDK-8206569 | 11.0.1 | Gunter Haug | P4 | Resolved | Fixed | b01 |
We at SAP have extended the thread dumps (obtained by jstack or jcmd) by several fields providing thread specific information. These extensions are quite popular with our support team. With some knowledge of the architecture of the application, they often allow for quick and simple diagnosis of a running system. Therefore we would like to contribute these enhancements.
I took a few simple examples here, namely cpu time, elapsed time since thread creation, bytes allocated and classes defined by the thread. Provided it is known how the application should behave, a misbehaving thread can identified easily.
There is no measurable overhead for this enhancement. However, it may be a problem that the format of the output is changed. Tools parsing the output may have to be changed.
The added values are:
- cpu=... : the time the thread spent executing on the CPU.
- elapsed=... : the wall clock time passed since the thread was started.
These two values allow you to detect threads that either spend too much time on the CPU or too less.
The first ones might be a perfromance bottleneck. Threads that spend no time on the CPU might be
blocked by something. This can especially be spotted by comparing subsequent thread dumps.
- allocated=... : The number of bytes allocated by this thread.
This might hint to a thread that tends to fill up the heap and cause too many garbage collections.
- defined_classes=... : The number of classes defined by this thread
This might hint to a thread that loads too many classes.
The values 'allocated=' and 'defined_classes=' are only printed if the VM is started with -XX:+PrintExtendedThreadInfo.
If the thread dumps are gathered by jcmd, '-e' must be added to the Thread.print command.
Here is an example of the output generated:
"main" #1 prio=5 os_prio=31 cpu=5884.26ms elapsed=42.41s allocated=155M defined_classes=1728 tid=0x00007fad8e801800 nid=0x2103 waiting on condition [0x0000000104f18000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
JavaThread state: _thread_blocked
Thread: 0x00007fad8e801800 [0x2103] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
JavaThread state: _thread_blocked
at java.lang.Thread.sleep(java.base/Native Method)
at spec.jbb.JBButil.SecondsToSleep(JBButil.java:359)
at spec.jbb.Company.displayResultTotals(Company.java:464)
at spec.jbb.JBBmain.DoARun(JBBmain.java:223)
at spec.jbb.JBBmain.runWarehouse(JBBmain.java:310)
at spec.jbb.JBBmain.doIt(JBBmain.java:261)
at spec.jbb.JBBmain.main(JBBmain.java:711)
Printing the pthread_id was dropped from this RFE.
I took a few simple examples here, namely cpu time, elapsed time since thread creation, bytes allocated and classes defined by the thread. Provided it is known how the application should behave, a misbehaving thread can identified easily.
There is no measurable overhead for this enhancement. However, it may be a problem that the format of the output is changed. Tools parsing the output may have to be changed.
The added values are:
- cpu=... : the time the thread spent executing on the CPU.
- elapsed=... : the wall clock time passed since the thread was started.
These two values allow you to detect threads that either spend too much time on the CPU or too less.
The first ones might be a perfromance bottleneck. Threads that spend no time on the CPU might be
blocked by something. This can especially be spotted by comparing subsequent thread dumps.
- allocated=... : The number of bytes allocated by this thread.
This might hint to a thread that tends to fill up the heap and cause too many garbage collections.
- defined_classes=... : The number of classes defined by this thread
This might hint to a thread that loads too many classes.
The values 'allocated=' and 'defined_classes=' are only printed if the VM is started with -XX:+PrintExtendedThreadInfo.
If the thread dumps are gathered by jcmd, '-e' must be added to the Thread.print command.
Here is an example of the output generated:
"main" #1 prio=5 os_prio=31 cpu=5884.26ms elapsed=42.41s allocated=155M defined_classes=1728 tid=0x00007fad8e801800 nid=0x2103 waiting on condition [0x0000000104f18000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
JavaThread state: _thread_blocked
Thread: 0x00007fad8e801800 [0x2103] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0
JavaThread state: _thread_blocked
at java.lang.Thread.sleep(java.base/Native Method)
at spec.jbb.JBButil.SecondsToSleep(JBButil.java:359)
at spec.jbb.Company.displayResultTotals(Company.java:464)
at spec.jbb.JBBmain.DoARun(JBBmain.java:223)
at spec.jbb.JBBmain.runWarehouse(JBBmain.java:310)
at spec.jbb.JBBmain.doIt(JBBmain.java:261)
at spec.jbb.JBBmain.main(JBBmain.java:711)
Printing the pthread_id was dropped from this RFE.
- backported by
-
JDK-8206569 Print additional information in thread dump (times, allocated bytes etc.)
-
- Resolved
-
-
JDK-8206792 Print additional information in thread dump (times, allocated bytes etc.)
-
- Resolved
-
- csr for
-
JDK-8205604 Add command line option controlling additional information in thread dump
-
- Closed
-
- relates to
-
JDK-8143176 Show how long a thread has been waiting for a lock in thread dumps
-
- Closed
-