jvm 性能调优监控工具 -- jpsjstackjmapjhatjstathprof

Posted 2021-04-05 小脑斧科技博客

1. 概述

上一篇文章中，我们介绍了哪些场景会引起 java 的内存泄露。
然而，很多情况下，内存泄露、内存不足、CPU占用过高等问题都很容易被重启服务器、增加内存等处理方式隐藏，大多 java 程序员也并不会去深究问题的根源。
本文，我们就来学习 java 提供的性能监控、调优工具，来定位、解决这些容易被隐藏的问题。

2. jps

jps (Java Virtual Machine Process Status Tool) 是用来输出 jvm 运行状态信息的工具。

2.1. 语法格式

• jps [options] [hostid]
  如果不指定 hostid 就默认是当前主机。

2.2. 命令行可选参数

• -q — 不输出类名、Jar名和传入main方法的参数

• -m — 输出传入main方法的参数

• -l — 输出main类或Jar的全限名

• -v — 输出传入JVM的参数

2.3. 实例

[e-mail] ~ $ jps -ml46082 com.intellij.database.remote.RemoteJdbcServer com.mysql.jdbc.Driver17125 org.jetbrains.jps.cmdline.Launcher /Applications/IntelliJ IDEA.app/Contents/lib/javac2.jar:/Applications/IntelliJ IDEA.app/Contents/lib/oromatcher.jar:/Applications/IntelliJ IDEA.app/Contents/lib/jgoodies-forms.jar:/Applications/IntelliJ IDEA.app/Contents/lib/asm-all.jar:/Applications/IntelliJ IDEA.app/Contents/lib/commons-codec-1.9.jar:/Applications/IntelliJ IDEA.app/Contents/lib/protobuf-2.5.0.jar:/Applications/IntelliJ IDEA.app/Contents/lib/httpcore-4.4.5.jar:/Applications/IntelliJ IDEA.app/Contents/lib/jna-platform.jar:/Applications/IntelliJ IDEA.app/Contents/lib/netty-all-4.1.10.Final.jar:/Applications/IntelliJ IDEA.app/Contents/lib/jps-model.jar:/Applications/IntelliJ IDEA.app/Contents/lib/util.jar:/Applications/IntelliJ IDEA.app/Contents/lib/slf4j-api-1.7.10.jar:/Applications/IntelliJ IDEA.app/Contents/lib/aether-1.1.0-all.jar:/Applications/IntelliJ IDEA.app/Contents/lib/snappy-in-java-0.5.1.jar:/Applications/IntelliJ IDEA.app/Contents/lib/jna.jar:/Applications/IntelliJ IDEA.app/Contents/lib/openapi.ja49302 sun.tools.jps.Jps -ml17128 org.jetbrains.jps.cmdline.Launcher /Applications/IntelliJ IDEA.app/Contents/lib/javac2.jar:/Applications/IntelliJ IDEA.app/Contents/lib/oromatcher.jar:/Applications/IntelliJ IDEA.app/Contents/lib/jgoodies-forms.jar:/Applications/IntelliJ IDEA.app/Contents/lib/asm-all.jar:/Applications/IntelliJ IDEA.app/Contents/lib/commons-codec-1.9.jar:/Applications/IntelliJ IDEA.app/Contents/lib/protobuf-2.5.0.jar:/Applications/IntelliJ IDEA.app/Contents/lib/httpcore-4.4.5.jar:/Applications/IntelliJ IDEA.app/Contents/lib/jna-platform.jar:/Applications/IntelliJ IDEA.app/Contents/lib/netty-all-4.1.10.Final.jar:/Applications/IntelliJ IDEA.app/Contents/lib/jps-model.jar:/Applications/IntelliJ IDEA.app/Contents/lib/util.jar:/Applications/IntelliJ IDEA.app/Contents/lib/slf4j-api-1.7.10.jar:/Applications/IntelliJ IDEA.app/Contents/lib/aether-1.1.0-all.jar:/Applications/IntelliJ IDEA.app/Contents/lib/snappy-in-java-0.5.1.jar:/Applications/IntelliJ IDEA.app/Contents/lib/jna.jar:/Applications/IntelliJ IDEA.app/Contents/lib/openapi.ja17146 org.jetbrains.idea.maven.server.RemoteMavenServer17102

3. jstack

jstack 主要用来查看某个Java进程内的线程堆栈信息。语法格式如下：

3.1. 语法格式

• jstack [option] <pid> (to connect to process)

• jstack [option] <executable> <core> (to connect to a core file)

• jstack [option] [server_id@]<remote server IP or hostname> (to connect to a remote debug server)

3.2. 命令行参数

jstack 命令有以下可选参数:

• -F — 强制 dump 线程，通常用于无响应的线程信息的输出

• -m — mixed mode，不仅会输出Java堆栈信息，还会输出C/C++堆栈信息（比如Native方法）

• -l — long listings，会打印出额外的锁信息，在发生死锁时可以用jstack -l pid来观察锁持有情况

