JVM(四)-虚拟机性能监控和故障处理工具

参考文献

深入理解Java虚拟机:JVM高级特性与最佳实践(第3版)
JDK Tools and Utilities
How to Analyze Java Thread Dumps

基础故障处理工具

工具	简介
`java`	Java 应用的启动程序
`javac`	JDK 内置的编译工具
`javap`	反编译 class 文件的工具
`javadoc`	根据 Java 代码和标准注释,自动生成相关的 API 说明文档
`javah`	JNI 开发时,根据 Java 代码生成需要的 .h 文件.
`extcheck`	检查某个 jar 文件和运行时扩展 jar 有没有版本冲突,很少使用
`jdb`	Java Debugger 可以调试本地和远端程序,属于 JPDA 中的一个 Demo 实现,供其他调试器参考.开发时很少使用
`jdeps`	探测 class 或 jar 包需要的依赖
`jar`	打包工具,可以将文件和目录打包成为 .jar 文件；.jar 文件本质上就是 zip 文件,只是后缀不同.使用时按顺序对应好选项和参数即可.
`keytool`	安全证书和密钥的管理工具(支持生成、导入、导出等操作)
`jarsigner`	jar 文件签名和验证工具
`policytool`	实际上这是一款图形界面工具,管理本机的 Java 安全策略

`jps`: 虚拟机进程状况工具

jps(JVM Process Status Tool)
可以列出正在运行的虚拟机进程,并显示虚拟机执行主类(Main Class,main()函数所在的类)名称以及这些进程的本地虚拟机唯一 ID(LVMID,Local Virtual Machine Identifier)
命令格式
1
jps [options] [hostid]
- -q: 只输出LVMID,省略主类的名称;
- -m: 输出虚拟机进程启动时传递给主类main()函数的参数;
- -l: 输出主类的全名,如果进程执行的JAR包,则输出JAR路径;
- -v: 输出虚拟机进程启动时的JVM参数

`jstat`: 虚拟机统计信息监视工具

jstat(JVM Statistics Monitoring Tool)是用于监视虚拟机各种运行状态信息的命令行工具.
它可以显示本地或者远程虚拟机进程中的类加载、内存、垃圾收集、即时编译等运行时数据,在没有 GUI 图形界面、只提供了纯文本控制台环境的服务器上,它将是运行期定位虚拟机性能问题的常用工具.

命令格式

1	jstat [option vmid [interval[s\|ms]] [count]]

