JVM命令之jstack深入讲解

5,201 阅读11分钟
原文链接: mp.weixin.qq.com

JVM命令使用演示这篇文章里演示了一些jvm命令的使用,这篇文章重点对jstack做一些深入的讲解。

作用

jstack主要用于生成java虚拟机当前时刻的线程快照。线程快照是当前java虚拟机内每一条线程正在执行的方法堆栈的集合,生成线程快照的主要目的是定位线程出现长时间停顿的原因,如线程间死锁、死循环、请求外部资源导致的长时间等待等。 线程出现停顿的时候通过jstack来查看各个线程的调用堆栈,就可以知道没有响应的线程到底在后台做什么事情,或者等待什么资源。如果现在运行的java程序呈现hung的状态,jstack是非常有用的。

使用

先看看看帮助

~  ᐅ jstack -help

Usage:

    jstack [-l] <pid>

        (to connect to running process)

    jstack -F [-m] [-l] <pid>

        (to connect to a hung process)

    jstack [-m] [-l] <executable> <core>

        (to connect to a core file)

    jstack [-m] [-l] [server_id@]<remote server IP or hostname>

        (to connect to a remote debug server)

Options:

    -F  to force a thread dump. Use when jstack <pid> does not respond (process is hung)

    -m  to print both java and native frames (mixed mode)

    -l  long listing. Prints additional information about locks

    -h or -help to print this help message

参数解释一下

-F:当正常输出的请求不被响应时,强制输出线程堆栈。

-l:除堆栈外,会打印出额外的锁信息,在发生死锁时可以用jstack -l pid来观察锁持有情况  

-m:如果调用到本地方法的话,可以显示C/C++的堆栈 

示例

~  ᐅ jstack -F 86200 

~  ᐅ jstack -l 86200 

~  ᐅ jstack -m 86200 

效果

~  ᐅ jstack -l 86200

2018-06-27 09:06:27

Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.92-b14 mixed mode):

"Attach Listener" #22 daemon prio=9 os_prio=31 tid=0x00007f93b9865000 nid=0xd07 waiting on condition [0x0000000000000000]

   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:

- None

"DestroyJavaVM" #21 prio=5 os_prio=31 tid=0x00007f93b996b800 nid=0x1803 waiting on condition [0x0000000000000000]

   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:

- None

"Buiest thread" #20 prio=5 os_prio=31 tid=0x00007f93b8138800 nid=0xa203 runnable [0x0000700004903000]

   java.lang.Thread.State: RUNNABLE

at com.mmall.practice.example.jvm.SearchBusiestCPU$2.run(SearchBusiestCPU.java:176)

   Locked ownable synchronizers:

- None

。。。省略一部分细节。。。

"VM Thread" os_prio=31 tid=0x00007f93b9842000 nid=0x2d03 runnable

"GC task thread#0 (ParallelGC)" os_prio=31 tid=0x00007f93b980d000 nid=0x1d07 runnable

"GC task thread#1 (ParallelGC)" os_prio=31 tid=0x00007f93b980d800 nid=0x1f03 runnable

"GC task thread#2 (ParallelGC)" os_prio=31 tid=0x00007f93b980e800 nid=0x2a03 runnable

"GC task thread#3 (ParallelGC)" os_prio=31 tid=0x00007f93b980f000 nid=0x5403 runnable

"VM Periodic Task Thread" os_prio=31 tid=0x00007f93b8aea000 nid=0x3b03 waiting on condition

JNI global references: 62

分析说明

想要通过jstack来分析线程,首先要知道jstack命令查看线程堆栈信息时可能会看到的线程的状态。首先看一个Monitor的概念

Monitor是 Java中用以实现线程之间的互斥与协作的主要手段,它可以看成是对象或者 Class的锁。每一个对象都有,也仅有一个 monitor。上面这个图,描述了线程和 Monitor之间关系,以及线程的状态转换图。

进入区(Entrt Set):表示线程通过synchronized要求获取对象的锁。如果对象未被锁住,则迚入拥有者;否则则在进入区等待。一旦对象锁被其他线程释放,立即参与竞争。

拥有者(The Owner):表示某一线程成功竞争到对象锁。

等待区(Wait Set):表示线程通过对象的wait方法,释放对象的锁,并在等待区等待被唤醒。

