程序地带

JVM Thread Dump 文件分析


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:


jps 或 ps –ef|grep java (获取PID)

jstack [-l ] | 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™ 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
C
o
n
d
i
t
i
o
n
O
b
j
e
c
t
)
a
t
j
a
v
a
.
u
t
i
l
.
c
o
n
c
u
r
r
e
n
t
.
l
o
c
k
s
.
L
o
c
k
S
u
p
p
o
r
t
.
p
a
r
k
(
L
o
c
k
S
u
p
p
o
r
t
.
j
a
v
a
:
175
)
a
t
j
a
v
a
.
u
t
i
l
.
c
o
n
c
u
r
r
e
n
t
.
l
o
c
k
s
.
A
b
s
t
r
a
c
t
Q
u
e
u
e
d
S
y
n
c
h
r
o
n
i
z
e
r
ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer
ConditionObject)atjava.util.concurrent.locks.LockSupport.park(LockSupport.java:175)atjava.util.concurrent.locks.AbstractQueuedSynchronizerConditionObject.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
W
o
r
k
e
r
.
r
u
n
(
T
h
r
e
a
d
P
o
o
l
E
x
e
c
u
t
o
r
.
j
a
v
a
:
624
)
a
t
o
r
g
.
a
p
a
c
h
e
.
t
o
m
c
a
t
.
u
t
i
l
.
t
h
r
e
a
d
s
.
T
a
s
k
T
h
r
e
a
d
Worker.run(ThreadPoolExecutor.java:624) at org.apache.tomcat.util.threads.TaskThread
Worker.run(ThreadPoolExecutor.java:624)atorg.apache.tomcat.util.threads.TaskThreadWrappingRunnable.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)如果发现有大量的线程都正处于这种状态,并且堆栈信息中得知正等待网络读写,这是因为网络阻塞导致线程无法执行,很有可能是一个网络瓶颈的征兆:


网络非常繁忙,几乎消耗了所有的带宽,仍然有大量数据等待网络读写; 网络可能是空闲的,但由于路由或防火墙等原因,导致包无法正常到达; 所以一定要结合系统的一些java基础性能观察工具进行综合分析,比如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的输出中消失。


版权声明:本文为博主原创文章,遵循 CC 4.0 BY-SA 版权协议,转载请附上原文出处链接和本声明。
本文链接:https://blog.csdn.net/chinaherolts2008/article/details/112689121

随机推荐

Linux&MacOS常用命令

最近在Mac上安装Jdk的时候,发现Mac上的指令一丁点都不熟悉,因此鉴于Linux和Mac都是基于Unix内核的总结一下常用的命令行,以后一定要多多使用&#...

Techyu 阅读(617)

静态变量的注意事项

1)定义静态的变量----成员位置----成员变量—加入static2)非静态的成员方法能不能访问静态的成员变量呢?既可以访问非静态的成员变量,也可以访问静态的变量!3)非静态的成员方法...

kblm 阅读(518)

测试版公众号-获取openid

没有企业认证服务号想学习公众号开发,可以申请测试版公众号 点击后扫码登录即可往下拉可以看到能调用的接口按照要求填写内容即可(域名自己准备,没有可以尝试用内网穿...

fuhouyin 阅读(400)

读取xml数据

参考:(https://www.cnblogs.com/planezhong/p/10068825.html)xml数据:<?xmlversion="...

萤火之森_LI 阅读(672)

jdbc连接基础

jdbc连接基础jdbc数据库连接方式一:方式二;方式三:...

程序设计师 阅读(217)