随笔- 2079  评论- 230  文章- 4 

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

目录

一、jdk工具之jps(JVM Process Status Tools)命令使用

二、jdk命令之javah命令(C Header and Stub File Generator)

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

四、jdk工具之jstat命令(Java Virtual Machine Statistics Monitoring Tool)

四、jdk工具之jstat命令2(Java Virtual Machine Statistics Monitoring Tool)详解

五、jdk工具之jmap(java memory map)、 mat之四--结合mat对内存泄露的分析

六、jdk工具之jinfo命令(Java Configuration Info)

七、jdk工具之jconsole命令(Java Monitoring and Management Console)

八、jdk工具之JvisualVM、JvisualVM之二--Java程序性能分析工具Java VisualVM

九、jdk工具之jhat命令(Java Heap Analyse Tool)

十、jdk工具之Jdb命令(The Java Debugger)

十一、jdk命令之Jstatd命令(Java Statistics Monitoring Daemon)

十一、jdk命令之Jstatd命令(Java Statistics Monitoring Daemon)

十二、jdk工具之jcmd介绍(堆转储、堆分析、获取系统信息、查看堆外内存)

十三、jdk命令之Java内存之本地内存分析神器:NMT 和 pmap

 

jstack是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工具查询. 

案例

说明

  1. 不同的 JAVA虚机的线程 DUMP的创建方法和文件格式是不一样的,不同的 JVM版本, dump信息也有差别。
  2. 在实际运行中,往往一次 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结果
  1. "Thread-1"prio=5tid=0x00acc490nid=0xe50waitingformonitorentry[0x02d3f000
  2. ..0x02d3fd68]
  3. atdeadlockthreads.TestThread.run(TestThread.java:31)
  4. -waitingtolock<0x22c19f18>(ajava.lang.Object)
  5. -locked<0x22c19f20>(ajava.lang.Object)
  6. "Thread-0"prio=5tid=0x00accdb0nid=0xdecwaitingformonitorentry[0x02cff000
  7. ..0x02cff9e8]
  8. atdeadlockthreads.TestThread.run(TestThread.java:31)
  9. -waitingtolock<0x22c19f20>(ajava.lang.Object)
  10. -locked<0x22c19f18>(ajava.lang.Object)
在 JAVA 5中加强了对死锁的检测。线程 Dump中可以直接报告出 Java级别的死锁,如下所示:
dump结果
  1. FoundoneJava-leveldeadlock:
  2. =============================
  3. "Thread-1":
  4. waitingtolockmonitor0x0003f334(object0x22c19f18,ajava.lang.Object),
  5. whichisheldby"Thread-0"
  6. "Thread-0":
  7. waitingtolockmonitor0x0003f314(object0x22c19f20,ajava.lang.Object),
  8. 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都指向同一个问题,我们才确定问题的典型性。 

2、命令格式

$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(等待条件发生)

Ø 线程的调用情况;

Ø 线程对资源的锁定情况;

 

线程的状态分析:

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

Runnable

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

Waiton condition 

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

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

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

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有时还表示:"切断[掉](计算机)电源"

posted on 2016-05-12 22:07  duanxz  阅读(...)  评论(...编辑  收藏