对于命令格式中的 VMID 与 LVMID 需要特别说明一下: 如果是本地虚拟机进程,VMID 与 LVMID 是一致的；如果是远程虚拟机进程,那VMID 的格式应当是:
1
protocol:][//]lvmid[@hostname[:port]/servername
参数 interval 和 count 代表查询间隔和次数,如果省略这 2 个参数,说明只查询一次.假设需要每 250 毫秒查询一次进程 2764 垃圾收集状况,一共查询 20 次,那命令应当是
1
jstat -gc 2764 250 20

选项 option 代表用户希望查询的虚拟机信息,主要分为三类: 类加
载、垃圾收集、运行期编译状况

选项	作用
`-class`	监视类加载,卸载数量,总空间以及类装在所耗费的时间
`-gc`	监视Java堆状况,包括Eden区,2个Survivor区,老年代,永久代等容量已用空间,垃圾收集时间合计等信息
`-gccapacity`	监视内容与-gc基本相同,但输出主要关注Java堆各个区域使用到的最大,最小空间
`-gcutil`	监视内容与-gc基本相同,但输出主要关注已使用空间占总空间的百分比
`-gccause`	与-gcutil功能一样,但是会额外输出导致上一次垃圾收集产生的原因
`-gcnew`	监视新生代垃圾收集状况
`-gcnewcapacity`	监视内容与-gcnew基本相同,输出主要关注使用到的最大,最小空间
`-gcold`	监视老年代垃圾收集状态
`-gcoldcapacity`	监视内容与-gcold基本相同,输出主要关注使用到的最大,最小空间
`-gcpermcapacity`	输出永久代使用到的最大,最小空间
`-complier`	输出即使编译器编译过的方法,耗时等信息
`-printcompilation`	输出已经被即时编译的方法

示例

`-gcutil`

1	jstat -gcutil -t 93217

-t 选项的位置是固定的,不能在前也不能在后.可以看出是用于显示时间戳,即 JVM 启动到现在的秒数.

Timestamp	S0	S1	E	O	M	CCS	YGC	YGCT	FGC	FGCT	CGC	CGCT	GCT
2975.9	0.00	100.00	84.55	75.93	97.58	92.68	63	0.653	0	0.000	6	0.004	0.657

Timestamp 列: JVM 启动了 2975秒.
S0: 就是 0 号存活区的百分比使用率.0% 很正常,因为 S0 和 S1 随时有一个是空的.
S1: 就是 1 号存活区的百分比使用率.
E: 就是 Eden 区,新生代的百分比使用率.
O: 就是 Old 区,老年代.百分比使用率.
M: 就是 Meta 区,元数据区百分比使用率.
CCS: 压缩 class 空间(Compressed class space)的百分比使用率.
YGC(Young GC): 年轻代 GC 的次数.
YGCT 年轻代 GC 消耗的总时间.
FGC: FullGC 的次数.
FGCT: FullGC 的总时间.
GCT: 所有 GC 加起来消耗的总时间,即 YGCT + FGCT.

`-gc`

# 每隔 1 秒输出一次该进程的 GC 统计信息，并且附带显示 JVM 运行时间
jstat -gc -t 93217 1s
# 每隔 1 秒输出一次 GC 统计信息，并在输出 3 次之后自动停止
jstat -gc -t 93217 1s 3
# 每隔 1 秒输出一次 GC 统计信息，并且每 10 行输出一次表头，输出 15 次后自动停止
jstat -gc -t -h 10 93217 1s 15

1
2
3

jstat -gc -t 7
Timestamp        S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT
       785384.0  0.0   4096.0  0.0   4096.0 3100672.0 634880.0 1818624.0   404109.1  144680.0 140248.6 17024.0 15523.3    461    2.279   0      0.000  672     4.785    7.064

Timestamp 列: JVM 启动了 785384秒,大约 9 天.
S0C: From Survivor的当前容量(capacity),单位 kB.
S1C: To Survivor存活区的当前容量,单位 kB.
S0U: From Survivor的使用量(utilization),单位 kB.
S1U: To Survivor的使用量,单位 kB.
EC: Eden 区的当前容量,单位 kB.
EU: Eden 区的使用量,单位 kB.
OC: Old 区的当前容量,单位 kB.
OU: Old 区的使用量,单位 kB. (需要关注)
MC: 元数据区的容量,单位 kB.
MU: 元数据区的使用量,单位 kB.
CCSC: 压缩的 class 空间容量,单位 kB.
CCSU: 压缩的 class 空间使用量,单位 kB.
YGC: 年轻代 GC 的次数.
YGCT: 年轻代 GC 消耗的总时间,单位秒. (重点关注)
FGC: Full GC 的次数
FGCT: Full GC 消耗的时间,单位秒. (重点关注)
CGC: 整个垃圾回收的次数（包括 Young GC 和 Full GC）。
CGCT: 整个垃圾回收消耗的总时间。
GCT: 所有垃圾回收消耗的总时间单位秒。

`jinfo`: Java配置信息工具

Jinfo(Configuration Info for Java)的作用是实时查看和调整虚拟机各项参数.
使用jps -v可以查看虚拟机启动时显式指定的参数列表,但是想知道未被显式指定的参数的系统默认值,可以使用jinfo -flag
Jinfo还可以使用-sysprops选项把虚拟机进程的System.getProperties()的内容打印出来

命令格式:

jinfo [option] pid
Usage:
    jinfo <option> <pid>
       (to connect to a running process)

where <option> is one of:
    -flag <name>         to print the value of the named VM flag
    -flag [+|-]<name>    to enable or disable the named VM flag
    -flag <name>=<value> to set the named VM flag to the given value
    -flags               to print VM flags
    -sysprops            to print Java system properties
    <no option>          to print both VM flags and system properties
    -? | -h | --help | -help to print this help message

1
2
3

root@xxxx:/home/xxxx# jinfo -flags 934668
VM Flags:
-XX:CICompilerCount=3 -XX:ConcGCThreads=1 -XX:G1ConcRefinementThreads=4 -XX:G1HeapRegionSize=2097152 -XX:GCDrainStackTargetSize=64 -XX:InitialHeapSize=526385152 -XX:MarkStackSize=4194304 -XX:MaxHeapSize=8420065280 -XX:MaxNewSize=5052039168 -XX:MinHeapDeltaBytes=2097152 -XX:NonNMethodCodeHeapSize=5830732 -XX:NonProfiledCodeHeapSize=122913754 -XX:ProfiledCodeHeapSize=122913754 -XX:ReservedCodeCacheSize=251658240 -XX:+SegmentedCodeCache -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseG1GC

`jmap`: Java内存映像工具

Jmap(Memory Map for Java)命令用于生成堆转储快照(一般为heapdump或dump文件).
如果不适用jmap命令,要想获取Java堆转储快照也可以使用-XX:+HeapDumpOnOutOfMemoryError参数,可以让虚拟机在内存溢出异常出现之后自动生成堆存储快照文件,也通过-XX:+HeapDumpOnCtrlBreak参数使用Ctrl+Break键让虚拟机生成堆转储快照文件,也可以在Linux系统下通过kill -3命令发送进程退出信号来获取堆转储快照.
jmap的作用不仅是为了获取堆转储快照,它还可以查询 finalize执行队列、Java 堆和方法区的详细信息,如空间使用率、当前用的是哪种收集器等.
jmap 命令,它在 JDK9 版本里被干掉了,取而代之的是 jhsdb

命令格式

jmap [option] vmid	
Usage:
    jmap -clstats <pid>
        to connect to running process and print class loader statistics
    jmap -finalizerinfo <pid>
        to connect to running process and print information on objects awaiting finalization
    jmap -histo[:live] <pid>
        to connect to running process and print histogram of java object heap
        if the "live" suboption is specified, only count live objects
    jmap -dump:<dump-options> <pid>
        to connect to running process and dump java heap
    jmap -? -h --help
        to print this help message

    dump-options:
      live         dump only live objects; if not specified,
                   all objects in the heap are dumped.
      format=b     binary format
      file=<file>  dump heap to <file>
      parallel=<number>  parallel threads number for heap iteration:
                         parallel=0 default behavior, use predefined number of threads
                         parallel=1 disable parallel heap iteration
                         parallel=<N> use N threads for parallel heap iteration

    Example: jmap -dump:live,format=b,file=heap.bin <pid>


# jmap -heap 4524 使用jhsdb jmap --heap --pid 4524代替 
jhsdb jmap --heap --pid 31258

jmap -histo 4524

jmap -dump:format=b,file=3826.hprof 3826

选项	作用
`-dump`	生成Java堆转储快照.格式为`-dump:[live,]format=b,file=\<filename>`,其中live子参数说明是否是dump出存活的对象
`-finalizerinfo`	显示在F-Queue中等待Finalizer线程执行finalize方法的对象.只在Linux/Solaris平台下有效
`-heap`	显示Java堆详细信息,让使用哪种回收器,参数配置,分代状况等,只在Linux/Solaris平台下有效
`-histo`	显示堆中对象统计信息,包括类,实例数量,合计容量
`-permstat`	以ClassLoader为统计口径显示永久代内存状态,只在Linux/Solaris平台下有效
`-F`	当虚拟机进程对-dump选项没有响应时,可以使用这个选项强制生成dump快照.只在Linux/Solaris平台有效

`jhat`: 虚拟机堆转储快照分析工具

jhat(JVM Heap Analysis Tool)命令与jmap搭配使用,来分析jmap生成的堆转储快照.
jhat内置了一个微型HTTP/Web服务,生成堆转储快照的分析结果后,可以在浏览器中查看
替代品: VisualVM,Eclipse Memory Analyzer.

`jstack`: Java堆栈跟踪工具

Jstack(Stack Trace for Java)命令用于生成虚拟机当前时刻的线程快照(一般称为threaddump或者javacore文件).
线程快照就是当前虚拟机内每一条线程正在执行的方法堆栈的集合.
生成线程快照的目的通常是定位线程出现长时间停顿的原因,如线程间死锁、死循环、请求外部资源导致的长时间挂起等,都是导致线程长时间停顿的常见原因.
线程出现停顿时通过 jstack 来查看各个线程的调用堆栈,就可以获知没有响应的线程到底在后台做些什么事情,或者等待着什么资源.

命令格式:

jstack [option] vmid

Usage:
    jstack [-l][-e] <pid>
        (to connect to running process)

Options:
    -l  long listing. Prints additional information about locks
    -e  extended listing. Prints additional information about threads
    -? -h --help -help to print this help message
    
jstack 999 > ./dump.txt

选项	作用
`-F`	强制执行 Thread Dump,可在 Java 进程卡死(hung 住)时使用,此选项可能需要系统权限.
`-l`	混合模式(mixed mode),将 Java 帧和 native 帧一起输出,此选项可能需要系统权限
`-m`	长列表模式,将线程相关的 locks 信息一起输出,比如持有的锁,等待的锁

`jstack`内容格式说明

全局信息(Global Information):这部分提供了关于 Java 进程的全局信息,包括 JVM 版本、进程 ID、线程总数等.
线程快照(Thread Dump):这是 jstack 输出的主要部分,它包含了当前 Java 进程中所有线程的信息.每个线程的信息包括线程名称、线程 ID、线程状态和堆栈信息.
锁信息(Lock Information):如果存在锁相关的问题,这部分会显示与锁相关的信息,例如锁的拥有者和等待者.
Java 进程中的其他线程(Other Threads in Java Process):这部分列出了除了 Java 线程之外的其他线程,例如操作系统线程.

`jstack`输出内容说明

第一行显示时间戳,第二行显示有关 JVM 的信息

1 2	2023-12-18 09:36:11 Full thread dump OpenJDK 64-Bit Server VM (11.0.15+10 mixed mode, sharing):

然后是显示安全内存回收 (SMR) 和非 JVM 内部线程

Threads class SMR info:
_java_thread_list=0x00007f67d02e6270, length=142, elements={
0x00007f6824027800, 0x00007f6824297000, 0x00007f6824299000, 0x00007f68242a0000,
0x00007f68242a2000, 0x00007f68242a4000, 0x00007f68242a6000, 0x00007f68242a8000,
0x00007f68242f3000, 0x00007f68245ea800, 0x00007f68249f7000, 0x00007f6824649000,
......
}

然后,转储显示线程列表.每个线程包含以下信息:

Name: 线程名称,
Priority (prior): 线程的优先级
Java ID (tid): JVM给出的唯一ID
Native ID (nid): 操作系统给出的唯一 ID,可用于提取与 CPU 或内存处理的相关性
State: 线程的实际状态
Stack trace

"pacs-pull-task-handlers-0" #129 prio=5 os_prio=0 cpu=16.79ms elapsed=232579.88s tid=0x00007f68258cb800 nid=0x8b waiting on condition  [0x00007f67727c9000]
   java.lang.Thread.State: WAITING (parking)
        at jdk.internal.misc.Unsafe.park(java.base@11.0.15/Native Method)
        - parking to wait for  <0x000000063ef4c4a0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(java.base@11.0.15/LockSupport.java:194)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.15/AbstractQueuedSynchronizer.java:2081)
        at java.util.concurrent.LinkedBlockingQueue.take(java.base@11.0.15/LinkedBlockingQueue.java:433)
        at com.xx.ct.pacs.utils.GlobalPullTaskContext.take(GlobalPullTaskContext.java:20)
        at com.xx.ct.pacs.manager.StoreDicomWithLockRunnable.run(StoreDicomWithLockRunnable.java:40)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.15/ThreadPoolExecutor.java:1128)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.15/ThreadPoolExecutor.java:628)
        at java.lang.Thread.run(java.base@11.0.15/Thread.java:829)

   Locked ownable synchronizers:
        - <0x000000061b95c2d8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
        - <0x000000063ef4c5a0> (a java.util.concurrent.ThreadPoolExecutor$Worker)

