企业官网建设流程全解析

先扯个真实场景。上周二晚上十一点，线上一个订单服务的 P99 延迟突然从 80ms 涨到 3.4s，监控面板上 CPU 每隔几分钟就出现一次完整的"尖刺"，业务方第一反应是数据库慢查询，DBA 查了一圈说没有；网络组说交换机丢包率正常；最后运维把 JVM GC 日志拉出来，才发现每 4 分钟一次 Full GC，单次停顿 3 到 6 秒。这就是典型的 JVM 调优和线上排查场景：问题不在硬件、不在数据库，而在虚拟机内部的垃圾回收机制上。

这篇文章我想把 GC 日志这件事彻底讲透。不聊虚的，就从一段真实的 jvm 日志入手，逐字段拆解每行数字到底在说什么，然后带你走一遍线上排查的完整链路，最后给出一份能直接抄作业的调优参数模板。无论你是刚接触 JVM 优化的小白，还是已经被线上故障折磨过几轮的开发，这篇都值得存下来反复对照。

1. 线上 GC 问题的症状，远比你想的更隐蔽

先说个很多人容易忽略的事实：GC 调优不是等 JVM 报 OOM 了才开始做的事。垃圾回收导致的停顿，绝大多数时候不会直接让进程挂掉，而是以各种"看似无关"的形态出现。我见过最离谱的一次，是业务反馈"接口偶尔卡一下，不是每次都卡"，最终定位到是 Young GC 周期性地把应用线程短暂挂起，刚好每次都叠加在某个热点接口的峰值请求上。

1.1 常见表象和真实根因的对应关系

如果你在排查线上问题时，遇到了下面这种"现象对不上原因"的情况，先别急着怀疑基础设施，把 GC 日志翻出来对照一下：

1.2 为什么 GC 日志是排查的第一现场

很多人习惯一上来就 heap dump、jstack 抓线程，这些工具当然重要，但它们就像事故现场的"照片"，拍到的是某一瞬间的状态。而 GC 日志是完整的"监控录像"，它能告诉你：垃圾是怎么堆积起来的、回收是什么时候失败的、对象是在哪个阶段晋升到老年代的。

我的习惯是：任何 JVM 进程，无论线上还是测试环境，都强制开启 GC 日志。理由很简单——出问题的时候，日志里一定能找到线索；没开日志，就只能靠猜。后面会给出具体参数，建议直接复制进你的启动脚本。

2. 从逐字段拆解入手：一条 Minor GC 日志怎么读

很多同学一打开 GC 日志就头疼，满屏的[PSYoungGen: 1536000K->196608K(1679360K)]看着像天书。其实拆开以后特别简单，就三块信息：回收前堆区占了多少、回收后占了多少、这个区域总共能放多少。关键是搞清楚每一段分别指哪个区域。

2.1 先看清楚日志在哪儿开启的

不同 JDK 版本的日志参数差异很大，这里给两版最常用的：

JDK 8 及以下：

-verbose:gc -Xloggc:/data/logs/gc-%t.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintTenuringDistribution -XX:+PrintGCApplicationStoppedTime -XX:+PrintHeapAtGC

JDK 9 及以上：

-Xlog:gc*:file=/data/logs/gc-%t.log:time,uptime,level,tags:filecount=5,filesize=20m

注意：JDK 9 以后PrintGCDetails这套老参数已经废弃，报错时不要再去纠结语法，直接用-Xlog:gc*即可。

2.2 拿一条 Young GC 记录逐段拆

假设你的日志里有这么一行：

[2024-06-11T14:32:01.123+0800] GC(12) Pause Young (Allocation Failure) 456.789s [PSYoungGen: 1536000K->196608K(1679360K)] 1536000K->512000K(3915776K), 0.0123456 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]

逐字段看：

