使用PrintGCDetails打印GC日志及分析工具

Java 8 中启用 -XX:+PrintGCDetails 需配合 -XX:+PrintGCTimeStamps 和 -Xloggc:gc.log，否则时间缺失、日志不落盘；须过滤非GC行并清理空行/ANSI码后方可解析。

Java 8 中如何正确启用 -XX:+PrintGCDetails

它本身不输出日志文件，只往标准错误流（stderr）打日志，直接运行会混在控制台里，一滚动就丢。必须配合重定向或日志框架才能留存。

• -XX:+PrintGCDetails 要和 -XX:+PrintGCDateStamps 或 -XX:+PrintGCTimeStamps 一起用，否则时间信息缺失，没法对齐业务日志
• Java 9+ 已废弃该参数，改用 -Xlog:gc*，但很多生产环境仍是 Java 8，别强行套新语法
• 别漏加 -XX:+PrintGCTimeStamps —— 否则每行只有相对毫秒数（如 0.123:），查问题时根本不知道是几点发生的
• 示例启动参数：java -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:gc.log MyApp（注意 -Xloggc 是 Java 8 的写法，不是 -Xlog）

GC 日志里关键字段怎么看：以 CMS 和 G1 为例

不同 GC 算法日志结构差异大，同一行里“回收前堆大小 / 当前堆大小 / 总堆大小”这种三元组位置不固定，靠肉眼数空格容易看错。

• CMS 日志中 [GC (Allocation Failure) 表示年轻代 GC，[Full GC (System.gc()) 才是真正 Full GC；但 [Full GC (Metadata GC Threshold) 其实只是 Metaspace 回收，不算 STW 全停顿
• G1 日志里 [GC pause (G1 Evacuation Pause) (young) 是年轻代收集，(mixed) 表示混合收集，to-space-exhausted 出现说明已经来不及回收，可能触发 Full GC
• Times: user=0.05 sys=0.01, real=0.04 secs 中的 real 才是真实停顿时间，user 和 sys 是 CPU 时间，不能反映卡顿

用 gceasy.io 或 GCViewer 解析日志前的预处理

原始日志常含非 GC 行（比如 Spring 启动日志、自定义 System.err.println），直接上传会导致解析失败或图表失真。

• 先用 grep "GC\|Full GC\|pause" 过滤（Java 8 用 grep "GC "，注意空格；G1 日志要加 pause 关键字）
• 避免用 tail -f gc.log | grep ... 实时过滤——日志轮转（logrotate）后文件句柄未更新，会丢数据
• GCViewer 不支持 Java 9+ 的 -Xlog 格式，Java 8 日志也建议先用 sed '/^$/d' 删空行，否则某些版本会解析中断
• 如果日志里有中文或 ANSI 转义符（比如某些容器环境），用 cat gc.log | col -b > gc_clean.log 清理后再上传

为什么可视化工具有时显示“吞吐量 99%”但用户明显感到卡顿

因为吞吐量只算 GC 占总运行时间比例，不反映单次停顿长度。一次 2 秒的 Full GC 在 3 分钟内占比才 1.1%，但用户点击按钮那秒刚好撞上，体验就是“卡死了”。

• 重点关注 Max Pause Time 和 P95/P99 Pause，不是平均值；gceasy.io 的 “Pause Distribution” 图比数字更直观
• 如果 young gen GC 频繁但每次 <10ms，而 mixed GC 很少却长达 800ms，说明 G1 的 Mixed 收集策略没调好，得看 initiating occupancy percent 是否过低
• 日志里出现大量 to-space-exhausted 或 concurrent mode failure，说明 GC 已经失控，此时看吞吐量数字毫无意义

真正难的不是打开日志，而是从一堆时间戳和内存数字里识别出哪一行是“压垮骆驼的最后一根稻草”。多看几次真实故障日志，比背参数有用得多。