3、jdk工具之jstack(Java Stack Trace)

时间 2020-06-08

标签 jdk 工具 jstack java stack trace 栏目 Java 繁體版

原文原文链接

jstack用于生成java虚拟机当前时刻的线程快照。线程快照是当前java虚拟机内每一条线程正在执行的方法堆栈的集合，生成线程快照的主要目的是定位线程出现长时间停顿的缘由，如线程间死锁、死循环、请求外部资源致使的长时间等待等。

线程出现停顿的时候经过jstack来查看各个线程的调用堆栈，就能够知道没有响应的线程到底在后台作什么事情，或者等待什么资源。

命令格式

编辑

jstack [ option ] pid

基本参数：

-F 当’jstack [-l] pid’没有响应的时候强制打印栈信息

-l 长列表. 打印关于锁的附加信息,例如属于java.util.concurrent的ownable synchronizers列表.

-m 打印java和native c/c++框架的全部栈信息. -h | -help打印帮助信息

pid 须要被打印配置信息的java进程id,能够用jps工具查询.

案例

说明

不一样的 JAVA虚机的线程 DUMP的建立方法和文件格式是不同的，不一样的 JVM版本， dump信息也有差异。
在实际运行中，每每一次 dump的信息，还不足以确认问题。建议产生三次 dump信息，若是每次 dump都指向同一个问题，咱们才肯定问题的典型性。

案例1-使用

先以一个小场景简单示范下 jstack 的使用。

场景：Java应用持续占用很高CPU，须要排查一下。

模拟：造个场景简单模拟下，没什么实际意义，仅做演示。我启动了100个线程持续访问个人博客，博客部署在Ubuntu 16.04上，是一个简单的Spring Boot应用，以jar包直接运行的。

top 命令查下系统运行状况，进程31951占用CPU 80.6%。

jps -l 确认一下，31951就是博客的进程ID，或 cat /proc/31951/cmdline 看下进程的启用命令。

root@iZ94dcq8q6jZ:~# jps -l
28416 sun.tools.jps.Jps
31951 blog.jar

top -Hp 31951 以线程模式查看下进程31951的全部线程状况

假设想看下第二个线程31998的状况，31998是操做系统的线程ID，先转成16进制。（再例如：21233用计算器转换为16进制52f1，注意字母是小写）

printf '%x' 31998 #值为7cfe

获取该线程的信息(匹配7cf3后取20行差很少)

jstack 31951 | grep 7cfe -A 20

其中部分数据以下：

"Tomcat JDBC Pool Cleaner[11483240:1532362388783]" #31 daemon prio=5 os_prio=0 tid=0x0a29dc00 nid=0x7cfe in Object.wait() [0xa2a69000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at java.util.TimerThread.mainLoop(Timer.java:552)
    - locked <0xaadc5a60> (a java.util.TaskQueue)
    at java.util.TimerThread.run(Timer.java:505)

注意：nid=0x7cfe中的nid指native id，是OS中线程ID，对应上面31998线程的16进制值7cfe；tid为Java中线程的ID。

至于如何利用jstack的数据分析线程状况，能够看看如何使用jstack分析线程状态和 jstack。

案例2-死锁

在多线程程序的编写中，若是不适当的运用同步机制，则有可能形成程序的死锁，常常表现为程序的停顿，或者再也不响应用户的请求。好比在下面这个示例中，是个较为典型的死锁状况：

dump结果

"Thread-1"prio=5tid=0x00acc490nid=0xe50waitingformonitorentry[0x02d3f000
..0x02d3fd68]
atdeadlockthreads.TestThread.run(TestThread.java:31)
-waitingtolock<0x22c19f18>(ajava.lang.Object)
-locked<0x22c19f20>(ajava.lang.Object)
"Thread-0"prio=5tid=0x00accdb0nid=0xdecwaitingformonitorentry[0x02cff000
..0x02cff9e8]
atdeadlockthreads.TestThread.run(TestThread.java:31)
-waitingtolock<0x22c19f20>(ajava.lang.Object)
-locked<0x22c19f18>(ajava.lang.Object)

在 JAVA 5中增强了对死锁的检测。线程 Dump中能够直接报告出 Java级别的死锁，以下所示：

dump结果

