《深入理解Java虚拟机》 Jvm故障定位工具

———— JDK 1.7
words: 2.7k    views:    time: 12min
深入理解Java虚拟机

JDK的bin目录下提供了很多命令行工具，这些工具都非常稳定并且功能强大，能在处理应用程序性能问题、故障定位时发挥很大的作用。其实这些命令大多只是jdk/lib/tools.jar的一层包装，如果能借助tools中提供的接口，我们也可以在应用程序中实现功能强大的监控分析功能。

1. 命令行工具

1.1. jps

JVM Process Status Tool，虚拟机进程状况工具，其功能与unix的ps类似，可以列出正在运行的虚拟机进程，并显示主类名称等信息

命令格式：jps [options] [hostid]

-q ：只输出LVMID，省略主类的名称
-m ：输出虚拟机进程启动时传递给主类Main()函数的参数
-l ：输出主类的全名，如果进程执行的是jar包，输出jar路径
-v ：输出虚拟机进程启动时JVM参数

1.2. jstat

JVM Statistics Monitoring Tool，虚拟机统计信息监视工具，监视虚拟机各种运行状态，可以显示本地或远程虚拟机进程中的类装载、内存、垃圾收集、JIT编译等运行信息

命令格式：jstat [option vmid [ interval [s|ms] [count] ] ]

-class ：监视类装载、卸载数量、总空间及类装载所耗费的时间
-gc ：监视Java堆状态，包括Eden区、2个Survivor区、老年代等容量、已用空间、GC时间合计等信息
-gccapacity ：与 -gc 类似，但输出主要关注Java堆各个区域使用到的最大和最小空间
-gcutil ：与 -gc 类似，但输出主要关注已使用空间占总空间的百分比
-gccause ：与 -gcutil 类似，但会额外输出导致上一次gc产生的原因
-gcnew ：监视新生代gc的状况
-gcnewcapacity ：与 -gcnew 类似，但输出主要关注使用到的最大和最小空间
-gcold ：监视老年代gc的状况
-gcoldcapacity ：与 -gcold 类似，但输出主要关注使用到的最大和最小空间
-compiler ：输出JIT编译器编译过的方法、耗时等信息

对于本地虚拟机进程而言，VMID和LVMID是一致的，参数interval和count分别表示查询的间隔和次数，缺省表示只查询一次

例如，每隔100ms查询一次进程8724的gc情况，共查询5次(-h3表示每3行打印一次列头，-t表示第一列输出时间戳，距离jvm启动时)

C:\Users\shanhm1991>jstat -gc -h3 -t 8724 100 5
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
Timestamp        S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
         3160.3  0.0   8192.0  0.0   8192.0 111616.0 61440.0   142336.0   109216.3  135340.0 122862.0 18944.0 15504.8     25    0.307   4      0.564    0.872
         3160.4  0.0   8192.0  0.0   8192.0 111616.0 61440.0   142336.0   109216.3  135340.0 122862.0 18944.0 15504.8     25    0.307   4      0.564    0.872
         3160.5  0.0   8192.0  0.0   8192.0 111616.0 61440.0   142336.0   109216.3  135340.0 122862.0 18944.0 15504.8     25    0.307   4      0.564    0.872
Timestamp        S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
         3160.6  0.0   8192.0  0.0   8192.0 111616.0 61440.0   142336.0   109216.3  135340.0 122862.0 18944.0 15504.8     25    0.307   4      0.564    0.872
         3160.7  0.0   8192.0  0.0   8192.0 111616.0 61440.0   142336.0   109216.3  135340.0 122862.0 18944.0 15504.8     25    0.307   4      0.564    0.872
		 
各字段含义：
S0C：年轻代第一个survivor区的容量(字节)
S1C：年轻代第二个survivor区的容量(字节)
S0U：年轻代第一个survivor区的已使用容量(字节)
S1U：年轻代第二个survivor区的已使用容量(字节)
EC： 年轻代Eden区的容量(字节)
EU： 年轻代Eden区的已使用容量(字节)
OC： 老年代的容量(字节)
OU： 老年代的已使用容量(字节)
MC： 方法区的容量(字节)
MU： 方法区的已使用容量(字节)
CCSC: 压缩类空间大小
CCSU: 压缩类空间使用大小
YGC： 年轻代gc次数
YGCT：年轻代gc消耗时间
FGC： 老年代gc次数
FGCT：老年代gc消耗时间
GCT： gc总消耗时间
C:\Users\shanhm1991>jstat -gcutil -h3 -t 8724 100 5
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
Timestamp         S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT
         3195.1   0.00 100.00  55.05  76.73  90.78  81.85     25    0.307     4    0.564    0.872
         3195.3   0.00 100.00  55.05  76.73  90.78  81.85     25    0.307     4    0.564    0.872
         3195.3   0.00 100.00  55.05  76.73  90.78  81.85     25    0.307     4    0.564    0.872
