
比如我接手过一个线上报表服务高峰期接口平均响应时间一度飙到 3 秒多CPU 倒是不忙但 GC 线程的占比高得吓人。打开 GC 日志一看Full GC 一小时出现十几次老年代回收一次要停顿接近两秒。后来纯靠调整新生代比例和晋升阈值把 Full GC 压到了每天个位数接口响应时间稳定在 200 毫秒以内。整个过程没有动一行业务代码说白了调 JVM 的第一步不是改参数而是先学会读 GC 日志。GC 日志就是 JVM 的“体检报告”每次垃圾回收干了什么、耗时多久、回收前后内存长什么样全都写在里面。如果你调 JVM 只是照着网上的参数模板“抄作业”那运气成分太大真正的调优思路是从日志里反推 JVM 当前的内存压力和分配行为再对症下药改参数。这篇文章我会从怎么打开 GC 日志、怎么逐行读懂字段再到真实场景怎么定位问题、怎么选参数和验证效果完整走一遍。这篇文章适合谁刚接触 JVM 调优、被各种参数搞晕的 Java 后端开发以及已经在用 G1 但一直没搞明白日志里那些括号数据的同学。我不打算堆砌命令和参数名而是讲清楚每个配置背后的意图以及你在实际操作中会踩到的坑。1. 为什么从 GC 日志入手调优1.1 先搞清楚 JVM 内存模型再谈参数JVM 的内存布局是调优的地基不了解它直接看参数就像不认识仪表盘就看油耗一样看了等于没看。按照 JVM 规范运行时数据区主要分为堆、虚拟机栈、本地方法栈、方法区元空间和程序计数器。真正影响 GC 行为的是堆年轻代Eden Survivor和老年代以及从 JDK 8 开始用本地内存实现的元空间。对象分配优先走 Eden 区Eden 满了触发 Minor GC经过多次回收仍然存活的对象会通过年龄计数器逐步晋升到老年代。如果晋升速度过快或者晋升阈值设置不合理老年代很快就会被填满导致 Full GC 频繁触发。这就是大部分线上性能问题的最常见根因——不是代码写错了而是对象生命周期和 GC 参数不匹配。以下是我自己做调优时的检查顺序建议你也按这个来先看 JVM 内存模型确认堆、元空间、栈各自的上限打开 GC 日志确认当前收集器的具体行为用 jstat、jmap 等工具观察各区域的使用率和对象分配速率根据日志反推问题区域再决定调哪个参数。1.2 为什么 GC 日志是定位问题的第一现场很多人在调优时习惯直接打开jvisualvm或者付费 APM 工具但这些工具通常只展示当前快照缺少历史趋势。GC 日志天然就是一个时间序列的记录它把每一次 GC 的类型、原因、耗时、内存变化按时间全部记录下来这对排查“偶发性变慢”或“定时任务引发的内存抖动”特别有帮助。另一个原因是 GC 日志直接影响参数决策。举个例子你可以通过日志清晰看到年轻代在 GC 前后的变化量从而推算出每次 Minor GC 大约回收多少内存、晋升到老年代的对象有多少。如果发现 Old 区增长速率异常说明存活对象太多或晋升阈值偏低这时才需要调整-XX:MaxTenuringThreshold或-XX:NewRatio。这比盲目用-Xmx调大堆更精准。2. GC 日志输出配置先让 JVM 开口说话2.1 JDK 8 时代的经典参数组合如果你还在用 JDK 8存量系统里这很常见一套标准的 GC 日志输出参数是这样的-Xloggc:/opt/logs/gc.log -XX:PrintGCDetails -XX:PrintGCDateStamps -XX:PrintGCTimeStamps-Xloggc指定日志输出路径-XX:PrintGCDetails输出详细内存回收信息-XX:PrintGCDateStamps加上日期时间方便把 GC 日志和对业务监控时间点对齐-XX:PrintGCTimeStamps记录 JVM 启动后的相对时间用来观察两次 GC 的间隔。建议再附加这两个参数-XX:PrintHeapAtGC -XX:PrintTenuringDistributionPrintHeapAtGC会在每次 GC 前后各打印一次堆的完整使用情况方便你精确对比各区域的变化。PrintTenuringDistribution会输出年轻代对象的年龄分布看一眼就知道有多少对象熬过了第几次 GC是判断晋升阈值是否合理的直接证据。2.2 JDK 11/17 用统一日志框架JDK 9 引入了 JEP 158把日志系统统一成了-Xlog格式JDK 11/17 完全沿用了这套机制。这时候再用PrintGCDetails其实已经没效果了正确姿势是-Xlog:gc*:file/opt/logs/gc.log:time,uptime,level,tags拆开看gc*表示输出所有 GC 相关日志file指定输出文件time加上日期时间uptime是 JVM 启动后经过的秒数level显示日志级别tags显示日志标签。这套格式支持按 tag 过滤比如只想看垃圾回收暂停和堆信息可以写成-Xlog:gcpause*,gcheap*:file/opt/logs/gc.log:time,uptime我建议在生产上不管哪个版本都加上 GC 日志滚动参数防止日志把磁盘吃满。JDK 8 通常配合-XX:UseGCLogFileRotation -XX:NumberOfGCLogFiles5 -XX:GCLogFileSize20MJDK 11 则在-Xlog里还能通过文件大小和轮转配置做到类似效果。滚动日志在排查问题时至关重要如果只有单个文件且被反复覆盖遇到问题再想调历史数据就抓瞎了。注意如果你同时加-XX:UseParallelGC和-XX:PrintGCDetails在 JDK 8 上能正常输出在 JDK 11 上这两个参数同时存在时新版统一日志会自动屏蔽旧格式别以为参数没生效。3. GC 日志逐行拆解把括号里的数据读明白3.1 Parallel Scavenge 收集器日志里的数字先看一个典型 JDK 8 默认收集器Parallel Scavenge Parallel Old的 Minor GC 日志[GC (Allocation Failure) [PSYoungGen: 6144K-508K(6144K)] 6348K-712K(19968K), 0.0123456 secs] [Times: user0.02 sys0.00, real0.01 secs]这行日志的信息密度很高。Allocation Failure表示 Eden 区空间不足触发了这次 GCPSYoungGen是年轻代使用 Parallel Scavenge 收集器的意思。方括号里6144K-508K(6144K)的含义是GC 前年轻代已用 6144K、GC 后剩余 508K、括号里 6144K 是年轻代当前总容量。后面一截是整个堆的变化6348K-712K(19968K)对应 GC 前堆占用量、GC 后堆占用量、当前堆总容量年轻代 老年代 非堆之外的已提交堆内存。最后real0.01 secs是真实停顿时长在 GC 日志里我们要重点看这个值因为它直接影响用户线程感知到的卡顿。一个容易误读的细节是6144K-508K(6144K)不代表老年代也回收了它只代表年轻代的变化。如果 Minor GC 后堆总使用量下降得不多说明大部分对象没被回收而是晋升到了老年代这往往就是 Full GC 的前兆。3.2 G1 收集器日志里的暂停与分区现在的服务普遍用 G1它的日志跟 Parallel Scavenge 差异很大。以一段典型的 G1 年轻代暂停日志为例[GC pause (G1 Evacuation Pause) (young), 0.0456789 secs] [Parallel Time: 44.7 ms, GC Workers: 4] [Eden: 512.0M(512.0M)-0.0B(512.0M) Survivors: 16.0M-16.0M] [Heap: 512.0M(1024.0M)-64.0M(1024.0M)] [Times: user0.15 sys0.01, real0.05 secs]G1 Evacuation Pause是 G1 的年轻代转移暂停young标记说明是纯年轻代回收。Eden: 512.0M(512.0M)-0.0B(512.0M)意思是 Eden 区从 512M 回收为 0括号里的 512M 是当前分配的 Eden 容量。Survivors表示存活对象从原来的 Survivor 区复制到了另一个 Survivor 区所以大小不变。Heap: 512.0M(1024.0M)-64.0M(1024.0M)这一段是整个堆的变化注意 G1 的堆总容量通常是你设置的-Xmx但实际提交给 JVM 的堆可能只有一部分。如果Heap后面的占用量长期接近总容量说明该扩容了。G1 还有一类日志需要警惕To-space exhausted。它表示在年轻代回收时Survivor 区和老年代都没有足够空间容纳存活对象导致 G1 直接退化为 Full GC这种日志出现时基本意味着你的堆太小或者分配速率过高。3.3 CMS 日志与 Full GC 的识别CMS 在 JDK 9 之后被废弃但存量系统里仍然大量存在。CMS 日志中 Full GC 通常长这样[Full GC (Metadata GC Threshold) [CMS: 12000K-11800K(15360K)], 1.2345678 secs]这个Metadata GC Threshold值得注意它表示元空间使用达到阈值触发的 Full GC而不是老年代满。很多人看到Full GC两个字就着急调堆大小实际上检查一下元空间参数-XX:MaxMetaspaceSize可能就解决了。CMS 的另一类 Full GC 是Allocation Failure那个才是老年代空间不足导致的。判断一次 GC 是否卡顿不能只看日志里的Full GC标签要看实际停顿real值。CMS 并发失败导致的 Full GC 停顿经常要几秒而正常并发标记阶段的CMS-concurrent日志虽然带 GC 字样但不暂停应用线程不能混为一谈。4. 参数优化的决策流程和实战案例4.1 用日志数据反推参数方向调参之前先梳理一下手里有什么信息GC 日志记录的停顿时间、各区域变化、GC 频率、对象晋升分布。这些数据对应三个最基本的问题内存是否够用、对象是否过早晋升、停顿是否可接受。我用一个简单的计算来说明。假设日志显示每次 Full GC 前老年代占用量都在 600M 附近而堆总容量是 1G那么老年代占堆比例已经达到 60%。如果年轻代设置过小新生对象很快填满 Eden频繁 Minor GC 会提高晋升概率老年代膨胀速度就会加快。这时我们可能需要调大堆的-Xmx或者调大年轻代比例-XX:NewRatio来降低晋升压力。反过来如果日志显示 Minor GC 很频繁但每次回收后 Eden 使用量下降明显且晋升到老年代的对象很少说明 GC 频率高是因为 Eden 区太小而不是存活对象太多。这种情况下把新生代调大GC 间隔会立刻拉开。在动手调参之前建议大家先连续收集 3~5 天的 GC 日志错误选择在一个业务高峰时段做调整往往会导致误判。比如秒杀系统下午 3 点的内存压力和凌晨 3 点完全不同单看半小时日志做出的结论大概率是错的。4.2 真实案例老年代疯狂增长的报表服务我曾负责过一个报表聚合服务JVM 参数原先就是默认值堆最大 1G后端会从多个数据源拉数据做聚合。上线一段时间后每天下午都会出现明显的接口超时查 GC 日志发现规律很清晰每次大批量查询进来之后年轻代 GC 频率显著上升半小时内出现 3 次 Full GC每次停顿 1.5 秒以上。我把-XX:PrintTenuringDistribution的输出拿来做分析发现对象年龄统计里大量对象在年龄 1 时就被拷贝到老年代。原因有两个一是 Eden 区大小只有 300M 左右批量查询产生的大量中间对象很快就把 Eden 塞满二是这些中间对象明明可以被回收但因为 Eden 容量不足在年龄 1 时就被晋升老年代瞬间膨胀。当时的调整方案把-Xms和-Xmx统一设置为 2G消除运行时堆扩容的抖动通过-XX:NewRatio1把年轻代和老年代比例调成 1:1给年轻代更多缓冲空间设置-XX:MaxTenuringThreshold15提高晋升阈值让短期对象尽量留在年轻代被回收开启-XX:UseConcMarkSweepGC换成 CMS这是当时 JDK 8 环境后来逐步迁移到 G1。调整后观察一周Minor GC 频率从每 1~2 分钟一次变成每 5~6 分钟一次Full GC 从每天早上到下午出现十几次降到每天 1~2 次接口平均响应时间从 800ms 降到 250ms。这次调优的核心不是哪个参数“妙手回春”而是日志告诉我问题出在晋升压力我才敢动MaxTenuringThreshold和NewRatio。注意改-XX:MaxTenuringThreshold只在串行/Parallel 收集器下能直接生效G1 下它的作用是给对象年龄设置一个上限但具体晋升与否还是由 G1 的自适应逻辑决定不要指望 G1 里调它能立即改变晋升速率。4.3 G1 场景下参数怎么选才不瞎调现在新项目大多默认 G1G1 调优时最关键的目标是停顿时间。你可以用-XX:MaxGCPauseMillis来给 G1 一个停顿目标比如 100ms。但要注意G1 会努力满足这个目标如果堆太小、分配速率太快它就会通过增大年轻代分区数量或提前进行并发标记来迎合目标结果可能是 GC 频率变得很高吞吐量下降。所以 G1 调优遵循的顺口溜是“先调堆再调目标最后调区域”。先确保堆确实满足业务正常水位一般让堆的使用率最高不超过 70%~80%再把MaxGCPauseMillis从默认的 200ms 开始逐步往下压每次调 20ms 左右观察。同时G1 的-XX:G1HeapRegionSize默认会根据堆大小自动计算不建议手动去改除非你明确知道大对象非常多需要把分区调大来减少大对象跨分区的开销。在 G1 日志中还有一个标签值得重点跟踪——Humongous Allocation这代表大对象分配。G1 分区大小是 1M~32M超过分区大小 50% 的对象会直接进入 Humongous 区域。如果你在日志里频繁看到这类分配说明业务代码里出现了比较大的数组或集合GC 参数只能缓解真正的解法是对象拆分或池化。5. 常见问题与排查技巧实录5.1 GC 日志里有 Full GC 但堆内存还很充裕遇到过好几次这种情况排查起来一度让人抓狂。日志显示老年代只用了 40%但频繁 Full GC。后来发现根因在元空间-XX:MaxMetaspaceSize没设置元空间动态扩容触发了Metadata GC Threshold。这类 Full GC 的特征是日志里有明显的Metadata GC Threshold字样而不是Allocation Failure。解法很简单给元空间设置一个合理上限比如 256M~512M并调大-XX:MetaspaceSize初始阈值避免运行时频繁扩容。还有一类是CMS: 12000K-11800K(15360K)这种回收效果极差的 Full GC回收前后老年代占用量几乎没变说明有大量对象无法被回收且持续存活。这时候调参数已经没有意义应该用jmap -dump抓堆 dump用 MAT 分析到底是谁占着内存。5.2 jstat 与 GC 日志配合使用的定位思路GC 日志告诉你的是一段时间内的历史jstat告诉你的是当前实时指标。我常用的命令是jstat -gcutil pid 1000 10这个命令每 1 秒输出一次共 10 次输出列包括EEden 使用率、S0/S1Survivor 使用率、O老年代使用率、M元空间使用率、YGC年轻代 GC 次数、FGCTFull GC 总耗时。用jstat观察O列如果持续快速上升说明晋升压力极大回过头查 GC 日志确认晋升对象的大小和速率。还有个小技巧用jmap -histo:live pid强制触发一次 Full GC 后再看对象直方图可以快速判断哪些对象是真正长期存活的。但这招在生产环境要慎用因为-histo:live会触发 STW优先在低峰期试用。5.3 GC 日志太长怎么快速提取关键信息生产环境的 GC 日志很容易一天就上百兆手动翻是不现实的。我一般用两条命令做粗过滤第一条提取所有 Full GC 记录grep Full GC gc.log | head -20第二条提取每次 GC 的日均停顿时间awk /real/ {print $NF} gc.log | awk -F {sum$2; count} END {print sum/count}如果你想可视化分析可以考虑 GCeasy 或 GCViewer 这类工具它们能自动解析日志并生成堆使用趋势、停顿分布、GC 频率图表。线上应急时工具是很好的辅助但定位最终方向时我还是会回到日志本身去看原始文字因为工具无法代替你判断业务负载的特征。5.4 一个容易忽略的细节JDK 版本切换会导致参数失效我见过一个团队把服务从 JDK 8 升级到 JDK 11业务代码完全没动结果几天后服务频繁 Full GC。原因是原来写在启动脚本里的-XX:PrintGCDetails -XX:PrintGCDateStamps在新版统一日志体系下失效GC 日志根本没输出后续所有监控和判断都失去了依据。升级 JDK 时一定要把日志参数一并验证启动后立刻检查 gc.log 是否在持续写入不要等到出事才发现没日志。同样容易踩坑的还有-XX:UseParallelGC和-XX:UseG1GC这类收集器参数在不同版本中的默认逻辑变化。JDK 11 之后 G1 是默认收集器但很多人的脚本里仍然显式写-XX:UseParallelGC这个参数会强制切换回并行收集器导致和预期的 GC 行为完全不同。升级时逐个参数检查一遍远比排障时猜测更省时间。6. 几个我觉得真正有用的经验总结调 JVM 参数不是把某个值改大改小那么简单它是一个“观察-假设-验证”的循环GC 日志是贯穿整个循环的主线。刚开始看懂 GC 日志需要一些时间但只要按着字段一层层拆多对照几次堆变化和实际代码行为进步会很快。我个人在实际操作中的几条体会给你参考参数调整永远一次只动一个否则你无法判断哪个改动真正产生了效果。同时记录基线数据和调整后的数据比如 Full GC 次数、平均停顿时间、吞吐量用数据说话。生产环境调优一定要留回滚预案。即使你认为某个参数肯定没问题也可能在特定流量下出现意想不到的情况。把旧的启动脚本留着变更窗口放在低峰期。如果 GC 日志显示停顿很长但内存压力不高先去查代码里的锁竞争和 IO 等待不要把所有锅都甩给 GC。GC 是结果不一定是根源。另外如果你在配置元空间和堆参数时拿不准值可以用这个估算思路先跑一次压力测试用jstat记录老年代平均增长率估算你预期的延长时长比如希望在 30 分钟内不触发 Full GC就用平均增长速率乘 30 分钟得到需要预留的空间再结合日志中的实际用量设置阈值。这篇文章写到这内容基本覆盖了 GC 日志分析从入门到实际排查的主要路径。希望你在下一次调优时不要直接复制参数而是先打开 GC 日志让 JVM 告诉你它到底经历了什么。