FoundoneJava-leveldeadlock:
=============================
"Thread-1":
waitingtolockmonitor0x0003f334(object0x22c19f18,ajava.lang.Object),
whichisheldby"Thread-0"
"Thread-0":
waitingtolockmonitor0x0003f314(object0x22c19f20,ajava.lang.Object),
whichisheldby"Thread-1"[2]

生成死锁（deadlock）的源代码

/**
 * 简单的应用,供测试JDK自带的jstack使用 本应用会形成deadlock，可能会致使系统崩溃
 * 逻辑：一旦两个线程互相等待的局面出现，死锁（deadlock）就发生了
 */
public class EasyJstack extends Thread {

    private EasyJstackResource resourceManger;// 资源管理类的私有引用，经过此引用能够经过其相关接口对资源进行读写
    private int a, b;// 将要写入资源的数据

    public static void main(String[] args) throws Exception {
        EasyJstackResource resourceManager = new EasyJstackResource();
        EasyJstack stack1 = new EasyJstack(resourceManager, 1, 2);
        EasyJstack stack2 = new EasyJstack(resourceManager, 3, 4);
        stack1.start();
        stack2.start();
    }

    public EasyJstack(EasyJstackResource resourceManager, int a, int b) {
        this.resourceManger = resourceManager;
        this.a = a;
        this.b = b;
    }

    public void run() {
        while (true) {
            this.resourceManger.read();
            this.resourceManger.write(this.a, this.b);
        }
    }

}

public class EasyJstackResource {
    /**
     * 管理的两个资源，若是有多个线程并发，那么就会死锁
     */
    private Resource resourceA = new Resource();
    private Resource resourceB = new Resource();

    public EasyJstackResource() {
        this.resourceA.setValue(0);
        this.resourceB.setValue(0);
    }

    public int read() {
        synchronized (this.resourceA) {
            System.out.println(Thread.currentThread().getName() + "线程拿到了资源 resourceA的对象锁");
            synchronized (resourceB) {
                System.out.println(Thread.currentThread().getName() + "线程拿到了资源 resourceB的对象锁");
                return this.resourceA.getValue() + this.resourceB.getValue();
            }
        }
    }

    public void write(int a, int b) {
        synchronized (this.resourceB) {
            System.out.println(Thread.currentThread().getName() + "线程拿到了资源 resourceB的对象锁");
            synchronized (this.resourceA) {
                System.out.println(Thread.currentThread().getName() + "线程拿到了资源 resourceA的对象锁");
                this.resourceA.setValue(a);
                this.resourceB.setValue(b);
            }
        }
    }

    public class Resource {
        private int value;// 资源的属性

        public int getValue() {
            return value;
        }

        public void setValue(int value) {
            this.value = value;
        }
    }
}

用jstack进行分析和结果

在dos中输入命令：jstack 7404

Found one Java-level deadlock:
=============================
"Thread-1":
  waiting to lock monitor 0x00000000577c2bc8 (object 0x00000000d7149440, a com.dxz.jstack.EasyJstackResource$Resource),
  which is held by "Thread-0"
"Thread-0":
  waiting to lock monitor 0x00000000577c4118 (object 0x00000000d7149428, a com.dxz.jstack.EasyJstackResource$Resource),
  which is held by "Thread-1"

Java stack information for the threads listed above:
===================================================
"Thread-1":
        at com.dxz.jstack.EasyJstackResource.read(EasyJstackResource.java:36)
        - waiting to lock <0x00000000d7149440> (a com.dxz.jstack.EasyJstackResource$Resource)
        - locked <0x00000000d7149428> (a com.dxz.jstack.EasyJstackResource$Resource)
        at com.dxz.jstack.EasyJstack.run(EasyJstack.java:41)
"Thread-0":
        at com.dxz.jstack.EasyJstackResource.write(EasyJstackResource.java:46)
        - waiting to lock <0x00000000d7149428> (a com.dxz.jstack.EasyJstackResource$Resource)
        - locked <0x00000000d7149440> (a com.dxz.jstack.EasyJstackResource$Resource)
        at com.dxz.jstack.EasyJstack.run(EasyJstack.java:42)

Found 1 deadlock.

仔细看这一段文字，告诉咱们 EasyJstackResource.java:36出了情况。若是出现了这种状况，咱们就要从这里开始顺藤摸瓜，解决问题。

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