Timestamp         S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT
         3195.4   0.00 100.00  55.05  76.73  90.78  81.85     25    0.307     4    0.564    0.872
         3195.6   0.00 100.00  55.05  76.73  90.78  81.85     25    0.307     4    0.564    0.872
		 
各字段含义：
S0：  年轻代第一个survivor区使用率
S1：  年轻代第二个survivor区使用率
E：   年轻代Eden区使用率
O：   老年代使用率
M：   方法区使用率
CCS： 压缩类空间使用率
YGC： 年轻代gc次数
YGCT：年轻代gc消耗时间
FGC： 老年代gc次数
FGCT：老年代gc消耗时间
GCT： gc总消耗时间

其它比如

C:\Users\shanhm1991>jstat -gcnew 8724
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
 S0C    S1C    S0U    S1U   TT MTT  DSS      EC       EU     YGC     YGCT
   0.0 7168.0    0.0 7168.0 15  15 6144.0  96256.0  27648.0     27    0.398
 
各字段含义：
S0C： 年轻代第一个survivor区大小
S1C： 年轻代第二个survivor区的大小
S0U： 年轻代第一个survivor区的使用大小
S1U： 年轻代第二个survivor区的使用大小
TT:   对象在年轻代存活的次数
MTT:  对象在年轻代存活的最大次数
DSS:  期望的survivor区大小
EC：  Eden区的大小
EU：  Eden区的使用大小
YGC： 年轻代gc次数
YGCT：年轻代gc消耗时间

1.3. jinfo

Configuration Info for Java，配置信息工具，实时查看和调整JVM的各项参数

命令格式：jinfo [option] pid

-flags ：打印传递给JVM命令行参数
-flag name ：输出指定name的JVM参数
-flag name=value ：设置指定name的JVM参数
-flag [+|-]name ：启用或禁用指定name的JVM参数

1.4. jmap

Memory Map for Java，内存映像工具，用于生成堆转储快照，查询finalize执行队列，Java堆等详细信息

命令格式：jmap [option] vmid

-dump ：生成Java堆转储快照
-heap ：打印Java堆详细信息，比如使用哪种回收器、参数配置、分代状况等
-histo ：打印堆中对象统计信息，包括类、实例数量和合计容量
-finalizerinfo ：打印在F-Queue中等待Finalizer线程执行finalize方法的对象

比如转储堆快照文件：jmap -dump:format=b,file=heap.dump 8724，或者打印堆的详细情况

C:\Users\shanhm1991>jmap -heap 8724
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
Attaching to process ID 8724, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.11-b03

using thread-local object allocation.
Garbage-First (G1) GC with 4 thread(s)

Heap Configuration:
   MinHeapFreeRatio         = 40
   MaxHeapFreeRatio         = 70
   MaxHeapSize              = 1073741824 (1024.0MB)
   NewSize                  = 1363144 (1.2999954223632812MB)
   MaxNewSize               = 643825664 (614.0MB)
   OldSize                  = 5452592 (5.1999969482421875MB)
   NewRatio                 = 2
   SurvivorRatio            = 8
   MetaspaceSize            = 21807104 (20.796875MB)
   CompressedClassSpaceSize = 1073741824 (1024.0MB)
   MaxMetaspaceSize         = 17592186044415 MB
   G1HeapRegionSize         = 1048576 (1.0MB)

Heap Usage:
G1 Heap:
   regions  = 1024
   capacity = 268435456 (256.0MB)
   used     = 196886512 (187.76560974121094MB)
   free     = 71548944 (68.23439025878906MB)
   73.34594130516052% used
G1 Young Generation:
Eden Space:
   regions  = 67
   capacity = 98566144 (94.0MB)
   used     = 70254592 (67.0MB)
   free     = 28311552 (27.0MB)
   71.27659574468085% used
Survivor Space:
   regions  = 7
   capacity = 7340032 (7.0MB)
   used     = 7340032 (7.0MB)
   free     = 0 (0.0MB)
   100.0% used
G1 Old Generation:
   regions  = 117
   capacity = 162529280 (155.0MB)
   used     = 118243312 (112.76560974121094MB)
   free     = 44285968 (42.23439025878906MB)
   72.75200628465221% used

67252 interned Strings occupying 7558272 bytes.

1.5. jhat

