JVM命令之 jstack深入讲解

最新推荐文章于 2024-06-16 23:04:05 发布

San6653

最新推荐文章于 2024-06-16 23:04:05 发布

阅读量406

点赞数

分类专栏： JVM调优文章标签： jvm

原文链接：https://www.imooc.com/article/43986?block_id=tuijian_wz

版权

JVM调优专栏收录该内容

2 篇文章 0 订阅

订阅专栏

作用

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（重点关注），线程阻塞，是指当前线程执行过程中，所需要的资源长时间等待却一直未能获取到，被容器的线程管理器标识为阻塞状态，可以理解为等待资源超时的线程

死锁案例演示

先准备一段死锁的代码

@Slf4j
public 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都指向同一个问题，才可以确定问题的典型性