程序喵

择善人而交，择善书而读
择善言而听，择善行而从
当前位置：首页 > Java开发 > jvm 指令工具 jstack 命令（Java堆栈跟踪） 大屏阅读

jvm 指令工具 jstack 命令（Java堆栈跟踪）

4年前 (2021-01-27) 分类：Java开发 阅读(1542) 评论(0)

一、jstack

1、jstack 是什么？

jstack 全称：Java Stack Trace（Java堆栈跟踪）

jstack是 java虚拟机自带的一种堆栈跟踪工具，用于生成java虚拟机当前时刻的线程快照。

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

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

如果java程序崩溃生成core文件，jstack工具可以用来获得core文件的java stack和native stack的信息，从而可以轻松地知道java程序是如何崩溃和在程序何处发生问题。

另外jstack工具还可以附属到正在运行的java程序中，看到当时运行的java程序的java stack和native stack的信息, 如果现在运行的java程序呈现hung的状态，jstack是非常有用的。

注意点

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

  • 在实际运行中，往往一次 dump的信息，还不足以确认问题。建议产生三次 dump信息，如果每次 dump都指向同一个问题，我们才确定问题的典型性。

2、jstack 命令

➜  ~ jstack
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)     # 连接dump的文件
    jstack [-m] [-l] [server_id@]<remote server IP or hostname> 
        (to connect to a remote debug server)  # 连接远程debug服务器

Options:
    -F  to force a thread dump. Use when jstack <pid> does not respond (process is hung) # 当 jstack <pid> 没有响应打印的时候强制打印栈信息
    -m  to print both java and native frames (mixed mode) # 打印java和native 框架的所有栈信息，可以打印JVM的堆栈,显示上Native的栈帧，一般应用排查不需要使用
    -l  long listing. Prints additional information about locks # 长列表，打印关于锁的附加信息，例如属于java.util.concurrent的ownable synchronizers列表，一般情况不需要使用
    -h or -help to print this help message # 打印帮助信息

3、语法格式

jstack [option] pid
jstack [option] executable core
jstack [option] [server-id@]remote-hostname-or-IP

描述

  • pid：需要被打印配置信息的java进程id，可以用jps获取。

  • executable：产生core dump的java可执行程序。

  • core：打印出的core文件。

  • remote-hostname-or-ip：远程debug服务器的名称或IP。

  • server-id：唯一id，假如一台主机上多个远程debug服务。

示例

$ jstack –l 23561

4、分析 jstack 输出

在执行 jstack -l [PID] > /tmp/output.txt 之后可以对 /tmp/output.txt 进行分析

jstack 输出开头是当前 dump 的时间和 JVM 基本信息（包括版本等）

二、线程分析

1、线程信息

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

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

用户级别的线程：它会根据用户请求的不同而发生变化。该类线程的运行情况往往是我们所关注的重点。而且这一部分也是最容易产生死锁的地方。

"pool-1-thread-3" #12 prio=5 os_prio=0 tid=0x00007fc99412f000 nid=0x9bc in Object.wait() [0x00007fc97c2f2000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000d7017420> (a com.liang.java.thinkinginjava.concurency.waxomatic.Car)
    at java.lang.Object.wait(Object.java:502)
    at com.liang.java.thinkinginjava.concurency.waxomatic.Car.waitForBuffing(WaxOMatic.java:47)
    - locked <0x00000000d7017420> (a com.liang.java.thinkinginjava.concurency.waxomatic.Car)
    at com.liang.java.thinkinginjava.concurency.waxomatic.WaxOn.run(WaxOMatic.java:61)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
    - <0x00000000d729cdb0> (a java.util.concurrent.ThreadPoolExecutor$Worker)

用户线程的信息

  • 线程的状态：waiting on condition（导致等待的原因）

  • "pool-1-thread-3" 是线程名称

  •  prio=5 是该线程JVM中的优先级

  •  os_prio=0 是该线程在OS中的优先级

  •  tid=0x00007fc99412f000 是JVM内的线程i （Java-level thread ID）

  •  nid=0x9bc 是Native thread ID，本地操作系统相关的线程id