JVM Heap Analysis Tool，虚拟机堆转储快照分析工具，与jmap搭配使用，其提供web访问入口http://localhost:7000/

命令格式：jhat [ options ] <heap-dump-file>

1.6. jstack

Stack Trace for Java，堆栈跟踪工具，用于生成虚拟机当前线程快照，即当前虚拟机内每一条线程正在执行的方法堆栈集合，目的是为了定位线程出现长时间停顿的原因，比如死锁，死循环或者等待资源。

命令格式：jstack [option] vmid

-F ：当正常输出的请求不被响应时，强制输出线程堆栈
-l ：除堆栈外，显示关于锁的附加信息
-m ：如果调用到本地方法的话，可以显示C/C++的堆栈

JDK 1.5之后，Thread类新增方法getAllStackTraces()用于获取虚拟机中所有线程的StackTraceElement对象，通过这个方法可以完成jstack大部分的功能，因此可以做一个管理员页面，通过浏览器来实时查看线程堆栈。

1
2
3
4
5
6
7
8
9
Map<Thread, StackTraceElement[]> map = Thread.getAllStackTraces();
for(Entry<Thread, StackTraceElement[]> stackTrace : map.entrySet()){
    Thread thread = stackTrace.getKey();
    StackTraceElement[] stack = stackTrace.getValue();
    System.out.println("线程：" + thread.getName());
    for(StackTraceElement element : stack){
        System.out.println("\t" + element);
    }
}

1.7. HSDIS

java虚拟机规范中，详细描述了虚拟机指令集中每条的执行过程、执行前后对操作数栈、局部变量表的影响等细节。但是随着技术发展，高性能虚拟机真正的细节实现方式已经渐渐与虚拟机规范所描述的内容产生了越来越大的差距，虚拟机规范中的描述逐渐成了虚拟机实现的“概念模型”——即实现只能保证与规范描述等效。因此，我们分析程序的执行语义问题时(虚拟机做了什么)时，在字节码层面上分析完全可行，但分析程序的执行行为问题(虚拟机具体怎样做)时，在字节码层面上分析就没有意义了。

HSDIS是Sun推荐的HotSpot虚拟机JIT编译代码的反汇编插件，它包含在HotSpot虚拟机的源码之中，但是没有提供编译后的程序

例如对下面代码的class文件进行反汇编

1
2
3
4
5
6
7
8
9
10
11
12
13
14
package d1;

public class Test{  
    int a = 1;
    static int b = 2;
    
    public int sum(int c){
        return a + b;
    }
    
    public static void main(String[] args) {
        new Test().sum(5);
    }
}

环境为ubuntu, java-8-openjdk：

  1. sudo apt-get install libhsdis0-fcml
  2. export LD_LIBRARY_PATH=/usr/lib/jvm/java-8-openjdk-amd64/jre/lib/amd64/hsdis-amd64.so
  3. 将编译好Test.class文件按package目录放到当前目录./d1/Test.class
  4. 打印要执行字节码指令
java -XX:+UnlockDiagnosticVMOptions -XX:+PrintAssembly -XX:PrintAssemblyOptions=hsdis-print-bytes -XX:CompileCommand=print d1.Test
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
Loaded disassembler from hsdis-amd64.so
Decoding compiled method 0x00007fccc5108510:
Code:
Argument 0 is unknown.RIP: 0x7fccc5108680 Code size: 0x00000290
[Disassembling for mach='amd64']
[Entry Point]
[Constants]
  # {method} {0x00007fccd8996000} 'hashCode' '()I' in 'java/lang/String'
  #           [sp+0x40]  (sp of caller)
  0x00007fccc5108680: mov     0x8(%rsi),%r10d   ;...44
                                                ;...8b
                                                ;...56
                                                ;...08
  0x00007fccc5108684: shl     $0x3,%r10         ;...49
                                                ;...c1
                                                ;...e2
                                                ;...03
  0x00007fccc5108688: cmp     %rax,%r10         ;...4c
  
  ........

2. 可视化工具

VisualVM（多合一故障处理工具）可以用来监视远程JVM的详细状态，只需要在jvm启动时配置Jmx连接

1
2
3
4
5
6
7
-Dcom.sun.management.jmxremote
-Dcom.sun.management.jmxremote.port=8099
-Dcom.sun.management.jmxremote.ssl=false 
-Dcom.sun.management.jmxremote.authenticate=false

-Dcom.sun.management.jmxremote.rmi.port=8099 
-Djava.rmi.server.hostname=192.168.180.1


参考：

  1. Copyright ©《深入理解java虚拟机》
  2. https://stackoverflow.com/questions/41300520/what-is-locked-ownable-synchronizers-in-thread-dump