• -h or -help — 打印帮助信息

3.3. 使用 — 找到 java 进程中最耗 CPU 的代码

jstack 是用来打印 java 进程内的线程堆栈信息的，通过堆栈信息我们可以定位到具体的代码，在 jvm 调优过程中使用非常多。
下面我们就来介绍一下如何找到某个 java 进程中最耗 CPU 的 java 线程。

• 找出进程 ID — ps
  首先我们通过 ps 命令找到运行在 jetty 容器中的 java 进程 pid。

  [techlog@dx-cn-techlog-techlog01 ~]$ ps aux | grep jetty
  techlog  19198  0.0  0.0 103248   860 pts/1    S+   17:43   0:00 grep jetty
  ubuntu  30948 11.7 66.4 10770196 5353460 ?    Ssl  12:18  38:06 /usr/local/java8/bin/java -server -Dfile.encoding=UTF-8 -Dsun.jnu.encoding=UTF-8 -Djava.io.tmpdir=/tmp -Djava.net.preferIPv6Addresses=false -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=80 -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -XX:+PrintTenuringDistribution -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=512M -XX:NewRatio=2 -XX:SurvivorRatio=8 -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M -XX:+HeapDumpOnOutOfMemoryError -XX:ReservedCodeCacheSize=128m -XX:InitialCodeCacheSize=128m -Xmx4g -Xms4g -Dspring.profiles.active=prod -Xloggc:/opt/logs/com.ubuntu.cn.techlog.techlog/techlog.gc.log -XX:ErrorFile=/opt/logs/com.ubuntu.cn.techlog.techlog/techlog.hs_err_%p.log -XX:HeapDumpPath=/opt/logs/com.ubuntu.cn.techlog.techlog/techlog.heap_err_%p.hprof -Djetty.appkey=techlog -Djetty.context=/ -Djetty.logs=/opt/logs/com.ubuntu.cn.techlog.techlog -Djetty.webroot=/opt/techlog/com.ubuntu.cn.techlog.techlog/webroot com.ubuntu.mms.boot.Bootstrap

• 找到占用 CPU 时间最长的线程 — top -Hp pid
  接下来，我们通过 top 命令找到进程中占用 CPU 时间最长的线程 ID。

  [techlog@dx-cn-techlog-techlog01 ~]$ top -Hp 30948top - 17:47:35 up 379 days,  2:48,  2 users,  load average: 0.18, 0.16, 0.19Tasks: 514 total,   1 running, 513 sleeping,   0 stopped,   0 zombie
  Cpu(s):  2.2%us,  1.1%sy,  0.0%ni, 96.5%id,  0.0%wa,  0.0%hi,  0.2%si,  0.0%st
  Mem:   8059416k total,  7848316k used,   211100k free,   142804k buffers
  Swap:  2096440k total,        0k used,  2096440k free,  1757056k cached
  
  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND31078 ubuntu   20   0 10.3g 5.1g  22m R  0.9 66.5   1:26.83 java31070 ubuntu   20   0 10.3g 5.1g  22m S  1.7 66.5   1:12.22 java31066 ubuntu   20   0 10.3g 5.1g  22m S  0.0 66.5   1:11.88 java30993 ubuntu   20   0 10.3g 5.1g  22m S  0.0 66.5   0:55.86 java30992 ubuntu   20   0 10.3g 5.1g  22m S  0.0 66.5   0:48.36 java31143 ubuntu   20   0 10.3g 5.1g  22m S  0.0 66.5   0:27.24 java31144 ubuntu   20   0 10.3g 5.1g  22m S  0.0 66.5   0:26.08 java

我们找到了线程 ID — 31078。

• 输出线程堆栈信息 — jstack
  首先通过 printf "%x " 31078 命令计算线程 ID 的 16 进制值为 7966，接下来，我们只需要调用 jstack，grep 7966 即可找到 CPU 消耗在什么代码上了。

  [techlog@dx-cn-techlog-techlog01 ~]$ jstack 30948 | grep 7966"MnsCacheManager-Schedule-1-thread-1" #68 daemon prio=5 os_prio=0 tid=0x00007fd225e0f800 nid=0x7966 waiting on condition [0x00007fd108830000]

我们看到这个线程处于 waiting on condition 的状态，表明他在等待某个事件触发。
通过 cat 命令结合 sed 命令，我们最终可以获取到在这一行接下来的几行数据：

"MnsCacheManager-Schedule-1-thread-1" #68 daemon prio=5 os_prio=0 tid=0x00007fd225e0f800 nid=0x7966 waiting on condition [0x00007fd108830000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x000000073b44d090> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

可以看到，线程处于 TIMED_WAITING 状态，表明该线程池中的线程正处于休眠，等待唤醒，且设置了超时。

3.4. 死锁问题的定位

死锁是代码中非常常见又很容易被忽视的问题，下面是一个 jstack 的输出，他明确显示出了死锁的存在以及具体的代码位置。

