Java GC 调试手记

编者注：本文为历史博文归档；涉及 JDK、框架与工具链版本请以当前官方文档为准。引用外链图片可能失效，阅读时请注意时效性。

摘要

本文记录了一次 GC 调试的实验过程与结果分析。

GC 知识要点回顾

问题 1：为什么要调试 GC 参数？

在 32 核处理器的系统上，10% 的 GC 时间导致 75% 的吞吐量损失。所以在大型系统上，调试 GC 是以小博大的不错选择。"Small improvements in reducing such a bottleneck can produce large gains in performance."

问题 2：怎么样调试 GC？

调试 GC，主要有 三个主要的参数：

• 选择合适的 GC Collector
• 整个 JVM Heap 堆的大小
• Young Generation 的大小（-Xmn 或 -XX:NewRatio=?）

问题 3：有哪些不同的 GC Collector？

Tony Printezis (JVM 大牛) 在 Garbage Collection in the Java HotSpot Virtual Machine 中有图为证，还有一篇更早的 Sun 开发人员介绍 GC 调试 也是有图为证。

Neo4j 总结如下：

简而言之，Young 和 Tenured 代各有三种 Collector，分别是：

• Serial：单线程。
• Parallel：多线程并行，GC 线程和 App 线程取一运行，即 GC 要 Stop the (app) World。
• Concurrent：多线程并发，GC 线程和 App 线程可同时运行。（注：Young generation 没有 CMS，取而代之的是可和 CMS (Old) 一起运行的 ParNew）

问题 4：如何选择 Collector？

Serial 可以直接排除掉，现在最普通的服务器也有双核 64 位/8G 内存，默认的 Collector 是 PS Scavenge 和 PS MarkSweep。所以 Collector 主要在并行 (Parallel) 和并发 (Concurrent) 两者之间选择。

问题 5：选择的标准 (参数指标) 是什么？如何得到这些参数值 (How to measure it)？

指标主要是 Throughput（吞吐量） 和 Latency（延迟）。garbage-collection-in-java-part-3 从 GC 的耗时给出了吞吐量和响应速度的公式：

Total Execution Time = Useful Time + Paused Time
throughput = Useful Time / Total Execution Time
latency = average paused time

如何得到 Useful time 和 Paused Time？即如何得到 JVM 的 GC 时间，有以下几种方式：

1. GC Log

打印 GC log，在 Java 启动参数中加入下面的语句（本文为 Tomcat 应用）。GC Log 记录每次 GC 时间，可根据 GC Log 计算平均 GC 时间和累积 GC 时间。

CATALINA_OPTS="$CATALINA_OPTS -verbose:gc -Xloggc:/usr/local/tomcat/gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps"

2. Jconsole

JDK 自带工具。在 Java 启动参数中加入下面的语句（本文为 Tomcat 应用），然后在监控端可以远程连接 1090 端口。在内存一项，有累积 GC 时间和次数。注意在以 min 为单位显示时，只显示整数部分，如 1min20s 显示为 1min。

CATALINA_OPTS="$CATALINA_OPTS -Dcom.sun.management.jmxremote.port=1090 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false"

3. VisualGC

JVM 监控工具，未同 JDK 一起发布，可在 JVisualvm (JDK 自带) 中以插件的方式使用，本文为独立使用。有累积 GC 时间和次数，并有曲线图直观显示。

首先在 Server 端启动 jstatd：

vi jstatd.all.policy

grant codebase "file:${java.home}/../lib/tools.jar" {
    permission java.security.AllPermission;
};

jstatd -J-Djava.security.policy=jstatd.all.policy

然后在监控端启动 VisualGC，远程连接服务端进程 id：

visualgc 102592@remote.domain

问题 6：应用请求的吞吐量和响应是否可以反映 JVM 的性能？

这正是我们调优的目标。本文使用 Jmeter 来做压力测试，并给出吞吐量和响应 report。

测试

硬件环境

Test case

1. 使用 Jmeter 压力测试。
2. 共 6 个 client，每个 client 启动 30 个线程发送请求。
3. 每个请求从 16 种测试样例中随机挑选一个，发送到 server 端。
4. 测试持续 10min。

参数值

1. server 使用默认 GC (PS Scavenge 和 PS MarkSweep)。
2. server 使用 CMS (-XX:+UseConcMarkSweepGC -XX:+UseParNewGC)。
3. server 使用 CMS，设置 Young generation 的大小为 200m (-Xmn200m)。
4. server 使用 CMS，设置 Young generation 的大小为 600m (-Xmn600m)。

