怎样使用jstack诊断Java应用程序故障

Posted

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了怎样使用jstack诊断Java应用程序故障相关的知识,希望对你有一定的参考价值。

参考技术A 1. 首先来了解一下jstack这个命令的作用,jstack 是一个可以返回在应用程序上运行的各种各样线程的一个完整转储的实用程序,您可以使用它查明问题。jstack [-l] <pid>,jpid可以通过使用jps命令来查看当前Java程序的jpid值,-l是可选参数,它可以显示线程阻塞/死锁情况。

/**
* 死锁例子
* @author crane.ding
* @since 2011-3-20
*/
public class DeadLock

public static void main(String[] args)
final Object obj_1 = new Object(), obj_2 = new Object();

Thread t1 = new Thread("t1")
@Override
public void run()
synchronized (obj_1)
try
Thread.sleep(3000);
catch (InterruptedException e)

synchronized (obj_2)
System.out.println("thread t1 done.");



;

Thread t2 = new Thread("t2")
@Override
public void run()
synchronized (obj_2)
try
Thread.sleep(3000);
catch (InterruptedException e)

synchronized (obj_1)
System.out.println("thread t2 done.");



;

t1.start();
t2.start();




2. 以上DeadLock类是一个死锁的例子,假使在不知情的情况下,运行DeadLock后,发现等了N久都没有在屏幕打印线程完成信息。这个时候就可以使用jps查看该程序的jpid值和使用jstack来生产堆栈结果问题。
$ java -cp deadlock.jar DeadLock &
$

$ jps
3076 Jps
448 DeadLock
$ jstack -l 448 > deadlock.jstack
结果文件deadlock.jstack内容如下:
2011-03-20 23:05:20
Full thread dump Java HotSpot(TM) Client VM (19.1-b02 mixed mode, sharing):