"t2" prio=5 tid=0x00007fd9d30ac000 nid=0x5903 waiting for monitor entry [0x000000011da46000]
  java.lang.Thread.State: BLOCKED (on object monitor)
  at DeadLock$2.run(DeadLock.java:38)
  - waiting to lock <0x00000007aaba7e58> (a java.lang.Object)
  - locked <0x00000007aaba7e68> (a java.lang.Object)

  Locked ownable synchronizers:
  - None"t1" prio=5 tid=0x00007fd9d30ab800 nid=0x5703 waiting for monitor entry [0x000000011d943000]
  java.lang.Thread.State: BLOCKED (on object monitor)
  at DeadLock$1.run(DeadLock.java:23)
  - waiting to lock <0x00000007aaba7e68> (a java.lang.Object)
  - locked <0x00000007aaba7e58> (a java.lang.Object)

  Locked ownable synchronizers:
  - None

可以看到，线程 t1 在等待锁，线程 t2 也在等待锁，双方又各自占用着对方等待的锁，从而可以轻易判断出死锁的存在。

4. jmap

jmap (JVM Memory Map) 命令用于生成heap dump文件。
通过可选参数还可以查询finalize执行队列、Java堆和永久代的详细信息，如当前使用率、当前使用的是哪种收集器等。

4.1. jmap 语法格式

• jmap [option] <pid>

• jmap [option] <executable <core> (to connect to a core file)

• jmap [option] [server_id@]<remote server IP or hostname> (to connect to remote debug server)

4.2. 可选参数

• 默认情况 — 打印堆内存 dump 文件内容

• -heap — 显示 java 堆详细内容，包括使用的GC算法、堆配置参数和各代中堆内存使用情况

• -histo — 显示堆中对象的详细信息

• -histo:live — 显示堆中存活对象的详细信息

• -permstat — 显示 java 堆内存中永久代类加载器统计信息

• -finalizerinfo — 显示在 F-Queue 队列中等待执行 finalizer 方法的对象

• -dump — 生成堆内存的转出快照

• -F — -dump 没有响应时，强制生成快照

4.3. 说明

需要注意的是，如果启动时所使用的 java 版本与 jmap 的版本是不同的，就会报错。
这种情况通常发生在机器上安装了多个版本的 jdk 包，需要仔细找一下需要使用的版本。

[ubuntu@dx-cn-techlog-techlog-staging01 ~]$ jmap -heap 22845Attaching to process ID 22845, please wait...
Exception in thread "main" java.lang.reflect.InvocationTargetException
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at sun.tools.jmap.JMap.runTool(JMap.java:197)
    at sun.tools.jmap.JMap.main(JMap.java:128)
Caused by: sun.jvm.hotspot.runtime.VMVersionMismatchException: Supported versions are 24.76-b04. Target VM is 25.45-b02
    at sun.jvm.hotspot.runtime.VM.checkVMVersion(VM.java:234)
    at sun.jvm.hotspot.runtime.VM.<init>(VM.java:297)
    at sun.jvm.hotspot.runtime.VM.initialize(VM.java:368)
    at sun.jvm.hotspot.bugspot.BugSpotAgent.setupVM(BugSpotAgent.java:598)
    at sun.jvm.hotspot.bugspot.BugSpotAgent.go(BugSpotAgent.java:493)
    at sun.jvm.hotspot.bugspot.BugSpotAgent.attach(BugSpotAgent.java:331)
    at sun.jvm.hotspot.tools.Tool.start(Tool.java:163)
    at sun.jvm.hotspot.tools.HeapSummary.main(HeapSummary.java:40)
    ... 6 more

5. jhat

如果你觉得 jmap 打印出的结果不直观，别担心，java 还提供了简单易用的浏览器界面分析工具 jhat。
JVM Heap Analysis Tool命令是与jmap搭配使用，用来分析jmap生成的dump，jhat内置了一个微型的HTTP/html服务器，生成dump的分析结果后，可以在浏览器中查看。

5.1. 使用方式

• 首先通过 jmap 输出堆内存的 dump 文件

  jmap -dump:format=b,file=dumpFileName pid

• 然后，通过 jhat 命令指定端口，即可在浏览器中查看了

  jhat -port port dumpFileName

5.2. 打印字段含义

• S0C、S1C、S0U、S1U — Survivor 0/1区容量（Capacity）和使用量（Used）

• EC、EU — Eden区容量和使用量

• OC、OU — 年老代容量和使用量

• PC、PU — 永久代容量和使用量

• YGC、YGT — 年轻代GC次数和GC耗时

• FGC、FGCT — Full GC次数和Full GC耗时

• GCT — GC总耗时

6. 参考资料

钰火 — http://www.cnblogs.com/myna/
JVM性能调优监控工具jps、jstack、jmap、jhat、jstat、hprof使用详解 — https://blog.csdn.net/dragonassassin/article/details/51010947。