JVM命令之jstack

简述

jstack是jdk自带的线程堆栈分析工具,使用该命令可以查看或导出Java应用中线程堆栈信息,主要用法:

image-20200511001238117
  • -F:强制打印线程堆栈信息,当jstack [-l] <pid>无响应时使用
  • -m:打印Java和native框架的所有堆栈信息
  • -l:长列表,打印关于锁的附加信息
  • -h or -help:打印帮助信息

pid是需要被打印堆栈信息的Java进程id,可以使用jps查看,通过jstack命令可以获取当前进程的所有线程信息,每个线程堆信息中可以看到线程ID、线程状态、是否持有锁等信息。

死锁排查

线程死锁的情况很简单,我们通过一张图即可理解:

image-20200511011015785

首先我们写一段死锁代码,代码逻辑很简单,写两个线程,提供两个ReentrantLock对象,在线程1中先对lock1加锁,然后再对lock2加锁,而在线程2中先对lock2加锁,再对lock1加锁,使这两个线程互相竞争锁lock1和lock2。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
import java.util.concurrent.locks.Lock;
import java.util.concurrent.locks.ReentrantLock;

public class DeadLockTest {

public static void main(String[] args) {
Lock lock1 = new ReentrantLock();
Lock lock2 = new ReentrantLock();

Thread t1 = new Thread(() -> {
try {
lock1.lock();
System.out.println("cc1获取到lock1");
Thread.sleep(1000);
lock2.lock();
System.out.println("cc1获取到lock2");
} catch (InterruptedException e) {
e.printStackTrace();
} finally {
lock1.unlock();
lock2.unlock();
}
}, "cc1");
Thread t2 = new Thread(() -> {
try {
lock2.lock();
System.out.println("cc2获取到lock2");
Thread.sleep(1000);
lock1.lock();
System.out.println("cc2获取到lock1");
} catch (InterruptedException e) {
e.printStackTrace();
} finally {
lock1.unlock();
lock2.unlock();
}
}, "cc2");

t1.start();
t2.start();
}

}

运行程序之后,控制台输出内容:

image-20200511004249590

然后就一直停顿在这里,下面我们使用jstack排查一下:

  1. 使用jps查看进程pid

    image-20200511004456408

    我们看到进程的pid为75169,接下来就可以根据该pid打印出堆栈信息

  2. 通过jstack查看进程的堆栈信息

    执行命令jstack -l 75169,查看控制台输出的信息

    image-20200511005029659
  3. 排查死锁

    • 直接方法

    查看红框内的信息,发现在堆栈信息中已经告诉了我们死锁的信息,及发生死锁的线程名称和正在等待的锁,以及等待的锁的当前拥有者的线程名称。

    查看黄框内的信息,这是我们排查代码问题的关键所在,也就是在堆栈信息中,会告诉我们发生死锁的代码位置,便于我们定位发生死锁的代码。

    • 间接方法

    如果堆栈中未告诉我们死锁的关联线程,那么我们可以通过线程正在等待的锁的信息在堆栈信息中进行搜索,本示例中,线程cc2的堆栈信息中- parking to wait for <0x000000076b2839a8>告诉我们当前线程cc2正在等待锁0x000000076b2839a8,并且当前已经霸占了锁0x000000076b2839d8;

    image-20200511005806128

    而线程cc1的堆栈信息中- parking to wait for <0x000000076b2839d8>告诉我们它正在等待锁0x000000076b2839d8,且当前已经持有了锁0x000000076b2839a8。

    image-20200511005950037

    通过线程cc1和cc2的堆栈信息我们能够直观的分析出它们相互霸占了对方想要获取的锁,并且在未获得所需要的锁之前,相互之间都不会释放已经持有的锁,因此导致了程序出现了死锁。

小结

以上就是我们通常情况下排查线程死锁的基本操作,主要操作顺序为:

  1. 使用jps查看进程pid
  2. 使用jstack -l pid查看线程堆栈信息
  3. 通过堆栈信息分析死锁情况

排查CPU过高

当运行中的线程过多时,CPU负载会极速飙升,如果我们不及时解决就会导致因CPU过高而唤醒的系统的自我保护,将进程杀死。在实际工作当中,我们经常会遇到此种情况,当然我们不能看到CPU达到100%或者300%了就认为是CPU负载过高,这要根据我们服务器的CPU个数和每个CPU的负载来判断CPU是否过高。

查看服务器负载:使用top命令查看机器负载

image-20200511013557261

  • load average后面分表代表1分钟、5分钟、15分钟的系统平均负载情况,一般不超过CPU个数*0.7即可认为是正常,使用uptime命令也可以查看该属性
  • 按键1可以查看每个CPU的负载情况,若有一个CPU使用量超过75%,那么就需要排查了

我们写一个死循环来将CPU吃满:

1
2
3
4
5
6
7
8
9
10
public class FullCpuTest {

public static void main(String[] args) {
long sum = 0L;
while (true) {
sum += 1;
}
}

}
  1. 运行程序之后,通过top命令查看CPU负载

    image-20200511021314252

    我们看到load average并不是很高,因为刚启动,待会就飙起来了,但是CPU0的usage已经达到了94.7%,我们的Java进程的pid为23731。

  2. 通过top -Hp 23731查看进程内的线程负载情况

    image-20200511021510357

    发现pid为23732的线程占用的CPU最高,那么我们就找到了问题所在

  3. 查看线程的堆栈信息

    • 通过jstack hpid查看线程中处于RUNNABLE状态的线程

      1
      2
      # 23732是线程的pid
      jstack 23732

      image-20200511021836792

    • 通过jstack pid定位具体的线程

      1. 打印线程23732的16进制数

        1
        printf '%x\n' 23732
      2. 通过jstack排查具体的线程信息

        1
        2
        3
        4
        # 23731是进程的pid
        # 5cb4是线程pid的十六进制数
        # -C2是输出命中行的上下行数,-C2表示上下各打印两行
        jstack 23731 | grep '0x5cb4' -C2 --color

        image-20200511022609016

    • 通过kill -3 pid查看线程堆栈信息

其他

一般生产环境不会让直接在服务器上操作,所以可以将堆栈信息输出到文件中,然后再详细分析