jstack用于打印出给定的Java进程ID或core file或远程调试服务的Java堆栈信息，若是是在64位机器上，须要指定选项"-J-d64"，Windows的jstack使用方式只支持如下的这种方式：jstack [-l] pid

若是java程序崩溃生成core文件，jstack工具能够用来得到core文件的java stack和native stack的信息，从而能够轻松地知道java程序是如何崩溃和在程序何处发生问题。另外，jstack工具还能够附属到正在运行的java程序中，看到当时运行的java程序的java stack和native stack的信息, 若是如今运行的java程序呈现hung的状态，jstack是很是有用的。

须要注意的问题:

l 不一样的 JAVA虚机的线程 DUMP的建立方法和文件格式是不同的，不一样的 JVM版本， dump信息也有差异。

l 在实际运行中，每每一次 dump的信息，还不足以确认问题。建议产生三次 dump信息，若是每次 dump都指向同一个问题，咱们才肯定问题的典型性。

二、命令格式

$jstack [ option ] pid

$jstack [ option ] executable core

$jstack [ option ] [server-id@]remote-hostname-or-IP

参数说明:

pid: java应用程序的进程号,通常能够经过jps来得到;

executable:产生core dump的java可执行程序;

core:打印出的core文件;

remote-hostname-or-ip:远程debug服务器的名称或IP;

server-id: 惟一id,假如一台主机上多个远程debug服务;

示例:

$jstack –l 23561

线程分析:

通常状况下，经过jstack输出的线程信息主要包括：jvm自身线程、用户线程等。其中jvm线程会在jvm启动时就会存在。对于用户线程则是在用户访问时才会生成。

l jvm线程：

在线程中，有一些 JVM内部的后台线程，来执行譬如垃圾回收，或者低内存的检测等等任务，这些线程每每在JVM初始化的时候就存在，以下所示：

"Attach Listener" daemon prio=10 tid=0x0000000052fb8000 nid=0xb8f waiting on condition [0x0000000000000000]

java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:

- None

destroyJavaVM" prio=10 tid=0x00002aaac1225800 nid=0x7208 waiting on condition [0x0000000000000000]

java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:

- None

l 用户级别的线程

还有一类线程是用户级别的，它会根据用户请求的不一样而发生变化。该类线程的运行状况每每是咱们所关注的重点。并且这一部分也是最容易产生死锁的地方。

"qtp496432309-42" prio=10 tid=0x00002aaaba2a1800 nid=0x7580 waiting on condition [0x00000000425e9000]

java.lang.Thread.State: TIMED_WAITING (parking)

at sun.misc.Unsafe.park(Native Method)

- parking to wait for <0x0000000788cfb020> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)

at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)

at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2025)

at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:320)

at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:479)

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

Locked ownable synchronizers:

- None

从上述的代码示例中咱们能够看到该用户线程的如下几类信息：

Ø 线程的状态：waiting on condition(等待条件发生)

Ø 线程的调用状况；

Ø 线程对资源的锁定状况；

线程的状态分析：

正如咱们刚看到的那样，线程的状态是一个重要的指标，它会显示在线程每行结尾的地方。那么线程常见的有哪些状态呢？线程在什么样的状况下会进入这种状态呢？咱们能从中发现什么线索？

l Runnable

该状态表示线程具有全部运行条件，在运行队列中准备操做系统的调度，或者正在运行。

l Waiton condition

该状态出如今线程等待某个条件的发生。具体是什么缘由，能够结合stacktrace来分析。最多见的状况是线程在等待网络的读写，好比当网络数据没有准备好读时，线程处于这种等待状态，而一旦有数据准备好读以后，线程会从新激活，读取并处理数据。在 Java引入 NIO以前，对于每一个网络链接，都有一个对应的线程来处理网络的读写操做，即便没有可读写的数据，线程仍然阻塞在读写操做上，这样有可能形成资源浪费，并且给操做系统的线程调度也带来压力。在 NIO里采用了新的机制，编写的服务器程序的性能和可扩展性都获得提升。