"DestroyJavaVM" prio=6 tid=0x00316800 nid=0x9fc waiting on condition [0x00000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"t2" prio=6 tid=0x02bcf000 nid=0xc70 waiting for monitor entry [0x02f6f000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.demo.DeadLock$2.run(DeadLock.java:40)
- waiting to lock <0x22a297a8> (a java.lang.Object)
- locked <0x22a297b0> (a java.lang.Object)

Locked ownable synchronizers:
- None

"t1" prio=6 tid=0x02bce400 nid=0xba0 waiting for monitor entry [0x02f1f000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.demo.DeadLock$1.run(DeadLock.java:25)
- waiting to lock <0x22a297b0> (a java.lang.Object)
- locked <0x22a297a8> (a java.lang.Object)

Locked ownable synchronizers:
- None

"Low Memory Detector" daemon prio=6 tid=0x02bb9400 nid=0xa6c runnable [0x00000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"CompilerThread0" daemon prio=10 tid=0x02bb2800 nid=0xcb8 waiting on condition [0x00000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"Attach Listener" daemon prio=10 tid=0x02bb1000 nid=0x7f4 waiting on condition [0x00000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"Signal Dispatcher" daemon prio=10 tid=0x02bd2800 nid=0xd80 runnable [0x00000000]
java.lang.Thread.State: RUNNABLE

Locked ownable synchronizers:
- None

"Finalizer" daemon prio=8 tid=0x02bab000 nid=0xe1c in Object.wait() [0x02d3f000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x229e1148> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
- locked <0x229e1148> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

Locked ownable synchronizers:
- None

"Reference Handler" daemon prio=10 tid=0x02ba6800 nid=0xbe0 in Object.wait() [0x02cef000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x229e1048> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:485)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
- locked <0x229e1048> (a java.lang.ref.Reference$Lock)

Locked ownable synchronizers:
- None

"VM Thread" prio=10 tid=0x02b6a400 nid=0x568 runnable

"VM Periodic Task Thread" prio=10 tid=0x02bc8400 nid=0x75c waiting on condition

JNI global references: 878

Found one Java-level deadlock:
=============================
"t2":
waiting to lock monitor 0x02baaeec (object 0x22a297a8, a java.lang.Object),
which is held by "t1"
"t1":
waiting to lock monitor 0x02baa2bc (object 0x22a297b0, a java.lang.Object),
which is held by "t2"

Java stack information for the threads listed above:
===================================================
"t2":
at com.demo.DeadLock$2.run(DeadLock.java:40)
- waiting to lock <0x22a297a8> (a java.lang.Object)
- locked <0x22a297b0> (a java.lang.Object)
"t1":
at com.demo.DeadLock$1.run(DeadLock.java:25)
- waiting to lock <0x22a297b0> (a java.lang.Object)
- locked <0x22a297a8> (a java.lang.Object)

Found 1 deadlock.

3.从这个结果文件看到发现了一个死锁,具体是线程t2在等待线程t1,而线程t1在等待线程t2造成的,同时也记录了线程的堆栈和代码行数,通过这个堆栈和行数就可以去检查对应的代码块,从而发现问题和解决问题。

给你的Java程序拍个片子吧:jstack命令解析

前言

如果有一天,你的Java程序长时间停顿,也许是它病了,需要用jstack拍个片子分析分析,才能诊断具体什么病症,是死锁综合征,还是死循环等其他病症,本文我们一起来学习jstack命令~

  • jstack 的功能
  • jstack用法
  • 线程状态等基础回顾
  • 实战案例1:jstack 分析死锁
  • 实战案例2:jstack 分析CPU 过高

jstack 的功能

jstack是JVM自带的Java堆栈跟踪工具,它用于打印出给定的java进程ID、core file、远程调试服务的Java堆栈信息.

jstack prints Java stack traces of Java threads for a given Java process or
core file or a remote debug server. 
  • jstack命令用于生成虚拟机当前时刻的线程快照。
  • 线程快照是当前虚拟机内每一条线程正在执行的方法堆栈的集合,生成线程快照的主要目的是定位线程出现长时间停顿的原因,
    如线程间死锁、死循环、请求外部资源导致的长时间等待等问题。
  • 线程出现停顿的时候通过jstack来查看各个线程的调用堆栈,就可以知道没有响应的线程到底在后台做什么事情,或者等待什么资源。
  • 如果java程序崩溃生成core文件,jstack工具可以用来获得core文件的java stack和native stack的信息,从而可以轻松地知道java程序是如何崩溃和在程序何处发生问题。
  • 另外,jstack工具还可以附属到正在运行的java程序中,看到当时运行的java程序的java stack和native stack的信息, 如果现在运行的java程序呈现hung的状态,jstack是非常有用的。

jstack用法

jstack 命令格式如下

jstack [ option ] pid 
jstack [ option ] executable core 
jstack [ option ] [server-id@]remote-hostname-or-IP 
  • executable Java executable from which the core dump was produced.(可能是产生core dump的java可执行程序)
  • core 将被打印信息的core dump文件
  • remote-hostname-or-IP 远程debug服务的主机名或ip
  • server-id 唯一id,假如一台主机上多个远程debug服务

最常用的是

jstack [option] <pid>  // 打印某个进程的堆栈信息

option参数说明如下:

技术图片

选项 作用
-F 当正常输出的请求不被响应时,强制输出线程堆栈
-m 如果调用到本地方法的话,可以显示C/C++的堆栈
-l 除堆栈外,显示关于锁的附加信息,在发生死锁时可以用jstack -l pid来观察锁持有情况

线程状态等基础回顾

线程状态简介

jstack用于生成线程快照的,我们分析线程的情况,需要复习一下线程状态吧,拿小凳子坐好,复习一下啦~
技术图片

Java语言定义了6种线程池状态:

  • New:创建后尚未启动的线程处于这种状态,不会出现在Dump中。
  • RUNNABLE:包括Running和Ready。线程开启start()方法,会进入该状态,在虚拟机内执行的。
  • Waiting:无限的等待另一个线程的特定操作。
  • Timed Waiting:有时限的等待另一个线程的特定操作。
  • 阻塞(Blocked):在程序等待进入同步区域的时候,线程将进入这种状态,在等待监视器锁。
  • 结束(Terminated):已终止线程的线程状态,线程已经结束执行。

Dump文件的线程状态一般其实就以下3种:

  • RUNNABLE,线程处于执行中
  • BLOCKED,线程被阻塞
  • WAITING,线程正在等待

Monitor 监视锁

因为Java程序一般都是多线程运行的,Java多线程跟监视锁环环相扣,所以我们分析线程状态时,也需要回顾一下Monitor监视锁知识。

有关于线程同步关键字Synchronized与监视锁的爱恨情仇,有兴趣的伙伴可以看一下我这篇文章
Synchronized解析——如果你愿意一层一层剥开我的心

Monitor的工作原理图如下:

技术图片

  • 线程想要获取monitor,首先会进入Entry Set队列,它是Waiting Thread,线程状态是Waiting for monitor entry。
  • 当某个线程成功获取对象的monitor后,进入Owner区域,它就是Active Thread。
  • 如果线程调用了wait()方法,则会进入Wait Set队列,它会释放monitor锁,它也是Waiting Thread,线程状态in Object.wait()
  • 如果其他线程调用 notify() / notifyAll() ,会唤醒Wait Set中的某个线程,该线程再次尝试获取monitor锁,成功即进入Owner区域。

Dump 文件分析关注重点

  • runnable,线程处于执行中
  • deadlock,死锁(重点关注)
  • blocked,线程被阻塞 (重点关注)
  • Parked,停止
  • locked,对象加锁
  • waiting,线程正在等待
  • waiting to lock 等待上锁
  • Object.wait(),对象等待中
  • waiting for monitor entry 等待获取监视器(重点关注)
  • Waiting on condition,等待资源(重点关注),最常见的情况是线程在等待网络的读写

实战案例1:jstack 分析死锁问题

  • 什么是死锁?
  • 如何用jstack排查死锁?

什么是死锁?

技术图片

死锁是指两个或两个以上的线程在执行过程中,因争夺资源而造成的一种互相等待的现象,若无外力作用,它们都将无法进行下去。

如何用如何用jstack排查死锁问题

先来看一段会产生死锁的Java程序,源码如下:

/**
 * Java 死锁demo
 */
public class DeathLockTest {
    private static Lock lock1 = new ReentrantLock();
    private static Lock lock2 = new ReentrantLock();

    public static void deathLock() {
        Thread t1 = new Thread() {
            @Override
            public void run() {
                try {
                    lock1.lock();
                    System.out.println(Thread.currentThread().getName() + " get the lock1");
                    Thread.sleep(1000);
                    lock2.lock();
                    System.out.println(Thread.currentThread().getName() + " get the lock2");
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        };
        Thread t2 = new Thread() {
            @Override
            public void run() {
                try {
                    lock2.lock();
                    System.out.println(Thread.currentThread().getName() + " get the lock2");
                    Thread.sleep(1000);
                    lock1.lock();
                    System.out.println(Thread.currentThread().getName() + " get the lock1");
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        };
        //设置线程名字,方便分析堆栈信息
        t1.setName("mythread-jay");
        t2.setName("mythread-tianluo");
        t1.start();
        t2.start();
    }
    public static void main(String[] args) {
        deathLock();
    }
}

运行结果:
技术图片
显然,线程jay和线程tianluo都是只执行到一半,就陷入了阻塞等待状态~

jstack排查Java死锁步骤

  • 在终端中输入jsp查看当前运行的java程序
  • 使用 jstack -l pid 查看线程堆栈信息
  • 分析堆栈信息

在终端中输入jsp查看当前运行的java程序

技术图片
通过使用 jps 命令获取需要监控的进程的pid,我们找到了23780 DeathLockTest

使用 jstack -l pid 查看线程堆栈信息

技术图片
由上图,可以清晰看到死锁信息:

  • mythread-tianluo 等待这个锁 “0x00000000d61ae3a0”,这个锁是由于mythread-jay线程持有。
  • mythread-jay线程等待这个锁“0x00000000d61ae3d0”,这个锁是由mythread-tianluo 线程持有。

还原死锁真相

技术图片
“mythread-tianluo"线程堆栈信息分析如下:

  • mythread-tianluo的线程处于等待(waiting)状态,持有“0x00000000d61ae3d0”锁,等待“0x00000000d61ae3a0”的锁

“mythread-jay"线程堆栈信息分析如下:

  • mythread-tianluo的线程处于等待(waiting)状态,持有“0x00000000d61ae3a0”锁,等待“0x00000000d61ae3d0”的锁

技术图片

实战案例2:jstack 分析CPU过高问题

来个导致CPU过高的demo程序,一个死循环,哈哈~

/**
 * 有个导致CPU过高程序的demo,死循环
 */
public class JstackCase {

     private static ExecutorService executorService = Executors.newFixedThreadPool(5);

    public static void main(String[] args) {

        Task task1 = new Task();
        Task task2 = new Task();
        executorService.execute(task1);
        executorService.execute(task2);
    }

    public static Object lock = new Object();

    static class Task implements Runnable{

        public void run() {
            synchronized (lock){
                long sum = 0L;
                while (true){
                    sum += 1;
                }
            }
        }
    }
}

jstack 分析CPU过高步骤

    1. top
    1. top -Hp pid
    1. jstack pid
    1. jstack -l [PID] >/tmp/log.txt
    1. 分析堆栈信息

1.top

在服务器上,我们可以通过top命令查看各个进程的cpu使用情况,它默认是按cpu使用率由高到低排序的
技术图片
由上图中,我们可以找出pid为21340的java进程,它占用了最高的cpu资源,凶手就是它,哈哈!

2. top -Hp pid

通过top -Hp 21340可以查看该进程下,各个线程的cpu使用情况,如下:
技术图片
可以发现pid为21350的线程,CPU资源占用最高,嘻嘻,小本本把它记下来,接下来拿jstack给它拍片子

3. jstack pid

通过top命令定位到cpu占用率较高的线程之后,接着使用jstack pid命令来查看当前java进程的堆栈状态,jstack 21350后,内容如下:
技术图片

4. jstack -l [PID] >/tmp/log.txt

其实,前3个步骤,堆栈信息已经出来啦。但是一般在生成环境,我们可以把这些堆栈信息打到一个文件里,再回头仔细分析哦~

5. 分析堆栈信息

我们把占用cpu资源较高的线程pid(本例子是21350),将该pid转成16进制的值

技术图片
在thread dump中,每个线程都有一个nid,我们找到对应的nid(5366),发现一直在跑(24行)

技术图片

这个时候,可以去检查代码是否有问题啦~ 当然,也建议隔段时间再执行一次stack命令,再一份获取thread dump,毕竟两次拍片结果(jstack)对比,更准确嘛~

参考与感谢

个人公众号

技术图片

  • 觉得写得好的小伙伴给个点赞+关注啦,谢谢~
  • 如果有写得不正确的地方,麻烦指出,感激不尽。
  • 同时非常期待小伙伴们能够关注我公众号,后面慢慢推出更好的干货~嘻嘻
  • github地址:https://github.com/whx123/JavaHome














以上是关于怎样使用jstack诊断Java应用程序故障的主要内容,如果未能解决你的问题,请参考以下文章

怎样使用jstack诊断Java应用程序故障

怎样使用jstack诊断Java应用程序故障

怎样使用jstack诊断Java应用程序故障

怎样使用jstack诊断Java应用程序故障

JVM故障问题排查心得「线程诊断系列」通过jstack线程状态分析虚拟机线程问题指南

基于Linux的WebSphere性能调优与故障诊断