• [2024-06-11T14:32:01.123+0800]：发生 GC 的时间点，带时区，用来和业务日志、监控面板对齐。
• GC(12)：这是 JVM 启动以来第 12 次 GC 事件，按序号查日志很方便。
• Pause Young：这是一次 Young GC，并且是暂停应用的。如果看到Pause Full，那就是 Full GC，问题大得多。
• (Allocation Failure)：触发原因是分配失败——新对象要进 Eden 区，但 Eden 区不够了，于是触发 Young GC。
• 456.789s：JVM 启动到这次 GC 的时间，单位是秒。你可以用它计算 GC 频率。
• [PSYoungGen: 1536000K->196608K(1679360K)]：这是年轻代（Parallel Scavenge 收集器下的 PSYoungGen）的回收信息。回收前占 1.5GB，回收后占 192MB，年轻代总容量 1.64GB。括号前的 196608K 是"存活对象"，不是"垃圾对象"。
• 外面一层的1536000K->512000K(3915776K)：这是整个堆的变化。回收前堆占用 1.5GB，回收后堆占用 512MB，堆总容量约 3.73GB。
• 0.0123456 secs：这次 GC 实际停顿时间，12.3ms。
• [Times: user=0.02 sys=0.00, real=0.01 secs]：CPU 消耗时间和实际经历时间。如果 user 远大于 real，说明 GC 用到了多线程并行回收。

2.3 为什么还要看"回收前"和"回收后"

只看回收后占用是不行的。比如同一台机器上，回收后都是 512MB，但回收前一个是 1.5GB，一个是 900MB，含义完全不同：前者说明年轻代里大部分对象都是"一次性垃圾"，回收效率高；后者说明存活对象本来就多，Eden 区快满时连 Young GC 都救不了。

我自己的判断标准是：如果 Young GC 后堆占用率超过 50%，而且老年代占用还在稳步上升，那就要开始警惕晋升问题了。晋升过快意味着对象活得太久或者 Survivor 区装不下，这往往是 Full GC 的前奏。

2.4 一条 Full GC 日志的"危险信号"

Full GC 的日志长这样：

[2024-06-11T15:02:45.678+0800] Full GC (Ergonomics) 456.789s [PSYoungGen: 0K->0K(1679360K)] [ParOldGen: 3514368K->3514368K(3670016K)] [Metaspace: 45829K->45829K(1060864K)] [3514368K->3514368K(5349376K), 2.234s]

这里最刺眼的不是停顿时间 2.2 秒，而是ParOldGen: 3514368K->3514368K——老年代回收前后一点没变。这意味着回收器认为这些对象全是"活的"，整个堆根本没有可回收空间。这种情况你去调堆大小只会适得其反，真正要做的是找出是谁持有这些对象。

3. GC 日志里的数字，把它们串成一张"问题地图"

日志单条看懂还不够，真正有用的是把多条日志串起来看趋势。我平时做 JVM 调优，最常看四组衍生指标：停顿时间、GC 频率、吞吐量、晋升速率。

3.1 用一组日志算出晋升速率

晋升速率是很多人忽略但极其关键的数字。它指的是单位时间内从年轻代晋升到老年代的对象大小。晋升速率太高，老年代很快就会被塞满，Full GC 必然提前。

举个例子。假设一次 Young GC 前年轻代占用 1.5GB，回收后年轻代占用 192MB，而堆总占用从 1.5GB 变成了 512MB。粗略算一下，堆占用增加了约 320MB，这部分基本就是没有被回收、并且从年轻代"活下来"的对象。如果这次 GC 距离上次只过了 5 秒，那晋升速率就是 64MB/s。老年代总共 3.5GB，按这个速度不到一分钟就会被撑爆。

实际计算时要更严谨，要看PrintTenuringDistribution输出的各年龄对象分布，但日常快速判断，用上面这个粗算法就够定位方向了。

3.2 吞吐量和停顿时间的估算

JVM 调优要追求的不是"GC 次数越少越好"，而是在满足业务 SLA 的前提下，让 GC 停顿尽量短、频次尽量低。官方有个概念叫吞吐量，简单理解就是：

吞吐量 = 应用运行时间 / (应用运行时间 + 所有 GC 停顿时间总和)

假设服务运行 1000 秒，其中 GC 停顿累计 10 秒，那吞吐量就是 99%。对于绝大多数在线业务，99% 以上算健康，99.5% 以上算优秀。但如果 1000 秒里有 50 秒花在 GC 上，用户体验会非常明显地变差，接口超时不奇怪。

具体调优目标不要拍脑袋定。我的经验是：在线业务优先看最大停顿时间（P99 接口别被 GC 毛刺打穿），离线批处理优先看吞吐量，两者冲突时优先保在线。

