手把手教你用JDK自带工具进行JVM性能调优与故障诊断

JDK自带了许多命令行和图形界面工具，帮助我们查看和分析Java虚拟机（JVM）的运行状态，这对于性能调优和问题排查至关重要。这篇文章将介绍如何使用这些原生工具来定位和分析Java程序的问题。

为了演示工具的使用，我们先准备一段测试代码。这段代码会启动10个线程，每个线程都执行一个死循环：分配一个大约10MB的字符串，然后休眠10秒。这样的程序会对垃圾回收（GC）造成一定的压力。

//启动10个线程
IntStream.rangeClosed(1， 10).mapToObj(i -> new Thread(() -> {
    while (true) {
        //每一个线程都是一个死循环，休眠10秒，打印10M数据
        String payload = IntStream.rangeClosed(1， 10000000)
                .mapToObj(__ -> "a")
                .collect(Collectors.joining("")) + UUID.randomUUID().toString();
        try {
            TimeUnit.SECONDS.sleep(10);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        System.out.println(payload.length());
    }
})).forEach(Thread::start);

TimeUnit.HOURS.sleep(1);

接下来，我们需要将程序打包。修改 pom.xml，配置 spring-boot-maven-plugin 插件来指定启动类：

<plugin>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-maven-plugin</artifactId>
    <configuration>
        <mainClass>org.geekbang.time.commonmistakes.troubleshootingtools.jdktool.CommonMistakesApplication</mainClass>
    </configuration>
</plugin>

打包后，使用 java -jar 命令启动程序，并设置JVM堆内存参数为最小1GB，最大1GB：

java -jar common-mistakes-0.0.1-SNAPSHOT.jar -Xms1g -Xmx1g

准备工作就绪后，我们就可以使用Java提供的各种工具来观察这个测试程序了。

使用 jps 查看进程

首先，使用 jps 命令可以快速列出系统上所有的Java进程，这比使用 ps 命令更方便。

➜  ~ jps
12707
22261 Launcher
23864 common-mistakes-0.0.1-SNAPSHOT.jar
15608 RemoteMavenServer36
23243 Main
23868 Jps
22893 KotlinCompileDaemon

使用 jinfo 查看JVM参数

jinfo 工具可以打印指定Java进程的JVM配置参数和系统属性。通过它，我们可以验证JVM参数是否设置正确。

➜  ~ jinfo 23864
Java System Properties:
#Wed Jan 29 12:49:47 CST 2020
...
user.name=zhuye
path.separator=\:
os.version=10.15.2
java.runtime.name=Java(TM) SE Runtime Environment
file.encoding=UTF-8
java.vm.name=Java HotSpot(TM) 64-Bit Server VM
...

VM Flags:
-XX:CICompilerCount=4 -XX:ConcGCThreads=2 -XX:G1ConcRefinementThreads=8 -XX:G1HeapRegionSize=1048576 -XX:GCDrainStackTargetSize=64 -XX:InitialHeapSize=268435456 -XX:MarkStackSize=4194304 -XX:MaxHeapSize=4294967296 -XX:MaxNewSize=2576351232 -XX:MinHeapDeltaBytes=1048576 -XX:NonNMethodCodeHeapSize=5835340 -XX:NonProfiledCodeHeapSize=122911450 -XX:ProfiledCodeHeapSize=122911450 -XX:ReservedCodeCacheSize=251658240 -XX:+SegmentedCodeCache -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseG1GC

VM Arguments:
java_command: common-mistakes-0.0.1-SNAPSHOT.jar -Xms1g -Xmx1g
java_class_path (initial): common-mistakes-0.0.1-SNAPSHOT.jar
Launcher Type: SUN_STANDARD

看第15行和19行的输出，我们发现一个问题：-Xms1g 和 -Xmx1g 这两个参数被当成了Java程序的启动参数，而不是JVM参数。所以实际上JVM的最大堆内存是4GB左右，而不是我们期望的1GB。

因此，当怀疑JVM配置异常时，应第一时间使用工具确认。正确的启动方式是将JVM参数放在 -jar 之前：

java -Xms1g -Xmx1g -jar common-mistakes-0.0.1-SNAPSHOT.jar test

我们也可以在代码中打印出JVM参数和程序参数来验证：

System.out.println("VM options");
System.out.println(ManagementFactory.getRuntimeMXBean().getInputArguments().stream().collect(Collectors.joining(System.lineSeparator())));
System.out.println("Program arguments");
System.out.println(Arrays.stream(args).collect(Collectors.joining(System.lineSeparator())));

重新以正确方式启动后，输出确认参数设置正确：

➜  target git:(master) ✗ java -Xms1g -Xmx1g -jar common-mistakes-0.0.1-SNAPSHOT.jar test
VM options
-Xms1g
-Xmx1g
Program arguments
test

使用 jvisualvm 图形化监控

jvisualvm 是一个功能强大的图形化监控工具。启动它并连接到我们的测试进程，可以在“概述”面板确认JVM参数已成功设置为1GB。

切换到“监视”面板，可以直观地看到JVM的运行状况：GC活动大约每10秒发生一次，堆内存在250MB到900MB之间波动，活动线程数为22。这个面板也提供了手动触发GC和生成堆转储（Heap Dump）的按钮。

使用 jconsole 查看曲线图

jconsole 是另一个图形化监控工具，它有一个特色功能：可以用曲线的形式展示各种监控数据，包括各个内存区的使用情况，这对于观察GC趋势非常直观。

使用 jstat 命令行监控GC

如果没有图形界面可用（例如在Linux服务器上），我们可以使用 jstat 命令来监控GC趋势。jstat 可以按固定频率输出JVM的各种指标。

以下命令使用 -gcutil 选项输出GC和内存占用汇总信息，每隔5秒输出一次，共输出100次。从输出可以看到，Young GC比较频繁，而Full GC基本每10秒一次，与我们的程序逻辑相符。

➜  ~ jstat -gcutil 23940 5000 100
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT    CGC    CGCT     GCT
  0.00 100.00   0.36  87.63  94.30  81.06    539   14.021    33    3.972   837    0.976   18.968
  0.00 100.00   0.60  69.51  94.30  81.06    540   14.029    33    3.972   839    0.978   18.979
  0.00   0.00   0.50  99.81  94.27  81.03    548   14.143    34    4.002   840    0.981   19.126
  0.00 100.00   0.59  70.47  94.27  81.03    549   14.177    34    4.002   844    0.985   19.164
  0.00 100.00   0.57  99.85  94.32  81.09    550   14.204    34    4.002   845    0.990   19.196
  0.00 100.00   0.65  77.69  94.32  81.09    559   14.469    36    4.198   847    0.993   19.659
  0.00 100.00   0.65  77.69  94.32  81.09    559   14.469    36    4.198   847    0.993   19.659
  0.00 100.00   0.70  35.54  94.32  81.09    567   14.763    37    4.378   853    1.001   20.142
  0.00 100.00   0.70  41.22  94.32  81.09    567   14.763    37    4.378   853    1.001   20.142
  0.00 100.00   1.89  96.76  94.32  81.09    574   14.943    38    4.487   859    1.007   20.438
  0.00 100.00   1.39  39.20  94.32  81.09    575   14.946    38    4.487   861    1.010   20.442

其中，S0 表示 Survivor0 区占用百分比，S1 表示 Survivor1 区占用百分比，E 表示 Eden 区占用百分比，O 表示老年代占用百分比，M 表示元数据区占用百分比，YGC 表示年轻代回收次数，YGCT 表示年轻代回收耗时，FGC 表示老年代回收次数，FGCT 表示老年代回收耗时。

使用 jstack 分析线程

线程问题是线上故障的常见原因。在 jvisualvm 的线程面板，我们可以看到大量以“Thread-”开头的线程，它们的活动规律是每10秒运行一下，其余时间在休眠，这与我们代码中 TimeUnit.SECONDS.sleep(10) 的逻辑匹配。

点击“线程 Dump”按钮，可以获取即时的线程快照（Thread Dump），查看所有线程的调用栈信息。

我们也可以使用命令行工具 jstack 来抓取线程栈：

➜  ~ jstack 23940
2020-01-29 13:08:15
Full thread dump Java HotSpot(TM) 64-Bit Server VM (11.0.3+12-LTS mixed mode):

...

"main" #1 prio=5 os_prio=31 cpu=440.66ms elapsed=574.86s tid=0x00007ffdd9800000 nid=0x2803 waiting on condition  [0x0000700003849000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(java.base@11.0.3/Native Method)
    at java.lang.Thread.sleep(java.base@11.0.3/Thread.java:339)
    at java.util.concurrent.TimeUnit.sleep(java.base@11.0.3/TimeUnit.java:446)
    at org.geekbang.time.commonmistakes.troubleshootingtools.jdktool.CommonMistakesApplication.main(CommonMistakesApplication.java:41)
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.3/Native Method)
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.3/NativeMethodAccessorImpl.java:62)
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.3/DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(java.base@11.0.3/Method.java:566)
    at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:48)
    at org.springframework.boot.loader.Launcher.launch(Launcher.java:87)
    at org.springframework.boot.loader.Launcher.launch(Launcher.java:51)
    at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:52)