“pacs-pull-task-handlers-0”: 线程名称,
#129: 线程 ID,是线程的唯一标识符.
prio=5: 线程优先级,表示线程在操作系统中的优先级.较低的数字表示较高的优先级.
os_prio=0: 操作系统优先级,表示线程在操作系统中的实际优先级.
cpu=16.79ms: 线程在 CPU 上的累计执行时间.
elapsed=232579.88s: 线程的已经过去的时间,以秒为单位.
tid=0x00007f68258cb800: 线程 ID 的十六进制表示.
nid=0x8b: 线程 ID 的十六进制表示.
waiting on condition: 线程当前的状态,表示线程正在等待某个条件.

GC信息

"VM Thread" os_prio=0 cpu=66854.35ms elapsed=232598.78s tid=0x00007f6824294000 nid=0xe runnable
"GC Thread#0" os_prio=0 cpu=50241.62ms elapsed=232598.81s tid=0x00007f682403f000 nid=0x9 runnable
"GC Thread#1" os_prio=0 cpu=50118.80ms elapsed=232598.31s tid=0x00007f67e4001000 nid=0x19 runnable
"GC Thread#2" os_prio=0 cpu=49487.58ms elapsed=232598.31s tid=0x00007f67e4002800 nid=0x1a runnable
"GC Thread#3" os_prio=0 cpu=50205.85ms elapsed=232598.31s tid=0x00007f67e4004000 nid=0x1b runnable
"G1 Main Marker" os_prio=0 cpu=38.97ms elapsed=232598.81s tid=0x00007f6824079800 nid=0xa runnable
"G1 Conc#0" os_prio=0 cpu=16157.80ms elapsed=232598.81s tid=0x00007f682407b000 nid=0xb runnable
"G1 Refine#0" os_prio=0 cpu=45.40ms elapsed=232598.81s tid=0x00007f68241ed800 nid=0xc runnable
"G1 Refine#1" os_prio=0 cpu=1.23ms elapsed=232557.45s tid=0x00007f67ec081800 nid=0xa5 runnable
"G1 Young RemSet Sampling" os_prio=0 cpu=289097.87ms elapsed=232598.81s tid=0x00007f68241ef800 nid=0xd runnable
"VM Periodic Task Thread" os_prio=0 cpu=64364.52ms elapsed=232598.73s tid=0x00007f68242f1000 nid=0x16 waiting on condition

