JDK14 performance management tool: introduction to jstack

Posted by unidox on Sat, 30 May 2020 03:56:47 +0200

brief introduction

In the previous article, we introduced the use of jstat tool in JDK14. In this article, we will further explore the use of jstack tool.

jstack tool is mainly used to print java stack information, mainly java class name, method name, bytecode index, row number and other information.

More highlights:

More at www.flydean.com

Command format of jstack

Usage:
    jstack [-l][-e] <pid>
        (to connect to running process)

Options:
    -l  long listing. Prints additional information about locks
    -e  extended listing. Prints additional information about threads
    -? -h --help -help to print this help message

The parameters of jstack are relatively simple. l can contain lock information, and e can contain additional information.

Use of jstack

Let's take an example:

jstack -l -e 53528

The output results are as follows:

2020-05-09 21:46:51
Full thread dump Java HotSpot(TM) 64-Bit Server VM (14.0.1+7 mixed mode, sharing):

Threads class SMR info:
_java_thread_list=0x00007fda0660eb00, length=14, elements={
0x00007fda04811000, 0x00007fda05845800, 0x00007fda05012000, 0x00007fda05847800,
0x00007fda05843800, 0x00007fda05854800, 0x00007fda0481f000, 0x00007fda0481f800,
0x00007fda04018800, 0x00007fda041ff800, 0x00007fda05a28800, 0x00007fda05b1a800,
0x00007fda05b1d800, 0x00007fda042be000
}

"Reference Handler" #2 daemon prio=10 os_prio=31 cpu=0.67ms elapsed=66335.21s allocated=0B defined_classes=0 tid=0x00007fda04811000 nid=0x4603 waiting on condition  [0x000070000afe1000]
   java.lang.Thread.State: RUNNABLE
	at java.lang.ref.Reference.waitForReferencePendingList(java.base@14.0.1/Native Method)
	at java.lang.ref.Reference.processPendingReferences(java.base@14.0.1/Reference.java:241)
	at java.lang.ref.Reference$ReferenceHandler.run(java.base@14.0.1/Reference.java:213)

   Locked ownable synchronizers:
	- None
  
...

"VM Thread" os_prio=31 cpu=1433.78ms elapsed=66335.22s tid=0x00007fda0506b000 nid=0x4803 runnable

"GC Thread#0" os_prio=31 cpu=18.63ms elapsed=66335.23s tid=0x00007fda0502a800 nid=0x3203 runnable

"GC Thread#1" os_prio=31 cpu=19.64ms elapsed=66334.06s tid=0x00007fda050e5800 nid=0x9d03 runnable

"GC Thread#2" os_prio=31 cpu=17.72ms elapsed=66334.06s tid=0x00007fda05015000 nid=0x6203 runnable

"GC Thread#3" os_prio=31 cpu=14.57ms elapsed=66332.78s tid=0x00007fda05138800 nid=0x6503 runnable

"G1 Main Marker" os_prio=31 cpu=0.25ms elapsed=66335.23s tid=0x00007fda05031000 nid=0x3303 runnable

"G1 Conc#0" os_prio=31 cpu=14.85ms elapsed=66335.23s tid=0x00007fda05031800 nid=0x4b03 runnable

"G1 Refine#0" os_prio=31 cpu=3.25ms elapsed=66335.23s tid=0x00007fda0583a800 nid=0x4a03 runnable

"G1 Young RemSet Sampling" os_prio=31 cpu=5929.79ms elapsed=66335.23s tid=0x00007fda0505a800 nid=0x3503 runnable
"VM Periodic Task Thread" os_prio=31 cpu=21862.12ms elapsed=66335.13s tid=0x00007fda0505b000 nid=0xa103 waiting on condition

JNI global refs: 43, weak refs: 45

The output results can be divided into the following parts:

JVM virtual machine information

The first part is the information of JVM virtual machine

2020-05-09 21:46:51
Full thread dump Java HotSpot(TM) 64-Bit Server VM (14.0.1+7 mixed mode, sharing):

It shows the thread dump time of the virtual machine and the version of the virtual machine.

Threads class SMR info

The second part is the internal thread information of non JVM (non VM and non GC threads) in the JVM.

Threads class SMR info:
_java_thread_list=0x00007fda0660eb00, length=14, elements={
0x00007fda04811000, 0x00007fda05845800, 0x00007fda05012000, 0x00007fda05847800,
0x00007fda05843800, 0x00007fda05854800, 0x00007fda0481f000, 0x00007fda0481f800,
0x00007fda04018800, 0x00007fda041ff800, 0x00007fda05a28800, 0x00007fda05b1a800,
0x00007fda05b1d800, 0x00007fda042be000
}

These elements match the tid of the subsequent thread. Represents the address of the local thread object. Note that these are not thread IDs.

You may notice that SMR is written in it. The full name of SMR is Safe Memory Reclamation.

