如何生成 java heap dump

Java heap 是某个时间点上 JVM 内存的一个瞬时镜像(snapshot), 通过工具查看内存里面的各种对象以及他们之间的关系, 对于分析内存问题非常有帮助. 常见的 heap dump 都是二进制的 hprof 格式, 获得之后一般通过 jhat, JVisualVM 或者 MAT 分析. 那么第一步, 如何获得 heap dump 呢? 本文将介绍常见的获得 heap dump 的一些方法.

  1. jcmd
    jcmd 是 jdk 自带的一个小工具, 推荐使用. 要通过 jcmd 获得 heap dump, 首先要得到该进程的 ID. 获得进程 ID 之后, 可以通过 jcmd 命令获得 heap dump.
    LM-SHC-16501315:Downloads xiatian$ jcmd
    42596 
    98797 sun.tools.jcmd.JCmd
    LM-SHC-16501315:Downloads xiatian$ jcmd 42596 GC.heap_dump /tmp/heap.hprof
    42596:
    Heap dump file created
  1. jmap
    jmap 是 JDK 从早期开始一直附带的一个小工具, 使用下面的命令来获取 heap dump:
    jmap -dump:[live],format=b,file=<file-path>
    其中的 live 是可选, 代表是否包含即将被 GC 的对象, 若包含 live, 则不包含即将被 GC 的对象.
    在我的使用经验中, 有时候 jmap 会出现不能 attach 到目标进程的问题.
    例子:
LM-SHC-16501315:Downloads xiatian$ jmap -dump:live,format=b,file=/tmp/heapdump.hprof 42596
Dumping heap to /private/tmp/heapdump.hprof ...
Heap dump file created
  1. JVisualVM
    若在桌面环境, 并且已经安装 JDK, 可以使用 JDK 自带 GUI 工具 JVisualVM.
    heap.png

  2. JConsole
    JConsole 也是 JDK 自带 GUI 工具
    jconsole.png

  3. 可以在 JVM 启动时添加如下参数, 当发生 OOM 时候, 自动产生 heap dump:

-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=<file-or-dir-path>
  1. 编程的方式: 可以通过使用 MBean 去操作, 产生 heap dump.
public static void dumpHeap(String filePath, boolean live) throws IOException {
    MBeanServer server = ManagementFactory.getPlatformMBeanServer();
    HotSpotDiagnosticMXBean mxBean = ManagementFactory.newPlatformMXBeanProxy(
      server, "com.sun.management:type=HotSpotDiagnostic", HotSpotDiagnosticMXBean.class);
    mxBean.dumpHeap(filePath, live);
}

有时候, 你会看到 core dump 和 heap dump, 2个不一样的dump, 那么2个区别是什么呢?
Java 常见的三种 dump 文件: Core Dump, heap dump, thread dump

jstack

jstack 用来打印当前 Java 进程的所有 stacktrace 信息, 包括每层栈的类名, 方法名, 行号, 以及线程的状态, 当前线程拥有的锁, 还能打印部分 native stracktrace.

jstack [ option ] pid
jstack [ option ] executable core
jstack [ option ] [server-id@]remote-hostname-or-IP

最常使用的还是跟 pid 去打印当钱进程的栈. 比如:

jstack -l 42596
jstack -l 42596 > /tmp/stack.txt
jstack -m 42596 // 打印包括 native 栈在内的所有栈. 
jstack -F 42956 //Solaris & Linux 上 force 打印栈

这个功能可以通过最新的 jcmd 来实现.

jcmd  42596 Thread.print

jinfo

jinfo 是 JDK 提供的一个查看 JVM 系统配置信息和启动参数的命令, 并且它可以在 JVM 运行状态下修改某些参数. 在 JDK 8 之后, jinfo 的很多功能都可以被新的工具 jcmd 所拥有, 更推荐使用 jcmd.

获取 java 线程 42596 的相关信息:

host:Downloads xiatian$ jinfo 42596
Attaching to process ID 42596, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.141-b15
Java System Properties:

java.vendor = Oracle Corporation
java.vm.info = mixed mode
line.separator = 

java.vm.name = Java HotSpot(TM) 64-Bit Server VM
org.apache.commons.logging.Log = org.apache.commons.logging.impl.NoOpLog
-XX:+UseG1GC
-XX:+UseStringDeduplication
-XstartOnFirstThread
-Dorg.eclipse.swt.internal.carbon.smallFonts
-Dosgi.requiredJavaVersion=1.8
-Xms256m
-Xmx1024m
-Declipse.p2.max.threads=10
java.specification.version = 1.8

