共计 8222 个字符，预计需要花费 21 分钟才能阅读完成。
这篇文章中介绍下如何应用 JDK 自带工具来剖析和定位 Java 程序的问题。
应用 JDK 自带工具查看 JVM 状况
JDK 自带了很多命令行甚至是图形界面工具，帮忙咱们查看 JVM 的一些信息。比方，在我的机器上运行 ls 命令，能够看到 JDK 8 提供了十分多的工具或程序：
接下来，我会与你介绍些罕用的监控工具。你也能够先通过上面这张图理解下各种工具的根本作用：
为了测试这些工具，咱们先来写一段代码：启动 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 插件打包的 Java 程序的 main 办法类：
| <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：
java -jar common-mistakes-0.0.1-SNAPSHOT.jar -Xms1g -Xmx1g
实现这些筹备工作后，咱们就能够应用 JDK 提供的工具，来察看剖析这个测试程序了。
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
而后，能够应用 jinfo 打印 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 行能够发现，咱们设置 JVM 参数的形式不对，-Xms1g 和 -Xmx1g 这两个参数被当成了 Java 程序的启动参数，整个 JVM 目前最大内存是 4GB 左右，而不是 1GB。最近整顿了一份最新的面试材料，外面收录了 2021 年各个大厂的面试题，打算跳槽的小伙伴不要错过，点击支付吧！
因而，当咱们狐疑 JVM 的配置很不失常的时候，要第一工夫应用工具来确认参数。除了应用工具确认 JVM 参数外，你也能够打印 VM 参数和程序参数：
| 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()))); |
把 JVM 参数放到 -jar 之前，重新启动程序，能够看到如下输入，从输入也能够确认这次 JVM 参数的配置正确了：
| ➜ 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 参数设置胜利了：
持续察看监督面板能够看到，JVM 的 GC 流动根本是 10 秒产生一次，堆内存在 250MB 到 900MB 之间稳定，流动线程数是 22。咱们能够在监督面板看到 JVM 的根本状况，也能够间接在这里进行手动 GC 和堆 Dump 操作：
jconsole 如果心愿看到各个内存区的 GC 曲线图，能够应用 jconsole 察看。jconsole 也是一个综合性图形界面监控工具，比 jvisualvm 更不便的一点是，能够用曲线的模式监控各种数据，包含 MBean 中的属性值：
jstat
同样，如果没有条件应用图形界面（毕竟在 Linux 服务器上，咱们次要应用命令行工具），又心愿看到 GC 趋势的话，咱们能够应用 jstat 工具。
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 示意老年代回收耗时。
jstat 命令的参数泛滥，蕴含 -class、-compiler、-gc 等。Java 8、Linux/Unix 平台 jstat 工具的残缺介绍，你能够查看这里。jstat 定时输入的个性，能够不便咱们继续察看程序的各项指标。
持续来到线程面板能够看到，大量以 Thread 结尾的线程根本都是有节奏的 10 秒运行一下，其余工夫都在休眠，和咱们的代码逻辑匹配：
点击面板的线程 Dump 按钮，能够查看线程刹时的线程栈：
jstack
通过命令行工具 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（https://fastthread.io/）这样的在线剖析工具来剖析线程栈。
jcmd
最初，咱们来看一下 Java HotSpot 虚拟机的 NMT 性能。
通过 NMT，咱们能够察看细粒度内存应用状况，设置 -XX:NativeMemoryTracking=summary/detail 能够开启 NMT 性能，开启后能够应用 jcmd 工具查看 NMT 数据。
咱们重新启动一次程序，这次加上 JVM 参数以 detail 形式开启 NMT：
-Xms1g -Xmx1g -XX:ThreadStackSize=256k -XX:NativeMemoryTracking=detail
在这里，咱们还减少了 -XX:ThreadStackSize 参数，并将其值设置为 256k，也就是冀望把线程栈设置为 256KB。咱们通过 NMT 察看一下设置是否胜利。
启动程序后执行如下 jcmd 命令，以概要模式输入 NMT 后果。能够看到，以后有 32 个线程，线程栈总共保留了差不多 4GB 左右的内存。咱们明明配置线程栈最大 256KB 啊，为什么会呈现 4GB 这么夸大的数字呢，到底哪里出了问题呢？
| ➜ ~ 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) |
从新以 VM.native_memory detail 参数运行 jcmd：
jcmd 24404 VM.native_memory detail
能够看到，有 16 个可疑线程，每一个线程保留了 262144KB 内存，也就是 256MB（通过下图红框能够看到，应用关键字 262144KB for Thread Stack from 搜寻到了 16 个后果）：
其实，ThreadStackSize 参数的单位是 KB，所以咱们如果要设置线程栈 256KB，那么应该设置 256 而不是 256k。从新设置正确的参数后，应用 jcmd 再次验证下：
除了用于查看 NMT 外，jcmd 还有许多性能。咱们能够通过 help，看到它的所有性能：
jcmd 24781 help
除了 jps、jinfo、jcmd、jstack、jstat、jconsole、jvisualvm 外，JDK 中还有一些工具，你能够通过官网文档查看残缺介绍。
官网文档：https://docs.oracle.com/javas…
