为了账号安全,请及时绑定邮箱和手机立即绑定

JVM命令之jstack深入讲解

标签:
Java

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的概念


https://img1.sycdn.imooc.com//5b499ed10001902a12100650.jpg

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

欢迎关注课程《Java并发编程与高并发解决方案》《Java开发企业级权限管理系统》


点击查看更多内容
12人点赞

若觉得本文不错,就分享一下吧!

评论

作者其他优质文章

正在加载中
感谢您的支持,我会继续努力的~
扫码打赏,你说多少就多少
赞赏金额会直接到老师账户
支付方式
打开微信扫一扫,即可进行扫码打赏哦
今天注册有机会得

100积分直接送

付费专栏免费学

大额优惠券免费领

立即参与 放弃机会
意见反馈 帮助中心 APP下载
官方微信

举报

0/150
提交
取消