JNI global refs: 87, weak refs: 1

分析技巧

主要关注RUNNABLE或BLOCKED线程,最终关注TIMED_WAITING线程.这些状态将向我们指出两个或多个线程之间发生冲突的方向:
- In a deadlock **situation in which several threads running hold a synchronized block on a shared object.**在死锁情况下,多个正在运行的线程在共享对象上持有同步块
- In thread contention, when a thread is blocked waiting for others to finish. 在线程竞争中,当一个线程被阻塞等待其他线程完成时.
对于异常高的CPU使用率,我们只需要查看RUNNABLE线程.我们将使用线程转储和其他命令来获取额外的信息.这些命令之一是 top -H -p PID,它显示哪些线程正在消耗该特定进程中的操作系统资源.我们还需要查看 JVM 内部线程,例如 GC,以防万一.另一方面,当处理性能异常低时,我们将查看BLOCKED线程.
- 在这些情况下,单个转储肯定不足以了解正在发生的情况.我们需要以紧密的间隔进行多次转储,以便比较同一线程在不同时间的堆栈.一方面,一张快照并不总是足以找出问题的根源.另一方面,我们需要避免快照之间的噪音(信息太多).
- 要了解线程随时间的演变,建议的最佳实践是至少进行 3 次转储,每 10 秒一次.另一个有用的技巧是将转储分成小块,以避免加载文件时发生崩溃.

