GC 玩起来（三）GC 日志分析

摘要
GC 日志是判断 Java 应用程序内存是否存在故障的重要判断依据。《GC 玩起来》这个小系列，期望能够使零基础的读者快速理解 GC 相关的重要概念，最终掌握 GC 日志的分析方法。
第三篇《GC 日志分析》旨在介绍生成 GC 日志的相关 JVM 参数，如何读懂 GC 日志，以及如何借助图形化工具分析 GC 日志。

1 GC 日志能帮我们做什么

GC 日志是由 JVM 产生的对垃圾回收活动进行描述的日志文件。

通过 GC 日志，我们能够直观的看到内存回收的情况及过程，是能够快速判断内存是否存在故障的重要依据。

2 如何生成 GC 日志

在 JAVA 命令中增加 GC 相关的参数，以生成 GC日志：

常用的选项组合：

java -Xms512m -Xmx2g -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:gc.log -jar xxx.jar

3 读懂 GC 日志

前文我们介绍了通过 -XX:+UseSerialGC 、 -XX:+UseParallelGC （同 -XX:+UseParallelOldGC ）、 -XX:+UseParNewGC 、 -XX:+UseConcMarkSweepGC 、 -XX:+UseG1GC 这些参数，来指定使用不同的垃圾回收器组合。不同的垃圾回收器所生成的 GC 日志也是有差异的，尤其是 CMS 、 G1 所生成的日志，会比 Serial 、Parallel 所生成的日志复杂许多。

这里我们以 JDK1.8 默认使用的 -XX:+UseParallelGC （即 Parallel Scavenge + Parallel Old ）为例，讲解其 GC 日志。

3.1 开头部分的环境信息

上图是 GC 日志的开头部分：

1. 第 1 部分是 Java 环境信息：

• Java HotSpot(TM) 64-Bit Server VM (25.144-b01) 是 JVM 版本信息；
• linux-amd64 JRE (1.8.0_144-b01) 是 JDK 版本信息；

2. 第 2 部分是服务器内存信息：

• physical 32611948k(7181112k free) 是服务器物理内存总大小与空闲大小；
• swap 67108860k(66625832k free) 是服务器 swap 交换区的总大小与空闲大小；

3. 第 3 部分打印出与 GC 相关的 JVM 启动参数，其中：

• -XX:InitialHeapSize=1073741824 -XX:MaxHeapSize=2147483648 指定了堆大小的初始化值与最大值；
• -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps 为 GC 日志的相关设置；
• -XX:+UseCompressedClassPointers -XX:+UseCompressedOops 开启了普通对象和类的指针压缩，能够提高内存性能
• -XX:+UseParallelGC 则体现出 JDK1.8 默认使用的垃圾回收器。

3.2 Young GC

上图描述的是 Young GC 活动：

1. 第 1 部分是日志时间：

• 2022-06-01T11:10:59.126+0800: 是日期格式的时间；
• 86.281: 是基准格式的时间，也就是应用启动后的 N 秒；

2. 第 2 部分是 GC 的类型与发生 GC 的原因：

• GC 表示当前 GC 类型为 Young GC ；
• Allocation Failure 是发生 GC 的原因，这里是年轻代中没有足够的空间来存储新数据了；

3. 第 3 部分是 GC 活动的详情：

• [PSYoungGen: 639473K->35837K(649728K)] ，从左到右分别是新生代垃圾回收前的大小、新生代垃圾回收后的大小、新生代总大小；
• 686696K->87816K(1671680K) ，中括号外的这三个数字，从左到右分别是堆垃圾回收前的大小、堆垃圾回收后的大小、堆总大小；
• 0.0192314 secs 是本次新生代垃圾回收的耗时；

4. 第 4 部分是 GC 耗时的详情：

• user=0.10 是用户耗时（即应用耗时）；
• sys=0.00 是系统内核耗时；
• real=0.01 是实际耗时，由于多核的原因，实际耗时可能会小于用户耗时 + 系统耗时。

3.3 Full GC

上图描述的是 Full GC 活动：

1. 第 1 部分是日志时间，与 Minor GC 日志相同，不再赘述；
2. 第 2 部分是 GC 的类型与发生 GC 的原因：

• Full GC 表示当前 GC 类型为 Full GC ；
• Metadata GC Threshold 是发生 GC 的原因，这里是元空间的占用大小达到了 GC 阈值；

3. 第 3 部分是 GC 活动的详情：

• [PSYoungGen: 33776K->0K(647680K)] ，从左到右分别是新生代垃圾回收前的大小、新生代垃圾回收后的大小、新生代总大小；
• [ParOldGen: 51986K->59081K(1324544K)] ，从左到右分别是老年代垃圾回收前的大小、老年代垃圾回收后的大小、老年代总大小；
• 85762K->59081K(1972224K) ，中括号外的这三个数字，从左到右分别是堆垃圾回收前的大小、堆垃圾回收后的大小、堆总大小；
• [Metaspace: 92860K->92312K(1134592K)] ，从左到右分别是元空间垃圾回收前的大小、元空间垃圾回收后的大小、元空间总大小；
• 0.1185325 secs 是本次新生代垃圾回收的耗时；

4. 第 4 部分是 GC 耗时的详情，与 Minor GC 日志相同，不再赘述。

以上便是 JDK1.8 下 -XX:+UseParallelGC （即 Parallel Scavenge + Parallel Old ）模式下， GC 日志的详细解读。不同的模式下的日志，对于新生代、老年代的别称也是不同的，我们将上一篇文章中的一张特征信息总结表格拿过来，再次加深一下印象：

4 GC 日志的图形化分析工具

接下来我们需要配合一些图形化的工具来分析 GC 日志。

4.1 GCeasy

GCeasy 是笔者最为推荐的 GC 日志分析工具，它是一个在线工具，号称业界第一个以机器学习算法为基础的 GC 日志分析工具。它不仅能够生成多元化的分析图例（这是免费的），还能够推荐 JVM 配置、提出存在的内存问题并推荐对应的解决方案（后面这些功能是付费的）。

我们来看一下免费的功能：

• 内存统计，包含新生代、老年代、持久代的最大分配值与峰值：

• 关键性能指标统计，包含吞吐量、应用暂停时间（含平均暂停时间、最大暂停时间、按暂停时间范围统计 GC 次数）：

• 多元化的图例，包含 GC 前后的堆的大小、 GC 分布、回收空间情况、新生代/老年代/持久代的内存情况、新生代向持久代转化情况：

• GC 详细数据统计：

4.2 GCViewer

GCViewer 是一个离线的 GC 可视化分析工具，在同类离线工具中，可以说是功能最为强大的了。下载地址：github.com/chewiebug/G…

• GCViewer 提供了一个交互式的图例区，可以根据个人需要来展示所选择的指标：

• GCViewer 对于数据的统计也是相当之完善的：

4.3 GChisto

GChisto 也是一个离线工具，功能相较于 GCViewer 显得比较简单，下载地址：github.com/jewes/gchis…

• GC 数据统计，包含各类 GC 的次数、耗时、开销占比等：

• 提供 GC 不同时间范围内次数统计、耗时统计等图例：

4.4 GCLogViewer

GCLogViewer 也是一个离线工具，官方地址国内无法打开（code.google.com/p/gclogview…），想要下载的话可以到 CSDN 上找一找。

其功能与 GChisto 比较相似，效果图如下：