ZGC 日志理解

2022-01-16 本文已影响0人 Yellowtail

概述

最近尝鲜在一些小的微服务里使用了 ZGC，也打开了相关的 gc 日志，想体验一下10ms以内的暂停，苦于没有支持ZGC的jvm监控工具，只能通过gc日志来监控。但是之前一直看不懂zgc的日志，现在来研究一下（纯日志的研究，不涉及任何优化）并分享出来

如果对 ZGC 和 zgc日志没有概念，可以先看一下美团的这篇博客

jvm 参数

-XX:+UseZGC -XX:-OmitStackTraceInFastThrow -XX:+PrintCommandLineFlags -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/xxx/oom/ -Xlog:safepoint,classhisto*=trace,age*,gc*=info:file=/xxx/gc/gc-%p-%t.log:time,tid,tags:filecount=5,filesize=50m

-XX:+UseZGC 开启ZGC，因为我们使用的是Java 17，所以直接可以打开，如果是Java 11，需要使用两个参数配合开启 -XX:+UnlockExperimentalVMOptions -XX:+UseZGC
-XX:-OmitStackTraceInFastThrow 禁止快速抛异常，当同一个位置的反复出现异常的时候，jvm会在一定次数后只抛出一个简易异常，没有堆栈的那种，定位不便，所以给禁了。但是禁止之后对性能有影响
-XX:HeapDumpPath=/xxx/oom/ OOM之后自动 dump 内存到指定目录
-Xlog:classhisto*=trace,age*,gc*=info:file=/xxx/gc/gc-%p-%t.log:time,tid,tags:filecount=5,filesize=50m 来自美团，但是删除了安全点safepoint相关的配置（因为不知道干啥的-_-）

日志解读

大概看一下第一屏

image.png

[gc, init]

gc, init 是 gc 初始化的日志，打印相关的信息

[gc, start] Warmup

是触发 ZGC 开始回收内存的标识，
其中 [gc,start ] GC(0) Garbage Collection (Warmup) 是服务刚启动时出现，一般不需要关注

找一个预热之后的回收日志

image.png

Garbage Collection (Proactive)

上图中这一行完整信息是 [2022-01-16T08:42:37.929+0000][10][gc,start ] GC(3) Garbage Collection (Proactive)
格式是jvm参数配置的，为：[时间] [线程号] [标记] 信息
关注一下信息部分
其中 GC(3) 这个3表示是第三次GC（看图中绿框得知，下一次数字就是4了）
Proactive 表示是GC的触发原因：ZGC默认的主动触发规则

以下是一次完整GC日志的解读，有些没有看懂的也都标注了