What is SMR? Simply speaking, it is safe memory allocation. Generally, this problem will appear in non automatic GC programming languages such as C + +. In these languages, we need to allocate memory for objects and destroy objects by ourselves, which may lead to an address may be allocated to multiple objects in a multithreaded environment, resulting in unsafe memory allocation.

Thread information

The third part is the specific information of thread:

"Reference Handler" #2 daemon prio=10 os_prio=31 cpu=0.67ms elapsed=66335.21s allocated=0B defined_classes=0 tid=0x00007fda04811000 nid=0x4603 waiting on condition  [0x000070000afe1000]
   java.lang.Thread.State: RUNNABLE
	at java.lang.ref.Reference.waitForReferencePendingList(java.base@14.0.1/Native Method)
	at java.lang.ref.Reference.processPendingReferences(java.base@14.0.1/Reference.java:241)
	at java.lang.ref.Reference$ReferenceHandler.run(java.base@14.0.1/Reference.java:213)

   Locked ownable synchronizers:
	- None

According to the order of fields, we can divide the thread information into the following parts:

  • Thread Name: for example, Reference Handler
  • ID of thread: for example, 2
  • Whether to guard threads: for example, daemon, which is a low priority thread, serves user threads. Because of the low priority of the daemon threads and the fact that only user threads are serviced, the JVM will automatically exit when all user threads are finished, regardless of whether there are still daemon threads running.
  • Priority: for example, prio=10
  • Priority of OS thread: for example, os_prio=31
  • CPU time: the time when the thread obtains the CPU, for example, cpu=0.67ms
  • elapsed: wall clock time after thread startup
  • Allocated: the number of allocated bytes allocated by this thread
  • defined_classes: number of class es defined by this thread

Note 'allocated =' and 'defined'_ Classes = 'you must turn on - XX:+PrintExtendedThreadInfo to output data.

  • Address:java Address of thread, for example: tid=0x00007fda04811000
  • OS thread ID: for example, nid=0x4603
  • Thread status: for example, waiting on condition
  • Latest Java stack pointer: the latest Java stack pointer SP, for example: [0x0000070000afe1000]

Thread Stack Trace

Next is the thread stack information:

java.lang.Thread.State: RUNNABLE
	at java.lang.ref.Reference.waitForReferencePendingList(java.base@14.0.1/Native Method)
	at java.lang.ref.Reference.processPendingReferences(java.base@14.0.1/Reference.java:241)
	at java.lang.ref.Reference$ReferenceHandler.run(java.base@14.0.1/Reference.java:213)

The above example is the thread stack information and lists the thread status.

Locked Ownable Synchronizer

The next part is the exclusive lock object owned by the thread and available for synchronization.

Ownable Synchronizer is a synchronizer whose synchronization property is implemented by using AbstractOwnableSynchronizer or its subclass.

For example, the write lock in ReentrantLock and ReentrantReadWriteLock (note that it is not read lock, because it needs exclusivity) are two examples.

JVM Threads

Next is the thread information of the JVM. Because this thread is internal to the JVM, there is no thread ID:

"VM Thread" os_prio=31 cpu=1433.78ms elapsed=66335.22s tid=0x00007fda0506b000 nid=0x4803 runnable

"GC Thread#0" os_prio=31 cpu=18.63ms elapsed=66335.23s tid=0x00007fda0502a800 nid=0x3203 runnable

"GC Thread#1" os_prio=31 cpu=19.64ms elapsed=66334.06s tid=0x00007fda050e5800 nid=0x9d03 runnable

"GC Thread#2" os_prio=31 cpu=17.72ms elapsed=66334.06s tid=0x00007fda05015000 nid=0x6203 runnable

"GC Thread#3" os_prio=31 cpu=14.57ms elapsed=66332.78s tid=0x00007fda05138800 nid=0x6503 runnable

"G1 Main Marker" os_prio=31 cpu=0.25ms elapsed=66335.23s tid=0x00007fda05031000 nid=0x3303 runnable

"G1 Conc#0" os_prio=31 cpu=14.85ms elapsed=66335.23s tid=0x00007fda05031800 nid=0x4b03 runnable

"G1 Refine#0" os_prio=31 cpu=3.25ms elapsed=66335.23s tid=0x00007fda0583a800 nid=0x4a03 runnable

"G1 Young RemSet Sampling" os_prio=31 cpu=5929.79ms elapsed=66335.23s tid=0x00007fda0505a800 nid=0x3503 runnable
"VM Periodic Task Thread" os_prio=31 cpu=21862.12ms elapsed=66335.13s tid=0x00007fda0505b000 nid=0xa103 waiting on condition

JNI References

The last part is the information of JNI (Java Native Interface) references. Note that these references may cause memory leakage, because these native references will not be automatically garbage collected.

JNI global refs: 43, weak refs: 45

summary

jstack is a very powerful tool for analyzing threads. I hope you can use it.

Author of this article: the flydean program

Link to this article: http://www.flydean.com/jdk14-jvm-jstack/

Source: flydean's blog

Welcome to my official account: the procedures, the more wonderful things waiting for you!

Topics: Programming Java jvm Spring Blockchain