概述
最近尝鲜在一些小的微服务里使用了 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.pngGarbage 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日志的解读,有些没有看懂的也都标注了
image.pngGarbage Collection Statistics
image.pnggc日志会大概间隔 10s
输出一次 统计信息,分别是 10秒、10分钟、10小时的统计信息
所以在应用负载很低的,没有触发 GC
的时候,这个统计信息会反复、重复出现
我最开始还以为是BUG
网友评论