`jcmd`: 诊断工具

诊断工具: jcmd 是 JDK 8 推出的一款本地诊断工具,只支持连接本机上同一个用户空间下的 JVM 进程.

[root@iZuf6ib0sh7w9cc92x0h4qZ ~]# jcmd --help
Usage: jcmd <pid | main class> <command ...|PerfCounter.print|-f file>
   or: jcmd -l                                                    
   or: jcmd -h                                                    
                                                                  
  command 必须是指定 JVM 可用的有效 jcmd 命令.     
  可以使用 "help" 命令查看该 JVM 支持哪些命令.  
  如果指定 pid 部分的值为 0,则会将 commands 发送给所有可见的 Java 进程.  
  指定 main class 则用来匹配启动类.可以部分匹配.(适用同一个类启动多实例).                       
  If no options are given, lists Java processes (same as -p).    

  PerfCounter.print 命令可以展示该进程暴露的各种计数器
  -f  从文件读取可执行命令                 
  -l  列出(list)本机上可见的 JVM 进程                    
  -h  this help

# JVM 实例运行时间
jcmd 11155 VM.uptime
9307.052 s

#JVM 版本号
jcmd 11155 VM.version
OpenJDK 64-Bit Server VM version 25.76-b162
JDK 8.0_76

# JVM 实际生效的配置参数
jcmd 11155 VM.flags
11155:
-XX:CICompilerCount=4 -XX:InitialHeapSize=268435456
-XX:MaxHeapSize=536870912 -XX:MaxNewSize=178782208
-XX:MinHeapDeltaBytes=524288 -XX:NewSize=89128960
-XX:OldSize=179306496 -XX:+UseCompressedClassPointers
-XX:+UseCompressedOops -XX:+UseParallelGC

