JAVA Thread Dump 文件剖析
Thread Dump 介绍
Thread Dump 是十分有用的诊断 Java 利用问题的工具。每一个 Java 虚拟机都有及时生成所有线程在某一点状态的 thread-dump 的能力,尽管各个 Java 虚拟机打印的 thread dump 略有不同,然而大多都提供了每个线程的所有信息,例如: 线程状态、线程 Id、本机 Id、线程名称、堆栈跟踪、优先级。
Thread Dump 特点
- 能在各种操作系统下应用
- 能在各种 Java 应用服务器下应用
- 能够在生产环境下应用而不影响零碎的性能
- 能够将问题间接定位到应用程序的代码行上(对于线上排查问题十分有用)
它能帮咱们解决哪些线上问题?
Thread dump 能帮咱们定位到 例如 CPU 峰值、应用程序中的无响应性、响应时间差、线程挂起、高内存耗费。
如何抓取 Thread Dump
个别当服务器挂起, 解体或者性能底下时, 就须要抓取服务器的线程堆栈 (Thread Dump) 用于后续的剖析. 在理论运行中,往往一次 dump 的信息,还不足以确认问题。为了反映线程状态的动态变化,须要接连屡次做 threaddump,每次距离 10-20s,倡议至多产生三次 dump 信息,如果每次 dump 都指向同一个问题,咱们才确定问题的典型性。
获取 thread dump
JDK 自带命令行工具获取 PID,再获取 ThreadDump:
1. jps 或 ps –ef|grep java (获取 PID)
2. jstack [-l]<pid> | tee -a jstack.log (获取 ThreadDump)
实操演练
获取所有线程的 thread dump 分两步.
- 第一步 获取过程的 PID
应用 Jps 获取所有 java 过程的信息
- 第二步 选取对应的 pid 例如上图红框中的数字串 应用 Jstack 获取所有线程栈信息
jstack -l 9468 | tee -a jstack.log
日志字段剖析
咱们把 Thread dump 文件分为 2 个局部来了解
拿咱们的例子来说:
// 头部信息 蕴含 以后工夫 jvm 信息
2021-01-14 17:00:51
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.171-b11 mixed mode):
// 线程 info 信息块
"ajp-nio-8019-exec-7" #75 daemon prio=5 os_prio=0 tid=0x00007fa0cc37e800 nid=0x2af3 waiting on condition [0x00007fa02eceb000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000f183aa30> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:103)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:31)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)
线程 info 信息块各个参数的意义:
- 线程名称:ajp-nio-8019-exec-7
- 线程类型:daemon
- 优先级: 默认是 5
- jvm 线程 id:tid=0x00007fa0cc37e800,jvm 外部线程的惟一标识(通过 java.lang.Thread.getId()获取,通常用自增形式实现。)
- 对应零碎线程 id(NativeThread ID):nid=0x2af3,和 top 命令查看的线程 pid 对应,不过一个是 10 进制,一个是 16 进制。(通过命令:top -H -p pid,能够查看该过程的所有线程信息)
- 线程状态:java.lang.Thread.State: WAITING (parking)
- 线程调用栈信息:用于代码的剖析。堆栈信息应该从下向上解读,因为程序调用的程序是从下向上的。
零碎线程状态 (Native Thread Status)
零碎线程有如下状态:
- deadlock
死锁线程,个别指多个线程调用期间进入了互相资源占用,导致始终期待无奈开释的状况。
- runnable
个别指该线程正在执行状态中,该线程占用了资源,正在解决某个操作,如通过 SQL 语句查询数据库、对某个文件进行写入等。
- blocked
线程正处于阻塞状态,指以后线程执行过程中,所须要的资源长时间期待却始终未能获取到,被容器的线程管理器标识为阻塞状态,能够了解为期待资源超时的线程。
- waiting on condition
线程正处于期待资源或期待某个条件的产生,具体的起因须要联合上面堆栈信息进行剖析。
(1)如果堆栈信息明确是利用代码,则证实该线程正在期待资源,个别是大量读取某种资源且该资源采纳了资源锁的状况下,线程进入期待状态,期待资源的读取,或者正在期待其余线程的执行等。
(2)如果发现有大量的线程都正处于这种状态,并且堆栈信息中得悉正等待网络读写,这是因为网络阻塞导致线程无奈执行,很有可能是一个网络瓶颈的征兆:
网络十分忙碌,简直耗费了所有的带宽,依然有大量数据期待网络读写;
网络可能是闲暇的,但因为路由或防火墙等起因,导致包无奈失常达到;
所以肯定要联合零碎的一些性能察看工具进行综合剖析,比方 netstat 统计单位工夫的发送包的数量,看是否很显著超过了所在网络带宽的限度;察看 CPU 的利用率,看零碎态的 CPU 工夫是否显著大于用户态的 CPU 工夫。这些都指向因为网络带宽所限导致的网络瓶颈。
(3)还有一种常见的状况是该线程在 sleep,期待 sleep 的工夫到了,将被唤醒。
- waiting for monitor entry 或 in Object.wait()
Moniter 是 Java 中用以实现线程之间的互斥与合作的次要伎俩,它能够看成是对象或者 class 的锁,每个对象都有,也仅有一个 Monitor。
从上图能够看出,每个 Monitor 在某个时刻只能被一个线程领有,该线程就是 “Active Thread”,而其余线程都是 “Waiting Thread”,别离在两个队列 “Entry Set” 和 ”Wait Set” 外面期待。其中在 “Entry Set” 中期待的线程状态是 waiting for monitor entry,在 “Wait Set” 中期待的线程状态是 in Object.wait()。
(1)”Entry Set” 外面的线程。
咱们称被 synchronized 爱护起来的代码段为临界区,对应的代码如下:
synchronized(obj) {}
当一个线程申请进入临界区时,它就进入了 “Entry Set” 队列中,这时候有两种可能性:
- 该 Monitor 不被其余线程领有,”Entry Set” 外面也没有其余期待的线程。本线程即成为相应类或者对象的 Monitor 的 Owner,执行临界区外面的代码;此时在 Thread Dump 中显示线程处于 “Runnable” 状态。
- 该 Monitor 被其余线程领有,本线程在 “Entry Set” 队列中期待。此时在 Thread Dump 中显示线程处于 “waiting for monity entry” 状态。
临界区的设置是为了保障其外部的代码执行的原子性和完整性,但因为临界区在任何工夫只容许线程串行通过,这和咱们应用多线程的初衷是相同的。如果在多线程程序中大量应用 synchronized,或者不适当的应用它,会造成大量线程在临界区的入口期待,造成零碎的性能大幅降落。如果在 Thread Dump 中发现这个状况,应该扫视源码并对其进行改良。
(2)”Wait Set” 外面的线程
当线程取得了 Monitor,进入了临界区之后,如果发现线程持续运行的条件没有满足,它则调用对象(通常是被 synchronized 的对象)的 wait()办法,放弃 Monitor,进入 “Wait Set” 队列。只有当别的线程在该对象上调用了 notify()或者 notifyAll()办法,”Wait Set” 队列中的线程才失去机会去竞争,然而只有一个线程取得对象的 Monitor,复原到运行态。”Wait Set” 中的线程在 Thread Dump 中显示的状态为 in Object.wait()。
通常来说,当 CPU 很忙的时候关注 Runnable 状态的线程,反之则关注 waiting for monitor entry 状态的线程。
JVM 线程状态
NEW:
每一个线程,在堆内存中都有一个对应的 Thread 对象。Thread t = new Thread(); 当刚刚在堆内存中创立 Thread 对象,还没有调用 t.start()办法之前,线程就处在 NEW 状态。在这个状态上,线程与一般的 java 对象没有什么区别,就仅仅是一个堆内存中的对象。RUNNABLE:
该状态示意线程具备所有运行条件,在运行队列中筹备操作系统的调度,或者正在运行。这个状态的线程比拟失常,但如果线程长时间停留在在这个状态就不失常了,这阐明线程运行的工夫很长(存在性能问题),或者是线程始终得不得执行的机会(存在线程饥饿的问题)。BLOCKED:
线程正在期待获取 java 对象的监视器(也叫内置锁),即线程正在期待进入由 synchronized 爱护的办法或者代码块。synchronized 用来保障原子性,任意时刻最多只能由一个线程进入该临界区域,其余线程只能排队期待。WAITING:
处在该线程的状态,正在期待某个事件的产生,只有特定的条件满足,能力取得执行机会。而产生这个特定的事件,通常都是另一个线程。也就是说,如果不产生特定的事件,那么处在该状态的线程始终期待,不能获取执行的机会。比方:
A 线程调用了 obj 对象的 obj.wait()办法,如果没有线程调用 obj.notify 或 obj.notifyAll,那么 A 线程就没有方法复原运行;如果 A 线程调用了 LockSupport.park(),没有别的线程调用 LockSupport.unpark(A),那么 A 没有方法复原运行。TIMED_WAITING:
J.U.C 中很多与线程相干类,都提供了限时版本和不限时版本的 API。TIMED_WAITING 意味着线程调用了限时版本的 API,正在等待时间流逝。当等待时间过来后,线程一样能够复原运行。如果线程进入了 WAITING 状态,肯定要特定的事件产生能力复原运行;而处在 TIMED_WAITING 的线程,如果特定的事件产生或者是工夫流逝结束,都会复原运行。TERMINATED:
线程执行结束,执行完 run 办法失常返回,或者抛出了运行时异样而完结,线程都会停留在这个状态。这个时候线程只剩下 Thread 对象了,没有什么用了。
依据 dump 日志剖析
上面咱们依据理论的代码 来剖析 dump 日志, 能够更加通明的理解线程为什么是这个状态
例子 1:
期待开释锁
package jstack;
public class BlockedState
{private static Object object = new Object();
public static void main(String[] args)
{Runnable task = new Runnable() {
@Override
public void run()
{synchronized (object)
{long begin = System.currentTimeMillis();
long end = System.currentTimeMillis();
// 让线程运行 5 分钟, 会始终持有 object 的监视器
while ((end - begin) <= 5 * 60 * 1000)
{}}
}
};
new Thread(task, "t1").start();
new Thread(task, "t2").start();}
}
先获取 object 的线程会执行 5 分钟,这 5 分钟内会始终持有 object 的监视器,另一个线程无奈执行处在 BLOCKED 状态
"t2" prio=6 tid=0x27d7a800 nid=0x1350 waiting for monitor entry [0x2833f000]
java.lang.Thread.State: BLOCKED (on object monitor)
at jstack.BlockedState$1.run(BlockedState.java:17)
- waiting to lock <0x1cfcdc00> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:662)
"t1" prio=6 tid=0x27d79400 nid=0x1338 runnable [0x282ef000]
java.lang.Thread.State: RUNNABLE
at jstack.BlockedState$1.run(BlockedState.java:22)
- locked <0x1cfcdc00> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:662)
通过 thread dump 能够看到:t2 线程在 BLOCKED (on object monitor)。waiting for monitor entry 期待进入 synchronized 爱护的区域,但 obj 对应的 Monitor 被其余线程所领有,所以 JVM 线程的状态是 java.lang.Thread.State: BLOCKED (on object monitor),阐明线程期待资源。
例子 2:
死锁
public class DeadLock {public static void main(String[] args) {
final Object resource1 = "resource1";
final Object resource2 = "resource2";
Thread t1 = new Thread(){public void run(){synchronized(resource1){System.out.println("Thread1:locked resource1");
try{Thread.sleep(50);
}catch(Exception ex){ }
synchronized(resource2){System.out.println("Thread1:locked resource2");
}
}
}
};
Thread t2 = new Thread(){public void run(){synchronized(resource2){System.out.println("Thread2:locked resource2");
try{Thread.sleep(50);
}catch(Exception ex){ }
synchronized(resource1){System.out.println("Thread2:locked resource1");
}
}
}
};
t1.start();
t2.start();}
}
咱们的这段代码是让两个线程相互期待对象开释锁, 造成死锁的状况, 在这种状况下, 获取 Thread dump 文件 咱们会发现 jvm 曾经提醒咱们死锁了 如下:
"Thread-1" #20 prio=5 os_prio=31 tid=0x00007fb76c0e1800 nid=0x9d03 waiting for monitor entry [0x0000700004dbf000]
java.lang.Thread.State: BLOCKED (on object monitor)
at DeadLock$2.run(DeadLock.java:35)
- waiting to lock <0x000000076af61870> (a java.lang.String)
- locked <0x000000076af618b0> (a java.lang.String)
"Thread-0" #19 prio=5 os_prio=31 tid=0x00007fb76c002800 nid=0x9e03 waiting for monitor entry [0x0000700004cbc000]
java.lang.Thread.State: BLOCKED (on object monitor)
at DeadLock$1.run(DeadLock.java:19)
- waiting to lock <0x000000076af618b0> (a java.lang.String)
- locked <0x000000076af61870> (a java.lang.String)
Found one Java-level deadlock:
=============================
"Thread-1":
waiting to lock monitor 0x00007fb769825b58 (object 0x000000076af61870, a java.lang.String),
which is held by "Thread-0"
"Thread-0":
waiting to lock monitor 0x00007fb769823168 (object 0x000000076af618b0, a java.lang.String),
which is held by "Thread-1"
Java stack information for the threads listed above:
===================================================
"Thread-1":
at DeadLock$2.run(DeadLock.java:35)
- waiting to lock <0x000000076af61870> (a java.lang.String)
- locked <0x000000076af618b0> (a java.lang.String)
"Thread-0":
at DeadLock$1.run(DeadLock.java:19)
- waiting to lock <0x000000076af618b0> (a java.lang.String)
- locked <0x000000076af61870> (a java.lang.String)
Found 1 deadlock.
例子 3
调用 wait(),sleep()对应的线程状态
public static void main(String[] args) {Thread thread = new Thread("线程 1") {
// 重写 run 办法
public void run() {synchronized (this) {System.out.println(Thread.currentThread().getName());
try {wait();
} catch (InterruptedException e) {e.printStackTrace();
}
}
}
};
thread.start();
try {TimeUnit.SECONDS.sleep(3);
} catch (InterruptedException e) {e.printStackTrace();
}
synchronized (thread) {System.out.println(Thread.currentThread().getName());
try {TimeUnit.SECONDS.sleep(60);
} catch (InterruptedException e) {e.printStackTrace();
}
thread.notify();}
}
下面代码会先执行线程 1 run()办法,而后调用 wait()办法阻塞 block 住。等到主线程调用 thread.notify()办法之后才会持续往下执行。咱们在程序跑起来之后大略 10 秒时候导出 thread dump 日志文件信息,此时:
"线程 1" #12 prio=5 os_prio=0 tid=0x00007f420024d800 nid=0x1ca5 in Object.wait() [0x00007f41e71ee000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000d8258ba0> (a com.jvm.study.threaddump.deadlock.ObjectWaitingMock$1)
at java.lang.Object.wait(Object.java:502)
at com.jvm.study.threaddump.deadlock.ObjectWaitingMock$1.run(ObjectWaitingMock.java:15)
- locked <0x00000000d8258ba0> (a com.jvm.study.threaddump.deadlock.ObjectWaitingMock$1)
Locked ownable synchronizers:
- None
....(其余信息这里咱们省略掉)
"main" #1 prio=5 os_prio=0 tid=0x00007f420000d800 nid=0x1c84 waiting on condition [0x00007f4209891000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at java.lang.Thread.sleep(Thread.java:340)
at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
at com.jvm.study.threaddump.deadlock.ObjectWaitingMock.main(ObjectWaitingMock.java:31)
- locked <0x00000000d8258ba0> (a com.jvm.study.threaddump.deadlock.ObjectWaitingMock$1)
Locked ownable synchronizers:
- None
- [线程 1]线程:wait()办法阻塞住了,状态对应 in Object.wait(),状态详细信息对应 java.lang.Thread.State: WAITING (on object monitor)。
- [main]线程:TimeUnit.SECONDS.sleep(60)阻塞住了,状态对应 waiting on condition,状态详细信息对应 java.lang.Thread.State: TIMED_WAITING (sleeping)。
依据案例症状剖析解决方案
- 1 CPU 占用率不高,但响应很慢
在整个申请的过程中屡次执行 Thread Dump 而后进行比照,获得 BLOCKED 状态的线程列表,通常是因为线程停在了 I /O、数据库连贯或网络连接的中央。
- 2 CPU 飙高,load 高,响应很慢
一个申请过程中屡次 dump;比照屡次 dump 文件的 runnable 线程,如果执行的办法有比拟大变动,阐明比拟失常。如果在执行同一个办法,就有一些问题了;先找到占用 CPU 的过程,而后再定位到对应的线程,最初剖析出对应的堆栈信息。
在同一时间屡次应用上述的办法,而后进行比照剖析,从代码中找到问题所在的起因.
- 3 申请无奈响应
屡次 dump,查看是否有 Found one Java-level deadlock 提醒, 死锁常常体现为程序的进展,或者不再响应用户的申请。从操作系统上察看,对应过程的 CPU 占用率为零,很快会从 top 或 prstat 的输入中隐没。
关注公众号:java 宝典