Write it first: The thread stack should be the most effective means to locate non-functional problems of multi-threaded applications, and can be said to be a killer weapon. Thread stacks are best at analyzing the following types of problems:
The system has too high CPU for no reason.
The system is suspended, no response.
The system is running slower and slower.
Performance bottlenecks (such as inability to fully utilize the CPU, etc.)
Thread deadlock, dead loop, starvation, etc.
The system fails due to too many threads (such as the inability to create threads, etc.).
How to interpret thread stack
As shown in the following Java source code program:
package org.ccgogoing.study.stacktrace;/** * @Author: LuoChong400 * @Description: Test thread* @Date: Create in 07:27 PM 2017/12/08 */public class MyTest { Object obj1 = new Object(); Object obj2 = new Object(); public void fun1() { synchronized (obj1) { fun2(); } } public void fun2() { synchronized (obj2) { while (true) { //In order to print the stack, the function stack analysis does not exit System.out.print(""); } } public static void main(String[] args) { MyTest aa = new MyTest(); aa.fun1(); } }Run the program in Idea, then press CTRL+BREAK key to print out the thread stack information as follows:
Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.79-b02 mixed mode):"Service Thread" daemon prio=6 tid=0x0000000000c53b000 nid=0xca58 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE"C2 CompilerThread1" daemon prio=10 tid=0x000000000c516000 nid=0xd390 waiting on condition [0x000000000000000] java.lang.Thread.State: RUNNABLE"C2 CompilerThread0" daemon prio=10 tid=0x000000000c515000 nid=0xcbac waiting on condition [0x00000000000000000] java.lang.Thread.State: RUNNABLE"Monitor Ctrl-Break" daemon prio=6 tid=0x000000000c514000 nid=0xd148 runnable [0x000000000caee000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:283) at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:325) at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:177) - locked <0x00000000d7858b50> (a java.io.InputStreamReader) at java.io.InputStreamReader.read(InputStreamReader.java:184) at java.io.BufferedReader.fill(BufferedReader.java:154) at java.io.BufferedReader.readLine(BufferedReader.java:317) - locked <0x0000000d7858b50> (a java.io.InputStreamReader) at java.io.BufferedReader.readLine(BufferedReader.java:382) at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:64)"Attach Listener" daemon prio=10 tid=0x000000000000004a000 nid=0xd24c runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE"Signal Dispatcher" daemon prio=10 tid=0x0000000000c1a8800 nid=0xd200 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE"Finalizer" daemon prio=8 tid=0x0000000000ace6000 nid=0xcd74 in Object.wait() [0x000000000c13f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x000000000d7284858> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x00000000d7284858> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)"Reference Handler" daemon prio=10 tid=0x0000000000ace4800 nid=0xce34 in Object.wait() [0x0000000000bf4f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000d7284470> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:503) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) - locked <0x00000000d7284470> (a java.lang.ref.Reference$Lock)"main"prio=6 tid=0x0000000000238e800 nid=0xc940 runnable [0x00000000027af000] java.lang.Thread.State: RUNNABLE at org.ccgogoing.study.stacktrace.MyTest.fun2(MyTest.java:22) - locked <0x00000000d77d50c8> (a java.lang.Object) at org.ccgogoing.study.stacktrace.MyTest.fun1(MyTest.java:15) - locked <0x00000000d77d50b8> (a java.lang.Object) at org.ccgogoing.study.stacktrace.MyTest.main(MyTest.java:29)"VM Thread" prio=10 tid=0x000000000ace1000 nid=0xd0a8 runnable "GC task thread#0 (ParallelGC)" prio=6 tid=0x000000000023a4000 nid=0xd398 runnable "GC task thread#1 (ParallelGC)" prio=6 tid=0x00000000023a5800 nid=0xcc20 runnable "GC task thread#2 (ParallelGC)" prio=6 tid=0x00000000023a7000 nid=0xb914 runnable "GC task thread#3 (ParallelGC)" prio=6 tid=0x00000000023a9000 nid=0xd088 runnable "VM Periodic Task Thread" prio=10 tid=0x000000000c53f000 nid=0xc1b4 waiting on condition JNI global references: 138Heap PSYoungGen total 36864K, used 6376K [0x000000000d7280000, 0x00000000d7280000, 0x0000000d9b800000, 0x000000100000000) eden space 31744K, 20% used [0x000000000d7280000, 0x0000000d78ba0d0, 0x0000000d9180000) from space 5120K, 0% used [0x000000000d9680000, 0x0000000d9680000, 0x0000000d9b80000) to space 5120K, 0% used [0x000000000d9180000, 0x0000000d9180000, 0x0000000d9180000, 0x0000000d9680000) ParOldGen total 83456K, used 0K [0x000000000085800000, 0x0000000008a980000, 0x0000000d7280000) object space 83456K, 0% used [0x00000000085800000, 0x0000000085800000, 0x000000008a980000) PSPermGen total 21504K, used 3300K [0x0000000000806000000, 0x000000081b000000, 0x0000000085800000) object space 21504K, 15% used [0x000000000806000000, 0x0000000080939290, 0x0000000081b000000) object space 21504K, 15% used [0x000000000806000000, 0x00000000080939290, 0x00000000081b000000)
In the above stack output, we can see that there are many background threads and main threads, among which only the main thread belongs to Java user threads, and the others are automatically created by virtual machines. During our analysis, we only care about the user threads.
From the main thread above, you can see the calling context of the current thread in a very intuitive way. The meaning of a certain layer of the call of one thread is as follows:
at MyTest.fun1(MyTest.java:15) | | | | | | | | | +-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
In addition, there is a statement in the stack:- locked <0x0000000d77d50b8> (a java.lang.Object) indicating that the thread already has a lock<0x0000000d77d50b8>, and the angle brackets indicate the lock ID. This is automatically generated by the system. We only need to know that the stack printed every time, and the same ID means the same lock. The first line of each thread stack means as follows:
"main" prio=1 tid=0x000000000238e800 nid=0xc940 runnable [0x00000000027af000] | | | | | | | | | | | | | +--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- Since Java is a parsing language and the executing entity is a Java virtual machine, the threads in the Java language run with the local threads in the virtual machine, and are actually the local threads executing Java thread code.
Interpretation of locks
Judging from the thread stack above, the direct information contained in the thread stack is: the number of threads, the method stack called by each thread, and the current lock status. The number of threads can be counted directly; the method stack called by the thread, from the bottom to the top, means which method on which class has been called by the current thread. And the lock state seems a little tricky. The information related to the lock is as follows:
When a thread owns a lock, the thread's stack will print --locked<0x00000000d77d50c8>
When a thread is waiting for other threads to release the lock, the thread stack will print --waiting to lock<0x00000000d77d50c8>
When a thread owns a lock, but executes the wait() method of the lock, the thread stack first prints locked, and then prints --waiting on
<0x00000000d77d50c8>
Interpretation of thread state
With the help of thread stack, many types of problems can be analyzed, and CPU consumption analysis is an important part of thread stack analysis;
Threads in TIMED_WAITING and WAITING states must not consume CPU. For threads in RUNNABLE, we must judge whether they consume CPU based on the nature of the current code.
If it is pure Java operation code, it consumes CPU.
If it is network IO, it rarely consumes CPU.
If it is local code, you should judge based on the nature of the local code (the local thread stack can be obtained through pstack and gstack). If it is pure operation code, it consumes CPU. If it is suspended, it does not consume CPU. If it is IO, it does not consume much CPU.
How to analyze problems with thread stack
Thread stacks are very helpful in positioning questions of the following types:
Analysis of thread deadlock
Excessive CPU analysis caused by Java code
Violent cycle analysis
Analysis of insufficient resources
Performance bottleneck analysis
Thread deadlock analysis
I won’t explain too much about the concept of deadlock. If you don’t understand, you can check it online;
The lock ring formed by two or more threads due to the lock dependence of the loop forms a true deadlock, as follows:
Found one Java-level deadlock:======================================================================================================================================================================================================================================================================================================================================================================================================================================================================================================================= lock monitor 0x0000000000a9abc78 (object 0x000000000d77363e0, a java.lang.Object), which is held by "org.ccgogoing.study.stacktrace.deadlock.TestThread2"Java stack information for the threads listed above:============================================================================================================================================================================================================================================================================================================================================================================================================================= org.ccgogoing.study.stacktrace.deadlock.TestThread2.fun(TestThread2.java:35) - waiting to lock <0x00000000d77363d0> (a java.lang.Object) - locked <0x00000000d77363e0> (a java.lang.Object) at org.ccgogoing.study.stacktrace.deadlock.TestThread1": at org.ccgogoing.study.stacktrace.deadlock.TestThread1.fun(TestThread1.java:33) - waiting to lock <0x00000000d77363e0> (a java.lang.Object) - locked <0x00000000d77363d0> (a java.lang.Object) at org.ccgogoing.study.stacktrace.deadlock.TestThread1.run(TestThread1.java:20)Found 1 deadlock.
From the printed stack we can see "Found one Java-level deadlock:", that is, if there is a deadlock situation, the stack will directly give the deadlock analysis results.
When a set of Java threads dies, it means Game Over, these threads will always be hung there and will never be able to continue running. When the thread that has a deadlock is executing the critical functions of the system, this deadlock may cause the entire system to be paralyzed. To restore the system, the temporary and only way to avoid it is to restart the system. Then hurry up and modify the bug that caused this deadlock.
Note: Two or more threads that are deadlocked do not consume CPU. Some people believe that the CPU's 100% usage rate is caused by thread deadlock. This statement is completely wrong. The dead loop, and the code in the loop is CPU-intensive, which may lead to a 100% usage rate of the CPU. IO operations such as sockets or databases do not consume much CPU.