# 查看命令行参数
jcmd 11155 VM.command_line
VM Arguments:
jvm_args: -Xmx512m -Dfile.encoding=UTF-8
java_command: org.jetbrains.idea.maven.server.RemoteMavenServer
java_class_path (initial): ...(xxx省略)...
Launcher Type: SUN_STANDARD

# 系统属性
jcmd 11155 VM.system_properties
...
java.runtime.name=OpenJDK Runtime Environment
java.vm.version=25.76-b162
java.vm.vendor=Oracle Corporation
user.country=CN

示例

分析哪个线程引起的CPU问题

注: 若应用是docker容器,则需要先进容器然后执行以下命令

使用top命令,查找到使用CPU最多的某个进程,记录它的pid.使用Shift + P快捷键可以按CPU的使用率进行排序

top -b -n 1 | grep java
  15812 root      20   0 8176456   3.0g  13992 S   6.2   9.4  29:39.22 java
  13754 root      20   0 4772516 312764   5164 S   0.0   1.0   8:47.42 java
  13848 root      20   0 5049192   1.0g   1508 S   0.0   3.2  44:14.55 java
  17090 root      20   0 8167128   3.2g  12400 S   0.0  10.3  31:02.32 java
2161750 root      20   0 8210492   1.7g  28472 S   0.0   5.3   2:22.51 java

使用top -Hp $pid,查看某个进程中使用CPU最多的某个线程,记录线程的ID

 top -Hp 17090
top - 13:38:28 up 5 days,  4:01,  2 users,  load average: 0.23, 0.15, 0.10
Threads: 119 total,   0 running, 119 sleeping,   0 stopped,   0 zombie
%Cpu(s):  1.6 us,  1.6 sy,  0.0 ni, 96.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :  32101.2 total,   2626.6 free,  20510.1 used,   8964.4 buff/cache
MiB Swap:      0.0 total,      0.0 free,      0.0 used.  11124.8 avail Mem

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
  17090 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:00.00 java
  17091 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:15.85 java
  17096 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:46.26 GC Thread#0
  17098 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:00.00 G1 Main Marker
  17099 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:00.31 G1 Conc#0
  17101 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:00.14 G1 Refine#0
  17102 root      20   0 8167128   3.2g  12400 S   0.0  10.3  11:26.19 G1 Young RemSet
  17103 root      20   0 8167128   3.2g  12400 S   0.0  10.3   1:13.02 VM Thread
  17104 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:00.03 Reference Handl
  17105 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:00.00 Finalizer
  17106 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:00.00 Signal Dispatch
  17107 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:00.11 Service Thread
  17108 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:55.03 C2 CompilerThre
  17109 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:09.51 C1 CompilerThre
  17110 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:00.11 Sweeper thread
  17119 root      20   0 8167128   3.2g  12400 S   0.0  10.3   3:26.96 VM Periodic Tas
  17121 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:00.30 Common-Cleaner
  17168 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:46.28 GC Thread#1
  17169 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:46.36 GC Thread#2
  17170 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:46.24 GC Thread#3
  17201 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:08.50 com.alibaba.nac
  17202 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:02.04 com.alibaba.nac
  17203 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:03.36 com.alibaba.nac
  17204 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:02.55 com.alibaba.nac
  17212 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:00.01 logback-3
  17213 root      20   0 8167128   3.2g  12400 S   0.0  10.3   0:00.00 logback-4