3.3 从 GC Cause 反推根因

日志里括号里那段英文，比如Allocation Failure、Metadata GC Threshold、GCLocker Initiated GC，其实是排查入口。我整理了一个速查表：

实操心得：看到System.gc不要急着在启动参数里加-XX:+DisableExplicitGC，有些框架和 NIO 底层依赖 System.gc 做堆外内存清理，一刀切禁用可能引发别的问题。要先用-XX:+PrintCommandLineFlags或 jstack 确认调用来源，再决定怎么处理。

4. 一次线上 Full GC 频率飙高：完整排查链路复盘

纸上谈兵没意思，分享一次我处理过的真实案例。场景是促销活动期间，商品详情服务的 Full GC 从 "几天一次" 变成 "每 4 分钟一次"，每次停顿 3 到 6 秒，接口大面积超时。

4.1 第一步：先定位是"垃圾没回收"还是"回收不过来"

打开 GC 日志的第一件事不是看参数，而是看 Full GC 前后的老年代占用。如果老年代每次回收后能降下去一大截，说明对象本身是可回收的，问题是回收频率跟不上分配速度；如果老年代回收后占用纹丝不动，说明有东西把对象"钉"在堆里，属于内存泄漏或者缓存设计问题。

我们当时看到的是后者：每次 Full GC 后，老年代依然占用 3.4GB，完全降不下来。这基本可以直接跳过调参环节，直奔 heap dump。

4.2 第二步：用 jmap/jcmd 看内存分布

在非高峰期执行：

jmap -dump:live,format=b,file=/tmp/heap-$(date +%s).hprof <pid>

或者用较新的 jcmd：

jcmd <pid> GC.heap_dump /tmp/heap-$(date +%s).hprof

注意：-dump:live会先触发一次 Full GC，所以不要在业务高峰期执行，否则你是嫌线上还不够乱。稳妥做法是直接 dump 不带 live，虽然文件大一点，但保证能还原真实状态。

拿到 dump 后用 MAT 打开，看 Dominator Tree 和 Leak Suspects。当时排在最前面的是一张HashMap，被一个 static 容器持有。点进去一看，key 是用户 ID，value 是一个包含商品详情的对象。理论上用户退出后应该清理，但代码里只做了 put，没有 remove。

4.3 第三步：顺着引用链找到"假缓存"

这种问题在 MAT 里非常典型：一个静态集合是 GC Root，它强引用着每一个 value，于是所有缓存对象都成了"合法存活对象"，垃圾回收器再努力也清不掉。

修复方式很简单：在用户会话结束的 finally 块里显式 remove，或者改用带过期策略的本地缓存框架，比如 Caffeine，设置最大容量和过期时间。修复上线后再看 GC 日志，老年代占用稳定在 1.2GB 左右，Full GC 基本销声匿迹，P99 恢复到了 80ms。

这个案例给我们的教训是：GC 日志只能告诉你"这里出了问题"，具体问题要靠 heap dump 和代码逻辑一起定位。但如果没有 GC 日志，你连往哪个方向查都不知道。

5. 调优不是调完就结束：参数背后的取舍和常见坑

很多人喜欢在网上抄一份"最佳 JVM 参数"，贴到启动脚本里就觉得完事了。JVM 调优最忌讳的就是不理解取舍、盲目照搬。

5.1 堆越大，停顿时间会教你做人

一个常见误区是把-Xmx设得很大，觉得堆越大越不容易 OOM。堆变大之后，Young GC 的停顿和 Full GC 的压缩时间都会显著上升，因为需要遍历、移动的对象更多了。我见过一台 64GB 内存的机器，-Xmx48g，每次 Full GC 停顿 20 多秒，服务等于周期性下线。

堆大小不是拍脑袋定的，要结合服务的实际存活对象大小、对象分配速率、可接受的最大停顿时间一起算。常规做法是先给一个保守值，比如-Xms4g -Xmx4g，然后根据 GC 日志里的堆占用趋势微调。

5.2 几组容易踩坑的参数

先说-XX:+UseAdaptiveSizePolicy。JVM 默认会根据运行时的 GC 历史自动调整各代大小，听起来智能，但在稳定业务下反而容易制造"抖动"——年轻代一会儿大一会儿小，GC 频率和停顿时间都不稳定。我的做法是，先通过日志观察一段时间，如果确认业务分配模式稳定，再显式固定-Xmn并关闭自适应调整。