若是发现有大量的线程都在处在 Wait on condition，从线程 stack看，正等待网络读写，这多是一个网络瓶颈的征兆。由于网络阻塞致使线程没法执行。一种状况是网络很是忙，几乎消耗了全部的带宽，仍然有大量数据等待网络读写；另外一种状况也多是网络空闲，但因为路由等问题，致使包没法正常的到达。因此要结合系统的一些性能观察工具来综合分析，好比 netstat统计单位时间的发送包的数目，若是很明显超过了所在网络带宽的限制 ; 观察 cpu的利用率，若是系统态的 CPU时间，相对于用户态的 CPU时间比例较高；若是程序运行在 Solaris 10平台上，能够用 dtrace工具看系统调用的状况，若是观察到 read/write的系统调用的次数或者运行时间遥遥领先；这些都指向因为网络带宽所限致使的网络瓶颈。

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

l Waitingfor monitor entry 和 in Object.wait()

在多线程的 JAVA程序中，实现线程之间的同步，就要说说Monitor。Monitor是Java中用以实现线程之间的互斥与协做的主要手段，它能够当作是对象或者 Class的锁。每个对象都有，也仅有一个 monitor。下面这个图，描述了线程和 Monitor之间关系，以及线程的状态转换图：

从图中能够看出，每一个 Monitor在某个时刻，只能被一个线程拥有，该线程就是 “Active Thread”，而其它线程都是 “Waiting Thread”，分别在两个队列 “ Entry Set”和 “Wait Set”里面等候。在 “Entry Set”中等待的线程状态是 “Waiting for monitorentry”，而在 “Wait Set”中等待的线程状态是“in Object.wait()”。

先看 “Entry Set”里面的线程。咱们称被 synchronized保护起来的代码段为临界区。当一个线程申请进入临界区时，它就进入了 “Entry Set”队列。对应的 code就像：

synchronized(obj){

.........

}

这时有两种可能性：

该 monitor不被其它线程拥有，Entry Set里面也没有其它等待线程。本线程即成为相应类或者对象的 Monitor的 Owner，执行临界区的代码。此时线程将处于Runnable状态；

该 monitor被其它线程拥有，本线程在 Entry Set队列中等待。此时dump的信息显示“waiting for monitor entry”。

"Thread-0" prio=10 tid=0x08222eb0 nid=0x9 waiting for monitor entry [0xf927b000..0xf927bdb8]

at testthread.WaitThread.run(WaitThread.java:39)
- waiting to lock <0xef63bf08> (a java.lang.Object)
- locked <0xef63beb8> (a java.util.ArrayList)
at java.lang.Thread.run(Thread.java:595)

临界区的设置，是为了保证其内部的代码执行的原子性和完整性。可是由于临界区在任什么时候间只容许线程串行经过，这和咱们多线程的程序的初衷是相反的。若是在多线程的程序中，大量使用 synchronized，或者不适当的使用了它，会形成大量线程在临界区的入口等待，形成系统的性能大幅降低。若是在线程 DUMP中发现了这个状况，应该审查源码，改进程序。

如今咱们再来看如今线程为何会进入 “Wait Set”。当线程得到了 Monitor，进入了临界区以后，若是发现线程继续运行的条件没有知足，它则调用对象（通常就是被 synchronized 的对象）的 wait() 方法，放弃了 Monitor，进入 “Wait Set”队列。只有当别的线程在该对象上调用了 notify() 或者 notifyAll() ， “ Wait Set”队列中线程才获得机会去竞争，可是只有一个线程得到对象的Monitor，恢复到运行态。在 “Wait Set”中的线程， DUMP中表现为： in Object.wait()，相似于：

"Thread-1" prio=10 tid=0x08223250 nid=0xa in Object.wait() [0xef47a000..0xef47aa38]

at java.lang.Object.wait(Native Method)

- waiting on <0xef63beb8> (a java.util.ArrayList)

at java.lang.Object.wait(Object.java:474)

at testthread.MyWaitThread.run(MyWaitThread.java:40)

- locked <0xef63beb8> (a java.util.ArrayList)

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

仔细观察上面的 DUMP信息，你会发现它有如下两行：

² locked <0xef63beb8> (ajava.util.ArrayList)

² waiting on <0xef63beb8> (ajava.util.ArrayList)

这里须要解释一下，为何先 lock了这个对象，而后又 waiting on同一个对象呢？让咱们看看这个线程对应的代码：