VM Flags:
Non-default VM flags: -XX:CICompilerCount=4 -XX:ConcGCThreads=2 -XX:G1HeapRegionSize=1048576 -XX:InitialHeapSize=268435456 -XX:MarkStackSize=4194304 -XX:MaxHeapSize=1073741824 -XX:MaxNewSize=643825664 -XX:MinHeapDeltaBytes=1048576 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseG1GC -XX:+UseStringDeduplication 
Command line:  -Dosgi.requiredJavaVersion=1.8 -Dosgi.instance.area.default=@user.home/eclipse-workspace -XX:+UseG1GC -XX:+UseStringDeduplication -XstartOnFirstThread -Dorg.eclipse.swt.internal.carbon.smallFonts -Dosgi.requiredJavaVersion=1.8 -Xms256m -Xmx1024m -Xdock:icon=../Resources/Eclipse.icns -XstartOnFirstThread -Dorg.eclipse.swt.internal.carbon.smallFonts -Declipse.p2.max.threads=10 

jinfo 还可以设置某些 JVM 参数, 比如:

jinfo -flag +PrintGCDetails  42596

那些参数变量是可以运行时通过 jinfo 更改的呢? 可以通过下面的命令获取当前 JRE 支持的运行时可更改的 flags:

java -XX:+PrintFlagsFinal -version|grep manageable

manageable.png
或者查看官方页面(https://www.oracle.com/technetwork/java/javase/tech/vmoptions-jsp-140102.html), 凡是标明 Manageable 的, 都是可以运行时可更改的.

一个例子是: 如果你发现有 JVM 可能有 OOM 的风险, 那么你可以通过 jinfo 立即设置: HeapDumpOnOutOfMemoryError & HeapDumpPath, 那么当它 OOM 时, 它自动做一个 heap dump.

与 verbose GC log 相关的 JVM flags

默认情况下, JVM 是不会输出 verbose GC log 的, 只有设置相关 flag 之后才会写到文件. 并且根据各种 flag 参数的设置不同, 输出的详细程度也不一样. 下面这些都是与 verbose GC log 相关的参数.

  1. -Xloggc:verboseGC.log
    设置 GC log 文件名, 这个必须设置, 才能看到日志文件.
  2. -XX:+PrintGC 打印 GC 日志
  3. -XX:+PrintGCDetails 输出更详细的 GC 日志, 包括每次年轻代, 总 heap size 大小 GC 前后变化, 以及消耗 CPU 的时间.

与log 文件 rotate 和文件大小, 个数相关的三个参数:

  1. -XX:+UseGCLogFileRotation log 循环写, 而不是一直写到一个文件

  2. -XX:NumberOfGCLogFiles=5 可循环写的文件个个数, 这里设置共5个

  3. -XX:GCLogFileSize=2000k 每个可循环文件的大小, 这里设置是2M. 当前正在写的文件名有一个 current, 用来区别不是正在写的. 比如可能的文件如下:

    verboseGC.log.0
    verboseGC.log.1
    verboseGC.log.2.current
    verboseGC.log.3
    verboseGC.log.4

log 文件中显示与时间相关的参数:
-XX:+PrintGCTimeStamps
-XX:+PrintGCDateStamps

一个典型的 verbose GC log 如下:

Java HotSpot(TM) 64-Bit Server VM (25.141-b15) for bsd-amd64 JRE (1.8.0_141-b15), built on Jul 12 2017 04:35:23 by "java_re" with gcc 4.2.1 (Based on Apple Inc. build 5658) (LLVM build 2336.11.00)
Memory: 4k page, physical 16777216k(317124k free)

/proc/meminfo:

CommandLine flags: -XX:GCLogFileSize=204800 -XX:InitialHeapSize=20971520 -XX:MaxHeapSize=20971520 -XX:NumberOfGCLogFiles=5 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseGCLogFileRotation -XX:+UseParallelGC 
2019-07-05T20:39:58.844+0700: 0.374: [GC (Allocation Failure) [PSYoungGen: 5632K->496K(6144K)] 5632K->2232K(19968K), 0.0028539 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2019-07-05T20:39:58.935+0700: 0.466: [GC (Allocation Failure) [PSYoungGen: 6128K->480K(6144K)] 7864K->3361K(19968K), 0.0017132 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2019-07-05T20:39:59.028+0700: 0.559: [GC (Allocation Failure) [PSYoungGen: 6112K->480K(6144K)] 8993K->4240K(19968K), 0.0014840 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]  

首先, 在每个文件的头部, 都会有当前 JVM 的一些信息, 以及一些 JVM 启动参数, 之后就是详细的 GC 日志.