2、线程状态

 在jstack输出的第二行为线程的状态，在JVM中线程状态使用枚举 java.lang.Thread.State 来表示，State的定义如下：

/**
 * 在给定的时间点，线程只能处于一种状态。 这些状态是虚拟机状态，不反映任何操作系统线程状态。
 */
public enum State {
    /**
     * 尚未启动的线程处于此状态。
     */
    NEW,

    /**
     * 在Java虚拟机中执行的线程处于这种状态。
     */
    RUNNABLE,

    /**
     * 等待monitor监视器锁而被阻塞的线程处于此状态。
     */
    BLOCKED,

    /**
     * 无限期地等待另一个线程执行特定操作的线程处于此状态。
     */
    WAITING,

    /**
     * 正在等待另一个线程执行操作的线程最多达到指定的等待时间，该线程处于此状态。 
     */
    TIMED_WAITING,

    /**
     * 退出的线程处于此状态。
     */
    TERMINATED;
}

3、线程与Monitor（监视器锁）

20190721184325347.png

解释

  • 进入区（Entry 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()”。 被 synchronized保护起来的代码段称为临界区，当线程申请进入临界区时，它就进入了 “Entry Set”队列。

4、线程状态

581813-20170419142908868-1270421357.png

NEW（新建）

线程刚刚被创建，也就是已经new过了，但是还没有调用start()方法，jstack命令不会列出处于此状态的线程信息。

RUNNABLE（可运行）

RUNNABLE这个名字很具有欺骗性，很容易让人误以为处于这个状态的线程正在运行，事实上，这个状态只是表示，线程是可运行的。一个单核CPU在同一时刻，只能运行一个线程。

BLOCKED（阻塞）

线程处于阻塞状态，正在等待一个监视器锁（monitor lock）。通常情况下，是因为本线程与其他线程公用了一个锁。其他在线程正在使用这个锁进入某个synchronized同步方法块或者方法，而本线程进入这个同步代码块也需要这个锁，最终导致本线程处于阻塞状态。

WAITING（无限等待）

等待状态，等待某个condition或monitor发生，以下方法调用可能会导致一个线程处于等待状态

  • wait() 不指定超时时间；

  • join() 不指定超时时间；

  • park() 不指定超时时间；

TIMED_WAITING（有限等待）

线程等待指定的时间，以下方法的调用可能会导致线程处于这个状态：

  • wait(long timeout) 指定超时时间；

  • join(long millis) 指定超时时间；

  • sleep(long millis) 指定超时时间；

  • parkNanos(long nanos)  指定超时时间；

  • parkUntil(long deadline) 指定超时时间；

TERMINATED（线程终止）

生命周期结束

三、jstack 实例

1、jstack 查看输出

➜  ~ jstack 96256
2020-03-02 00:20:09
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.211-b12 mixed mode):

"Attach Listener" #30 daemon prio=9 os_prio=31 tid=0x00007ff134010000 nid=0x1307 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"DestroyJavaVM" #29 prio=5 os_prio=31 tid=0x00007ff131549800 nid=0x2503 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"http-nio-8080-Acceptor" #27 daemon prio=5 os_prio=31 tid=0x00007ff131633800 nid=0xa003 runnable [0x00007000036d7000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422)
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250)
    - locked <0x000000079670b230> (a java.lang.Object)
    at org.apache.tomcat.util.net.NioEndpoint.serverSocketAccept(NioEndpoint.java:461)
    at org.apache.tomcat.util.net.NioEndpoint.serverSocketAccept(NioEndpoint.java:73)
    at org.apache.tomcat.util.net.Acceptor.run(Acceptor.java:95)
    at java.lang.Thread.run(Thread.java:748)