从图中可以看出,一个 Monitor在某个时刻,只能被一个线程拥有,该线程就是 “Active Thread”,而其它线程都是 “Waiting Thread”,分别在两个队列 “ Entry Set”和 “Wait Set”里面等候。在 “Entry Set”中等待的线程状态是 “Waiting for monitor entry”,而在 “Wait Set”中等待的线程状态是 “in Object.wait()”。 先看 “Entry Set”里面的线程。我们称被 synchronized保护起来的代码段为临界区。当一个线程申请进入临界区时,它就进入了 “Entry Set”队列。

jstack命令输出的堆栈信息值得关注的线程状态及说明如下:

Deadlock(重点关注),死锁线程,一般指多个线程调用间,进入相互资源占用,导致一直等待无法释放的情况。

Runnable,一般指该线程正在执行状态中,该线程占用了资源,正在处理某个请求,有可能正在传递SQL到数据库执行,有可能在对某个文件操作,有可能进行数据类型等转换。

Waiting on condition(重点关注),等待资源,或等待某个条件的发生。具体原因需结合实际堆栈来分析。

  • 一种情况是网络非常忙,几乎消耗了所有的带宽,仍然有大量数据等待网络读写;

  • 另一种情况也可能是网络空闲,但由于路由等问题,导致包无法正常的到达。

  • 如果堆栈信息明确是应用代码,则证明该线程正在等待资源。一般是大量读取某资源,且该资源采用了资源锁的情况下,线程进入等待状态,等待资源的读取。

  • 又或者,正在等待其他线程的执行等。

  • 如果发现有大量的线程都在处在 Wait on condition,从线程 stack看,正等待网络读写,这可能是一个网络瓶颈的征兆。因为网络阻塞导致线程无法执行。

  • 另外一种出现 Wait on condition的常见情况是该线程在 sleep,等待 sleep的时间到了时候,将被唤醒。

Waiting on monitor entry(重点关注),等待进入一个临界区

Object.wait() 或 TIMED_WAITING,说明它获得了监视器之后,又调用了 java.lang.Object.wait() 方法。每个 Monitor在某个时刻,只能被一个线程拥有,该线程就是 “Active Thread”,而其它线程都是 “Waiting Thread”,分别在两个队列 “ Entry Set”和 “Wait Set”里面等候。在 “Entry Set”中等待的线程状态是 “Waiting for monitor entry”,而在 “Wait Set”中等待的线程状态是 “in Object.wait()”。当线程获得了 Monitor,如果发现线程继续运行的条件没有满足,它则调用对象(一般就是被 synchronized 的对象)的 wait() 方法,放弃了 Monitor,进入 “Wait Set”队列。

此时线程状态大致为以下几种:

  • java.lang.Thread.State: TIMED_WAITING (on object monitor);

  • java.lang.Thread.State: WAITING (on object monitor);

Blocked(重点关注),线程阻塞,是指当前线程执行过程中,所需要的资源长时间等待却一直未能获取到,被容器的线程管理器标识为阻塞状态,可以理解为等待资源超时的线程

死锁案例演示

先准备一段死锁的代码

@Slf4jpublic class DeadLock implements Runnable {    public int flag = 1;    //静态对象是类的所有对象共享的    private static Object o1 = new Object(), o2 = new Object();    @Override    public void run() {        log.info("flag:{}", flag);        if (flag == 1) {            synchronized (o1) {                try {                    Thread.sleep(500);                } catch (Exception e) {                    e.printStackTrace();                }                synchronized (o2) {                    log.info("1");                }            }        }        if (flag == 0) {            synchronized (o2) {                try {                    Thread.sleep(500);                } catch (Exception e) {                    e.printStackTrace();                }                synchronized (o1) {                    log.info("0");                }            }        }    }    public static void main(String[] args) {        DeadLock td1 = new DeadLock();        DeadLock td2 = new DeadLock();        td1.flag = 1;        td2.flag = 0;        //td1,td2都处于可执行状态,但JVM线程调度先执行哪个线程是不确定的。        //td2的run()可能在td1的run()之前运行        new Thread(td1).start();        new Thread(td2).start();    }}

运行结果如下:

14:47:19.351 [Thread-1] INFO com.mmall.concurrency.example.deadLock.DeadLock - flag:0

14:47:19.351 [Thread-0] INFO com.mmall.concurrency.example.deadLock.DeadLock - flag:1

程序输出了两行内容,就不再打印其它的东西了,但是程序并没有停止。这样就产生了死锁。

使用jstack命令看一下堆栈信息

~  ᐅ jps

93893 Launcher

94055 Jps

93894 DeadLock

34413

~  ᐅ jstack -l 93894

2018-06-28 14:48:26

Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.92-b14 mixed mode):