"Thread-1" #13 prio=5 os_prio=31 cpu=17851.77ms elapsed=574.41s tid=0x00007ffdda029000 nid=0x9803 waiting on condition  [0x000070000539d000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(java.base@11.0.3/Native Method)
    at java.lang.Thread.sleep(java.base@11.0.3/Thread.java:339)
    at java.util.concurrent.TimeUnit.sleep(java.base@11.0.3/TimeUnit.java:446)
    at org.geekbang.time.commonmistakes.troubleshootingtools.jdktool.CommonMistakesApplication.lambda$null$1(CommonMistakesApplication.java:33)
    at org.geekbang.time.commonmistakes.troubleshootingtools.jdktool.CommonMistakesApplication$$Lambda$41/0x00000008000a8c40.run(Unknown Source)
    at java.lang.Thread.run(java.base@11.0.3/Thread.java:834)

...

获取到的线程栈文件，可以使用在线的分析工具（如 fastthread.io）进行深入分析。

使用 jcmd 与 NMT 分析本地内存

最后，我们来看看Java HotSpot虚拟机的NMT（Native Memory Tracking，本地内存跟踪）功能。通过NMT，我们可以观察JVM自身（非堆内存）的细粒度内存使用情况。

开启NMT需要在启动时添加JVM参数 -XX:NativeMemoryTracking=summary/detail。为了演示，我们重新启动程序，并额外设置一个较小的线程栈大小：