"http-nio-8080-ClientPoller" #26 daemon prio=5 os_prio=31 tid=0x00007ff1314f7800 nid=0xa203 runnable [0x00007000035d4000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method)
    at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198)
    at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:117)
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
    - locked <0x000000079692ea60> (a sun.nio.ch.Util$3)
    - locked <0x000000079692ea50> (a java.util.Collections$UnmodifiableSet)
    - locked <0x000000079692e930> (a sun.nio.ch.KQueueSelectorImpl)
    at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
    at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:706)
    at java.lang.Thread.run(Thread.java:748)


    // 省略若干代码行 //

"VM Thread" os_prio=31 tid=0x00007ff132028800 nid=0x5003 runnable

"GC task thread#0 (ParallelGC)" os_prio=31 tid=0x00007ff130801000 nid=0x1c07 runnable

"GC task thread#1 (ParallelGC)" os_prio=31 tid=0x00007ff132005000 nid=0x2a03 runnable

"GC task thread#2 (ParallelGC)" os_prio=31 tid=0x00007ff132005800 nid=0x5403 runnable

"GC task thread#3 (ParallelGC)" os_prio=31 tid=0x00007ff131800000 nid=0x5203 runnable

"VM Periodic Task Thread" os_prio=31 tid=0x00007ff132044800 nid=0x4303 waiting on condition

JNI global references: 1040

2、jstack 统计线程数

➜  ~ jstack -l 96256 | grep 'java.lang.Thread.State' | wc -l
      25

3、jstack 检测死锁

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

Found one Java-level deadlock:
=============================
"Thread-1":
waiting to lock monitor 0x0003f334 (object 0x22c19f18, a java.lang.Object),
which is held by "Thread-0"
"Thread-0":
waiting to lock monitor 0x0003f314 (object 0x22c19f20, a java.lang.Object),
which is held by "Thread-1"

四、jstack检测cpu高

步骤一：查看cpu占用高进程

执行 top -c 命令动态显示进程及占用资源的排行，快捷键 shift+h 会显示所有的线程信息。

➜  ~ top
Mem:  16333644k total,  9472968k used,  6860676k free,   165616k buffers
Swap:        0k total,        0k used,        0k free,  6665292k cached
  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND     
17850 root      20   0 7588m 112m  11m S 100.7  0.7  47:53.80 java       
 1552 root      20   0  121m  13m 8524 S  0.7  0.1  14:37.75 AliYunDun   
 3581 root      20   0 9750m 2.0g  13m S  0.7 12.9 298:30.20 java        
    1 root      20   0 19360 1612 1308 S  0.0  0.0   0:00.81 init        
    2 root      20   0     0    0    0 S  0.0  0.0   0:00.00 kthreadd    
    3 root      RT   0     0    0    0 S  0.0  0.0   0:00.14 migration/0

步骤二：查看cpu占用高的线程

top -Hp <pid> 

或者

top -bn1 -Hp <pid>

或者
ps -mp <pid> -o THREAD,tid,time | sort -k3rn

步骤三：转换线程ID

thread id在栈信息中是以十六进制的形式显示的，因此需要使用 printf "%x \n" <tid> 命令将现场id转成十六进制的值，然后执行 jstack -l <pid> | grep <thread-hex-id> -A 10 命令显示出错的堆栈信息，如下图：

printf "%x\n" 17880          
45d8

步骤四：定位cpu占用线程

jstack 17850 | grep 45d8 -A 30

案例分析

CPU占用率过高？用jstack诊断快速解决：https://www.bilibili.com/video/BV1cA411v7tG

当CPU飙高时，它在做什么：https://www.jianshu.com/p/90579ec3113f

如何使用jstack分析线程状态：https://www.cnblogs.com/wuchanming/p/7766994.html


另外，环境有条件可以使用arthas来分析，操作比较方便

jvm相关命令之：thread：https://www.bilibili.com/video/BV19k4y1k7o9?p=10

未经允许请勿转载：程序喵 » jvm 指令工具 jstack 命令（Java堆栈跟踪）

点  赞 (1) 打  赏
分享到：
标签：