使用printf %x $tid,将十进制的tid转换为十六进制
使用jstack $pid >$pid.log存储Java进程的线程栈
使用less命令查看生成的文件,并查找刚才转化的十六进制的tid,找到发生问题的上下文.

其他资源的查看

系统当前网络连接

1	ss -antp > $DUMP_DIR/ss.dump 2>&1

其中,ss 命令将系统的所有网络连接输出到 ss.dump 文件中.使用 ss 命令而不是 netstat 的原因,是因为 netstat 在网络连接非常多的情况下,执行非常缓慢.
后续的处理,可通过查看各种网络连接状态的梳理,来排查 TIME_WAIT 或者 CLOSE_WAIT,或者其他连接过高的问题,非常有用.
线上有个系统更新之后,监控到 CLOSE_WAIT 的状态突增,最后整个 JVM 都无法响应.CLOSE_WAIT 状态的产生一般都是代码问题,使用 jstack 最终定位到是因为 HttpClient 的不当使用而引起的,多个连接不完全主动关闭.

网络状态统计

1	netstat -s > $DUMP_DIR/netstat-s.dump 2>&1

此命令将网络统计状态输出到 netstat-s.dump 文件中.它能够按照各个协议进行统计输出,对把握当时整个网络状态,有非常大的作用.

1	sar -n DEV 1 2 > $DUMP_DIR/sar-traffic.dump 2>&1

上面这个命令,会使用 sar 输出当前的网络流量.在一些速度非常高的模块上,比如 Redis、Kafka,就经常发生跑满网卡的情况.如果你的 Java 程序和它们在一起运行,资源则会被挤占,表现形式就是网络通信非常缓慢.

进程资源

1	lsof -p $PID > $DUMP_DIR/lsof-$PID.dump

CPU资源

mpstat > $DUMP_DIR/mpstat.dump 2>&1
vmstat 1 3 > $DUMP_DIR/vmstat.dump 2>&1
uptime > $DUMP_DIR/uptime.dump 2>&1
sar -p ALL  > $DUMP_DIR/sar-cpu.dump  2>&1

I/O 资源

1	iostat -x > $DUMP_DIR/iostat.dump 2>&1

内存资源

1	free -h > $DUMP_DIR/free.dump 2>&1

其他全局

1
2
3

ps -ef > $DUMP_DIR/ps.dump 2>&1
dmesg > $DUMP_DIR/dmesg.dump 2>&1
sysctl -a > $DUMP_DIR/sysctl.dump 2>&1

进程快照,最后的遗言(`jinfo`)

1	${JDK_BIN}jinfo $PID > $DUMP_DIR/jinfo.dump 2>&1

`dump`堆信息

1 2	jstat -gcutil $PID > $DUMP_DIR/jstat-gcutil.dump 2>&1 jstat -gccapacity $PID > $DUMP_DIR/jstat-gccapacity.dump 2>&1

Java 9之前

jhsdb jmap --pid $PID > $DUMP_DIR/jmap.dump 2>&1
jhsdb jmap -heap $PID > $DUMP_DIR/jmap-heap.dump 2>&1
jhsdb jmap --histo --pid $PID > $DUMP_DIR/jmap-histo.dump 2>&1
jhsdb jmap --binaryheap --pid $PID --outfile $DUMP_DIR/heap.bin > /dev/null 2>&1

Java 9之后

jcmd $PID GC.heap_dump $DUMP_DIR/heap.bin
# 使用下面命令时 需要开启-XX:NativeMemoryTracking=detail 不然会遇到Native memory tracking is not enabled 提示
jcmd $PID VM.native_memory summary > $DUMP_DIR/native-memory-summary.txt
jcmd $PID GC.class_histogram > $DUMP_DIR/class-histogram.txt
jcmd $PID VM.flags > $DUMP_DIR/vm-flags.txt

`JVM`执行栈

1	jstack $PID > $DUMP_DIR/jstack.dump 2>&1

参考文献

基础故障处理工具

jps: 虚拟机进程状况工具

jstat: 虚拟机统计信息监视工具

示例

-gcutil

-gc

jinfo: Java配置信息工具

jmap: Java内存映像工具

jhat: 虚拟机堆转储快照分析工具

jstack: Java堆栈跟踪工具

jstack内容格式说明

jstack输出内容说明