-Xms1g -Xmx1g -XX:ThreadStackSize=256k -XX:NativeMemoryTracking=detail

启动后，使用 jcmd 命令查看NMT的概要信息：

➜  ~ jcmd 24404 VM.native_memory summary
24404:

Native Memory Tracking:

Total: reserved=6635310KB， committed=5337110KB
-                 Java Heap (reserved=1048576KB， committed=1048576KB)
                            (mmap: reserved=1048576KB， committed=1048576KB)

-                     Class (reserved=1066233KB， committed=15097KB)
                            (classes #902)
                            (malloc=9465KB #908)
                            (mmap: reserved=1056768KB， committed=5632KB)

-                    Thread (reserved=4209797KB， committed=4209797KB)
                            (thread #32)
                            (stack: reserved=4209664KB， committed=4209664KB)
                            (malloc=96KB #165)
                            (arena=37KB #59)

-                      Code (reserved=249823KB， committed=2759KB)
                            (malloc=223KB #730)
                            (mmap: reserved=249600KB， committed=2536KB)

-                        GC (reserved=48700KB， committed=48700KB)
                            (malloc=10384KB #135)
                            (mmap: reserved=38316KB， committed=38316KB)

-                  Compiler (reserved=186KB， committed=186KB)
                            (malloc=56KB #105)
                            (arena=131KB #7)

-                  Internal (reserved=9693KB， committed=9693KB)
                            (malloc=9661KB #2585)
                            (mmap: reserved=32KB， committed=32KB)

-                    Symbol (reserved=2021KB， committed=2021KB)
                            (malloc=1182KB #334)
                            (arena=839KB #1)

-    Native Memory Tracking (reserved=85KB， committed=85KB)
                            (malloc=5KB #53)
                            (tracking overhead=80KB)

-               Arena Chunk (reserved=196KB， committed=196KB)
                            (malloc=196KB)

输出显示有32个线程，但线程栈总共保留了约4GB内存。这很奇怪，我们明明通过 -XX:ThreadStackSize=256k 设置了线程栈最大为256KB。

使用 detail 模式查看更多细节：

jcmd 24404 VM.native_memory detail

在详细输出中搜索，我们发现有16个线程，每个线程竟然保留了262144KB（即256MB）的栈内存。

问题出在参数单位上：ThreadStackSize 参数的单位是KB，所以设置 256k 会被解释为256 * 1024 KB。正确的设置应该是 256。修正参数后，NMT输出显示线程栈内存恢复正常。

jcmd 是一个功能丰富的工具，除了查询NMT，还可以执行其他诊断命令，可以通过 jcmd <pid> help 查看所有可用命令。

总结

工欲善其事，必先利其器。熟练掌握 jps， jinfo， jvisualvm/jconsole， jstat， jstack， jcmd 这些JDK自带工具，是每一位Java开发者进行运维和性能调优的基本功。它们能帮助我们在不同场景下，快速获取JVM的运行状态、定位内存泄漏、分析线程死锁、验证参数配置，从而高效地解决线上问题。希望本文的实践演示能帮助你更好地理解和使用这些工具。