gc日志是内存行为的客观记录,需通过时间线对齐与行为归因分析其与性能问题的关联:比对stw停顿与p95/p99延迟峰值、识别高频gc背后的对象分配/存活异常、结合async-profiler定位垃圾制造源头、对照内存水位与流量曲线优化参数。

GC 日志本身不是性能问题的“原因”,而是应用内存行为在 JVM 层的客观记录。分析它和应用性能的关联,核心是建立「时间线对齐 + 行为归因」逻辑:把 GC 发生的时间、类型、停顿、内存变化,和应用响应延迟、CPU 飙升、请求失败等可观测指标对应起来,找出因果线索。
看 GC 停顿是否直接拖慢请求
关键指标是 STW(Stop-The-World)时长 和应用端监控的 P95/P99 延迟峰值是否重合:
- 用
-XX:+PrintGCApplicationStoppedTime(JDK8)或-Xlog:gc+pause(JDK9+)单独提取每次 GC 的暂停毫秒数 - 将这些时间戳与 APM 工具(如 SkyWalking、Pinpoint)中标记的慢请求时间点比对
- 若某次 Full GC 持续 610ms,而同一秒内大量接口 RT 跳到 700ms 以上,且无其他异常(DB慢、网络抖动),就高度提示 GC 是瓶颈
查 GC 频率是否暴露内存压力
高频 GC 往往不是配置问题,而是应用在“拼命回收”——说明对象生成太快或存活太久:
- Young GC 超过 5 次/秒,大概率存在短生命周期对象暴增(如日志拼接、JSON 序列化临时字符串、循环中新建集合)
- Full GC 或 CMS concurrent mode failure 频发,通常指向老年代被大对象/长生命周期对象缓慢填满,比如缓存未设淘汰策略、静态 Map 持有业务对象、线程局部变量泄漏
- 配合
-XX:+PrintTenuringDistribution查看对象年龄分布:若大量对象在 age=1 就晋升,说明 Survivor 区太小或对象太大,直接进老年代
结合 async-profiler 看“谁在制造垃圾”
GC 日志告诉你“发生了什么”,async-profiler 告诉你“谁干的”:
- 在 GC 高峰期运行
./profiler.sh -d 30 -e alloc -f alloc.jfr <pid></pid>,采集内存分配热点 - 用 JDK Mission Control 打开 JFR 文件,筛选
Allocation Requiring GC事件,定位分配量最大的调用栈 - 例如发现
com.example.ReportService.generatePdf()每秒分配 200MB 临时字节数组,而该方法又恰好触发 Young GC 暴增,就能闭环归因
观察内存水位与 GC 触发节奏是否匹配
GC 不是随机发生的,它由堆使用率驱动。把 GC 日志里的内存快照和业务流量曲线叠在一起看:
- 日志中
12345K->6789K(24576K)这类信息,反映 Eden 区从 12MB 降到 6MB,总容量 24MB —— 若每次 GC 后 Eden 剩余空间都极低(如仅剩 5%),说明新生代偏小或对象存活率高 - CMS 收集器下出现
CMS Initial Mark后紧跟着CMS Final Remark耗时陡增,往往意味着并发标记阶段有大量新对象进入老年代,加剧了 remark 阶段的扫描压力 - G1 日志中频繁出现
G1 Evacuation Pause (mixed),但老年代占用长期低于 45%,说明 G1 过早启动混合收集,可能需调整-XX:G1MixedGCCountTarget