观察值

1. Jmeter 请求的 summary report。
2. server 端累积 GC 时间和次数。

测试结果

1) CMS 和 Parallel 比较

1.1) 吞吐量和响应

(PS Scavenge 和 PS MarkSweep)

(ParNew 和 CMS)

从 Jmeter 的 report 中可以看出，使用 CMS 后吞吐量 (对应总的请求数) 下降 18%，而最大响应时间 (包括最小响应时间) 有近 30% 的提升 (变小)。这验证了 Tony Printezis 在 Step-by-Step: Garbage Collection Tuning in the Java HotSpot™ Virtual Machine 中说的：使用 CMS 应用的吞吐量会相对下降，但有更好的最差响应时间。

• Expect longer young GC times

  • Due to slower allocations into the old gen

• Expect better worst-case latencies

  • CMS does its work mostly-concurrently
  • Shorter worst-case pauses

• Expect lower throughput

  • CMS does more work

在官方的 JVM 性能调优中给出的建议也是：如果你的应用对峰值处理有要求，而对一两秒的停顿可以接受，则使用 -XX:+UseParallelGC；如果应用对响应有更高的要求，停顿最好小于一秒，则使用 -XX:+UseConcMarkSweepGC。

1.2) GC 累积时间和次数

(PS Scavenge 和 PS MarkSweep)

(ParNew 和 CMS)

PS 累积 GC 时间 (visualgc) 为 1min25s，其中 Eden 189 次，共 52s；Old 13 次，共 33s。

CMS 累积 GC (visualgc) 为 2min2s，其中 Eden 2333 次，共 1min46s；Old 55 次，共 16s。(Jconsole 和 GC log 却显示没有 Full GC，从 understanding cms gc logs 和 jstat 显示的 full GC 次数与 CMS 周期的关系 中我推测 visualgc 与 jstat 显示一致，都是统计 Old 的回收次数；而 Full GC 则是 Young 和 Old 一起回收，在其他类型的 GC 里，Old 只有 Full GC 时才触发)。

可以看到 PS 的 GC 频率相对低，但每次 GC 时间长，每次 Full 在 3s 左右徘徊，Young 在 0.3s 左右；CMS 则是短频快，频繁快速回收，Young 在 0.03s (<0.1s) 左右，Old <0.5s。从 JMeter 上，使用 PS GC，Request Report 会有间歇性的停顿，即 server 没有任何响应；CMS 则相对较少，停顿不那么明显。

2) CMS 下不同 Xmn 的比较

由于 CMS Young 太多频繁，又测试了分别调整 Xmn 为 200m 和 600m 之后的结果。200m 是仿照 cassandra 中 100m * cpu # 来设置 Young gen 的大小；600m 则是与 PS 下的 Young gen 一致。

200m

600m

随着 Young gen 的增大 (40m -> 200m -> 600m)，Young 的回收次数减少，Old 的回收次数增加，总体 GC 累积时间下降，应用吞吐量上升，最差响应时间变慢 (即便和 PS 比较也更差，是我的测试有问题？)。

结论

App 停顿 3s 是不可接受的，因此倾向于使用 CMS；CMS 的 default young gen 相当小，于是设置 Xmn。对于更加 Prefer 响应的应用，下面配置是否是黄金标配：

JVM_OPTS="$JVM_OPTS -XX:+UseParNewGC"
JVM_OPTS="$JVM_OPTS -XX:+UseConcMarkSweepGC"
JVM_OPTS="$JVM_OPTS -XX:+CMSParallelRemarkEnabled"
JVM_OPTS="$JVM_OPTS -XX:SurvivorRatio=8"
JVM_OPTS="$JVM_OPTS -XX:MaxTenuringThreshold=1"
JVM_OPTS="$JVM_OPTS -XX:CMSInitiatingOccupancyFraction=75"
JVM_OPTS="$JVM_OPTS -XX:+UseCMSInitiatingOccupancyOnly"

说明：本文涉及的技术内容基于较早期的 JDK 版本（如 JDK 6/7/8）。请注意，CMS 收集器在 JDK 9 中被标记为废弃，并在 JDK 14 中正式移除。现代 JDK 版本推荐使用 G1、ZGC 或 Shenandoah 等垃圾收集器。文中提到的部分工具（如 VisualGC 插件）在新版 JDK 或 IDE 中可能需要额外配置或已不再适用，请以官方最新文档为准。