synchronized(obj){

.........

obj.wait();

.........

}

线程的执行中，先用 synchronized 得到了这个对象的 Monitor（对应于 locked <0xef63beb8> ）。当执行到 obj.wait(), 线程即放弃了 Monitor的全部权，进入 “wait set”队列（对应于 waiting on<0xef63beb8> ）。

往在你的程序中，会出现多个相似的线程，他们都有类似的 dump也多是正常的。好比，在程序中有多个服务线程，设计成从一个队列里面读取请求数据。这个队列就是 lock以及 waiting on的对象。当队列为空的时候，这些线程都会在这个队列上等待，直到队列有了数据，这些线程被notify，固然只有一个线程得到了 lock，继续执行，而其它线程继续等待。

dump:

Dump的本意是"倾卸垃圾"、"把(垃圾桶)倒空"。在计算机技术中使用Dump的主要意思仍然如此,即当电脑运行发现故障后,没法排除而死机,一般要从新启动。为了找出故障的缘由 ,须要分析现场(即死机时整个内存的当前情况),在从新启动系统以前要把内存中的一片0、 1(这时它们尤如一堆垃圾)"卸出"保存起来,以便由专家去分析引发死机的缘由。技术资料中把这个"卸出"的过程叫dump;有时把卸出的"内容"也叫dump。国际标准化组织(ISO)把前者定义为To record,at a particular instant,the contents of all or part of one stora geevice in another storage device.Dumping is usually for the purpose of debuggin。"译文以下:"在某个特定时刻,把一个存储设备中的所有或部分的内容转录进另外一个存储设备之中。转储的目的一般是用于排除故障。"所以,dump做为动词,宜译为"转储";相应的动名词,或做为名词来看 ,则译为"转储(过程、动做…)"。同时,ISO把后者定义为"Data that as been dumped。"译文以下:"经转储而产生的那些数据"。这些数据实际上就是内存中由一片0、1组成的map(映像),所以,这时的dump应译为"内像"(内存中的映像)。
明白了dump的上述二个基本含义以后,dump的其它用法就不难理解了。好比在IBM主机系统中作dump时,一般是转储到磁带上,因此有人把这盘磁带也叫dump!为了便于阅读与分析,把内像按既定的格式打印在纸上,人们便把这一堆打印纸也叫dump!为了实现以上二项工做,必须有相应的程序,人们把这种程序也叫dump,实为dump routine的简写。IBM的VSE/SP操做系统中还专门有一条dump宏指令供程序员使用。
当咱们把dump译为"转储"时,老是指"把内存中的内容复制到其它存储设备上",而实际使用dump时,并不是一概如此,有时dump就是copy(复制)的意思。IBM的《Dictionary of Compuing》(第十版)就是这样定义dump的:"To copy data in a readable format from mainr a uxiliary storage onto a external medium such as tape,diskette orprinter(按照可阅读的格式,把主存或辅存中的数据复制到外部媒体,如磁带、软盘或打印机上。)","Tocopy the contents of all or part of virtual storage for the purpose of collectng error information(为了收集出错信息把部分或所有虚存中的内容复制起来)。"最明显的例子是VM/SP(IBM的大型操做系统)中有一个DDR(DASD Dump Restore:磁盘转储恢复)独立程序,主用于把可运行的操做系统等软件从磁盘(DASD)复制到磁带上(这个过程称为dump,或反过来,在无需操做系统的控制下 ,可把磁带上的软件复制回到磁盘之中,以便恢复可运行的操做系统(这个过程为restore)。这儿的dump过程就不涉及内存,相似的例子还有很多这儿就不一一列举了。在影像系统中,dump被定义为一种方法或过程(process),借此数字节目代码能够从录像盘传送播放录像的微处理器上,这时的dump就是"转录"的意思。一样在影像系统中,dump还被定义为:一次可装入播放录像处理器中的"一段节目代码(a unit of program code)",一张录像盘上能够存放多个节目段(program dumps)。除上述的意思外,dump有时还表示:"切断[掉](计算机)电源"

3、jdk工具之jstack(Java Stack Trace)

目录

基本介绍

命令格式

案例

说明

案例1-使用

案例2-死锁

生成死锁（deadlock）的源代码

用jstack进行分析和结果