java 线程快照_jstack分析线程快照的三步曲及CPU占用过高和死锁问题的排查

jstack(Stack Trace For Java, 官方链接)用于生成java虚拟机某个进程在当前时刻的线程快照(一般称为threaddump或javacore文件，由线程的调用堆栈组成)，用来定位线程长时间停顿的原因，如死循环、死锁等。

一般在用该工具时主要分为三步：

获取进程id

方法1: jps -l

方法2: ps -ef|grep java

方法3: lsof -i:

上述三个方法根据具体情况选择使用，方法1最简便(适合java进程少的情况)，方法2信息更详尽，方法3则适合有多个java进程，根据方法1可能分辨不出来想找的进程，而需要通过端口号进行定位。

获取进程中的线程状态

top -Hp

注意该命令只能在linux中使用，而在macOS上不能使用。因为linux将线程作为轻量级进程也分配了pid，而macOS并没有这么处理。

如果通过上述命令我们发现进程中的某个线程指标不正常，想重点关注，这时需要将线程的pid通过下面命令转化为十六进进制，方便在线程快照信息中查找。

​ echo 'obase=16; ibase=10; ' | bc | tr '[A-Z]' '[a-z]'

查看并分析线程快照信息

用jstack 命令可以在控制台打印线程快照信息， jstack > 可以将线程快照信息输出到文件。如下为打印出来的一条线程快照，由10个部分组成。

image-20181111102804259

线程名称，如果程序中没有显示给线程命名则显示默认名称

线程序号，相当于程序所有线程的一个编号

线程优先级，java中线程的默认优先级为5

线程系统优先级

线程id

线程native id，在linux中对应线程的轻量级进程id，十六进制，通过该字段都与top命令中的线程对应起来。

线程描述

线程栈的起始地址

线程状态

线程执行堆栈，具体到代码的行数

需要注意的是执行该命令时当前用户必须为启动该进程的用户，否则会失败，即使是root用户也不行。

接下来将通过两个实例来对该工具的使用进行详细说明：

实例1: 利用线程快照分析CPU占用过高的原因

用于演示CPU示例代码如下: 启动三个线程，且某个线程获取唯一的锁后一直没有释放，可想而知，另外两个线程将处于阻塞状态。

import java.util.UUID;

public class HighCPUCase {

public static Object lock = new Object();

public static void main(String[] args) {

new Thread(new Task(), "task1").start();

new Thread(new Task(), "task2").start();

new Thread(new Task(), "task3").start();

}

static class Task implements Runnable{

@Override

public void run(){

synchronized (lock){

while (true){

System.out.println(UUID.randomUUID().toString());

}

}

}

}

}

现在用文章开始的三步曲来验证我们的猜想。

首先获取进程id

image-20181110225814867

获取进程中消耗CPU最高的线程

image-20181110230019853

将23068用如下命令转化为16进制后为5a1c

image-20181110230321690

查看并分析线程快照

image-20181110231223530

​ 上图中蓝色线框为我们需要重点关注的内容，可以看到5a1c(由第2步得到)对应的线程为task1，该线程处于RUNNABLE状态，且下在执行HighCPUCase.java中的第17行，而线程task2和task3都因为等待锁而处于BLOCKED状态。仔细观察可以发现task2和task3等待的锁与task1获得的锁完全相同。

​ 由此我们下结论，CPU高的原因是因为线程task1，而它正在执行HighCPUCase.java中的第17行，线程task2和task3处于阻塞状态是因为task1获得唯一一把锁后一直没有释放。然后我们根据结论再去看代码，分析得完全没毛病。

实例2: 利用线程快照分析死锁

下面为演示死锁的代码，模拟有两个线程A,B, 两把锁1，2，当线程1成功拿到锁1尝试去拿锁2发现拿不到，而此时线程2成功拿到锁2尝试去拿锁1也拿不到，谁也不让谁就只能干耗着了，导致程序一直不能结束。

public class DeadLockCase {

public static void main(String[] args){

Object o1 = new Object();

Object o2 = new Object();

new Thread(new SyncThread(o1, o2), "t1").start();

new Thread(new SyncThread(o2, o1), "t2").start();

}

static class SyncThread implements Runnable {

private Object lock1;

private Object lock2;

public SyncThread(Object o1, Object o2){

this.lock1 = o1;

this.lock2 = o2;

}

@Override

public void run() {

String name = Thread.currentThread().getName();

System.out.println(name + " acquiring lock on " + lock1);

synchronized (lock1) {

System.out.println(name + " acquired lock on " + lock1);

work();

System.out.println(name + " acquiring lock on " + lock2);

synchronized (lock2) {

System.out.println(name + " acquired lock on " + lock2);

work();

}

System.out.println(name + " released lock on " + lock2);

}

System.out.println(name + " released lock on " + lock1);

}

private void work() {

try {

//模拟死锁的关键，保证线程1只能获取一个锁，而线程2能获取到另一个锁

Thread.sleep(3000);

} catch (InterruptedException e) {

e.printStackTrace();

}

}

}

}

运行上面代码输出如下，可以看到符合我们的预期:

image-20181110235104076

下面还是通过线程快照来反推：

首先拿到进程id

image-20181110235201192

查看进程内的线程情况

image-20181110235336030

可以看到所有线程无异常指标，这一步还不知道哪一个线程有问题。

23152对就的十六进制数为5a70， 23144对应的十六进制数为5a68，接下来就重点关注这两个。

查看线程快照

开始部分：细心观察发现两个线程处于BLOCKED状态是因为在等相互之间的锁。

image-20181111000447280

结尾部分:很明确的告诉了你发现了一个java级别死锁，t2在待t1手上的锁，t1在等t2手上的锁。

在实际生产中肯定比这本文中涉及到的两个例子复杂，但如果能先把基础的学会，碰到问题也不会慌而是学会去分解复杂的问题，大而化小，最后方能解决问题。

参考文章：