"Attach Listener" #13 daemon prio=9 os_prio=31 tid=0x00007ff14c101800 nid=0x1307 waiting on condition [0x0000000000000000]

   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:

- None

"DestroyJavaVM" #12 prio=5 os_prio=31 tid=0x00007ff14c0fe000 nid=0x1703 waiting on condition [0x0000000000000000]

   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:

- None

"Thread-1" #11 prio=5 os_prio=31 tid=0x00007ff14ca77000 nid=0x3d03 waiting for monitor entry [0x000070000c45c000]

   java.lang.Thread.State: BLOCKED (on object monitor)

at com.mmall.concurrency.example.deadLock.DeadLock.run(DeadLock.java:43)

- waiting to lock <0x000000076b5115c0> (a java.lang.Object)

- locked <0x000000076b5115d0> (a java.lang.Object)

at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:

- None

"Thread-0" #10 prio=5 os_prio=31 tid=0x00007ff14ca4b000 nid=0x3c03 waiting for monitor entry [0x000070000c359000]

   java.lang.Thread.State: BLOCKED (on object monitor)

at com.mmall.concurrency.example.deadLock.DeadLock.run(DeadLock.java:31)

- waiting to lock <0x000000076b5115d0> (a java.lang.Object)

- locked <0x000000076b5115c0> (a java.lang.Object)

at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:

- None

。。。此处省略部分无用的thread堆栈信息。。。

"VM Thread" os_prio=31 tid=0x00007ff14b82b000 nid=0x2d03 runnable

"GC task thread#0 (ParallelGC)" os_prio=31 tid=0x00007ff14c012800 nid=0x2107 runnable

"GC task thread#1 (ParallelGC)" os_prio=31 tid=0x00007ff14c013000 nid=0x2003 runnable

"GC task thread#2 (ParallelGC)" os_prio=31 tid=0x00007ff14c816000 nid=0x2a03 runnable

"GC task thread#3 (ParallelGC)" os_prio=31 tid=0x00007ff14c816800 nid=0x5403 runnable

"VM Periodic Task Thread" os_prio=31 tid=0x00007ff14ca0b000 nid=0x3a03 waiting on condition

JNI global references: 42

Found one Java-level deadlock:

=============================

"Thread-1":

  waiting to lock monitor 0x00007ff14b0195c8 (object 0x000000076b5115c0, a java.lang.Object),

  which is held by "Thread-0"

"Thread-0":

  waiting to lock monitor 0x00007ff14b0174c8 (object 0x000000076b5115d0, a java.lang.Object),

  which is held by "Thread-1"

Java stack information for the threads listed above:

===================================================

"Thread-1":

at com.mmall.concurrency.example.deadLock.DeadLock.run(DeadLock.java:43)

- waiting to lock <0x000000076b5115c0> (a java.lang.Object)

- locked <0x000000076b5115d0> (a java.lang.Object)

at java.lang.Thread.run(Thread.java:745)

"Thread-0":

at com.mmall.concurrency.example.deadLock.DeadLock.run(DeadLock.java:31)

- waiting to lock <0x000000076b5115d0> (a java.lang.Object)

- locked <0x000000076b5115c0> (a java.lang.Object)

at java.lang.Thread.run(Thread.java:745)

Found 1 deadlock.

这个堆栈明显告诉我们 Found one Java-level deadlock,指出造成死锁的两个线程的内容。又通过Java stack information for the threads listed above列出更详细的死锁的信息,并指出产生死锁的代码行数及竞争的资源。

注意

1、不同的 JAVA虚机的线程 DUMP的创建方法和文件格式可能不一样,不同的 JVM版本, dump信息也有差别。

2、 在实际运行中,往往一次 dump的信息,还不足以确认问题。建议产生2~3次 dump信息,如果每次 dump都指向同一个问题,才可以确定问题的典型性

其他文章推荐

面试中并发类问题的准备和学习

自定义注解完成数据库切库

多个数据源轻松支持

改造电商交易后台权限管理过程

数据权限通用设计方案

简谈从零开始搭建一套业务相关监控报警系统

Java项目中使用log记录日志的一些总结

Redis在股票分时K线图计算的实践

并发之Fork/Join框架使用及注意点

Java并发编程与高并发解决方案:

https://coding.imooc.com/class/195.html

Java开发企业级权限管理 系统:

https://coding.imooc.com/class/149.html

如果喜欢相关的技术文章,别忘了关注我哦~