再比如 CMS 的-XX:CMSInitiatingOccupancyFraction=70。这个参数的本意是老年代占用到 70% 就开始并发回收，但如果你不加上-XX:+UseCMSInitiatingOccupancyOnly，JVM 会无视你设的 70，还是按自己的动态判断来。这种"参数设了等于没设"的坑，排查起来特别费时间。

还有-XX:+DisableExplicitGC，前面提到过，慎用。如果非要用，建议配合-XX:+ExplicitGCInvokesConcurrent，把显式 GC 从 Full GC 降级为并发回收，降低停顿。

5.3 我常用的最小化参数模板

JDK 8 环境，我的启动参数大致是这样：

-Xms4g -Xmx4g -Xmn2g -XX:+UseG1GC -XX:MaxGCPauseMillis=100 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/data/logs/heap.hprof -verbose:gc -Xloggc:/data/logs/gc-%t.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintTenuringDistribution -XX:+PrintGCApplicationStoppedTime

G1 下-Xmn仍然有效，但不要和-XX:MaxGCPauseMillis同时调得太激进，否则 G1 会频繁做回收来迎合停顿目标，导致 CPU 消耗上升。稳妥策略是：先保持默认 G1，只设置MaxGCPauseMillis，运行一段观察，再决定要不要动-Xmn。

切换到 JDK 17 时，把日志参数整体换掉：

-Xms4g -Xmx4g -XX:+UseG1GC -XX:MaxGCPauseMillis=100 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/data/logs/heap.hprof -Xlog:gc*:file=/data/logs/gc-%t.log:time,uptime,level,tags:filecount=5,filesize=20m

6. 日志分析也要有工具：不是所有事都要靠眼睛盯

GC 日志文件动辄几百 MB，靠人眼逐行看是不现实的。我平时会用一些轻量手段先把日志"压缩"成几行统计数据。

6.1 用 grep 和 awk 快速统计 GC 次数和停顿

以 JDK 8 日志为例，统计 Full GC 次数：

grep "Full GC" gc-*.log | wc -l

统计每次 Full GC 的停顿时间并求和：

grep "Full GC" gc-*.log | grep -oP "\[Full GC.*?, \K[0-9.]+(?= secs)" | awk '{sum+=$1; count++} END {printf "count=%d total=%.3f avg=%.3f\n", count, sum, sum/count}'

脚本不是重点，重点是思路：先用一个维度（比如 Full GC 次数）筛出问题，再缩小时间范围去逐行看上下文。直接打开 500MB 的文件搜索关键词，大概只有新人会这么做。

6.2 在线日志分析工具怎么用，结果怎么验证

把 GC 日志上传到 GCEasy 这类工具，会自动生成吞吐量、停顿时间分布、各代内存使用曲线。工具给出的"推荐参数"可以参考，但别直接照抄。我的做法是用工具生成图表来定位趋势，具体调整还是结合业务场景手动算。比如工具说"平均停顿 50ms"，你要看这个 50ms 到底是均匀分布的，还是被几次 2 秒的大停顿拉高的。后者靠工具默认的"平均值"根本看不出来，必须回到原始日志里找那几条异常记录。

6.3 日志文件生命周期：不要等到排查时才想起来日志被滚动覆盖了

线上问题通常是突发的，等你发现问题时，可能要查的日志已经是几小时前的事了。所以日志滚动和保留策略要在最开始就配好。JDK 9 以上的filecount=5,filesize=20m表示保留 5 个文件，每个 20MB，能覆盖最近 100MB 的 GC 历史，日常够用。另外强烈建议加上-XX:+HeapDumpOnOutOfMemoryError和-XX:HeapDumpPath，OOM 时自动生成堆快照，这个文件有时候比日志本身还值钱。

最后再分享一个小技巧：GC 日志的%t占位符会在 JVM 启动时生成带时间戳的文件名，多实例部署时不会互相覆盖。如果你用的是同一套发布脚本，一定要确认日志路径的目录有写权限，不然 JVM 启动时会直接报错退出，那一刻你会感谢自己提前踩过这个坑。