OpenJDK11中如何通过xlog配置打印GC日志轮转耗时?
OpenJDK11 基于xlog打印GC日志轮转耗时的配置方案
JDK9引入统一日志框架(JEP 158)后,JDK8原有的UseGCLogFileRotation参数被正式移除,GC日志轮转能力被整合进统一日志的文件输出规则中,轮转相关的事件默认不输出,仅配置GC相关日志级别无法捕获对应信息,具体配置方法如下:
- 首先明确日志tag归属:日志轮转属于JVM统一日志框架自身的运行事件,归属于
log标签,不属于GC业务标签范畴,这也是之前配置logging=trace无法拿到信息的核心原因。 - 开启轮转耗时日志的完整xlog配置示例:
-Xlog:gc*,log+debug=debug:file=/your/gc/log/path/gc.log:time,uptime,level,tags:filecount=10,filesize=200M
配置说明:
gc*保留原有全量GC日志输出log+debug=debug开启log标签下debug级别的日志,该级别刚好覆盖日志轮转的全流程事件,不会输出冗余的框架内部调试信息- 输出路径后拼接的
filecount=10,filesize=200M是xlog体系下的日志轮转配置,对应JDK8时期的NumberOfGCLogFiles、GCLogFileSize参数 - 配置生效后,触发日志轮转时会输出对应事件行,直接包含轮转耗时,格式参考:
[2024-03-15T09:22:41.382+0800][89.231s][debug][log] Rotating log file /your/gc/log/path/gc.log (attempt 1)
[2024-03-15T09:22:41.397+0800][89.246s][debug][log] Log file rotation completed, total time: 15ms
排查轮转触发Safepoint长停顿的配套配置
如果要对齐轮转事件和Safepoint停顿的时间关联,建议在xlog配置中额外加入safepoint相关标签,完整配置如下:
-Xlog:gc*,safepoint*,log+debug=debug:file=/your/gc/log/path/gc.log:time,uptime,level,tags:filecount=10,filesize=200M
配置后可以直接通过时间戳比对,确认长停顿是否和日志轮转时间点完全重合。
另外注意:OpenJDK11 11.0.8之前的小版本存在日志轮转时持有全局日志锁导致STW时间异常变长的已知问题,如果确认停顿由轮转触发,优先升级JDK小版本到11.0.8及以上,可解决绝大多数锁竞争导致的无意义长停顿。
内容的提问来源于stack exchange,提问作者kimmking
相关产品推荐
相关产品推荐

