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频繁但每次 mixed GC 很少却长达 800ms,说明 G1 的 Mixed 收集策略没调好,得看initiating occupancy percent是否过低 - 日志里出现大量
to-space-exhausted或concurrent mode failure,说明 GC 已经失控,此时看吞吐量数字毫无意义
真正难的不是打开日志,而是从一堆时间戳和内存数字里识别出哪一行是“压垮骆驼的最后一根稻草”。多看几次真实故障日志,比背参数有用得多。











