ZGC实践

0、JDK 17配置

VM_PARAM='-server -Xmx22g -Xms22g -Xss512k -XX:MaxDirectMemorySize=1024m -XX:+HeapDumpOnOutOfMemoryError -XX:InitialCodeCacheSize=512m -XX:ReservedCodeCacheSize=512m -XX:+UnlockExperimentalVMOptions -XX:+UseZGC -XX:+UnlockDiagnosticVMOptions -XX:ZAllocationSpikeTolerance=3 -XX:ConcGCThreads=12 -XX:ZStatisticsInterval=30 -Xlog:safepoint,classhisto*=trace,age*,gc*=info:file=/opt/logs/logs/gc-%t.log:time,tid,tags:filecount=5,filesize=50m -Dio.netty.tryReflectionSetAccessible=true --add-opens java.base/java.lang=ALL-UNNAMED --add-opens java.base/java.io=ALL-UNNAMED --add-opens java.base/java.math=ALL-UNNAMED --add-opens java.base/java.net=ALL-UNNAMED --add-opens java.base/java.nio=ALL-UNNAMED --add-opens java.base/java.security=ALL-UNNAMED --add-opens java.base/java.text=ALL-UNNAMED --add-opens java.base/java.time=ALL-UNNAMED --add-opens java.base/java.util=ALL-UNNAMED --add-opens java.base/java.util.concurrent=ALL-UNNAMED --add-opens java.base/java.util.concurrent.locks=ALL-UNNAMED --add-opens java.base/java.util.concurrent.atomic=ALL-UNNAMED --add-opens java.base/jdk.internal.access=ALL-UNNAMED --add-opens java.base/jdk.internal.misc=ALL-UNNAMED --add-opens java.base/sun.reflect.generics.reflectiveObjects=ALL-UNNAMED --add-opens java.base/jdk.internal.perf=ALL-UNNAMED --add-opens java.base/java.instrument=ALL-UNNAMED --add-opens jdk.attach/sun.tools.attach=ALL-UNNAMED --add-opens=java.base/java.lang.reflect=ALL-UNNAMED -Djava.security.egd=file:/dev/./urandom'

1、秒杀期间性能出现毛刺

原因：自适应算法长时间没GC，流量突增，新对象创建过快，GC不及时，对象将堆占满，引起内存分配阻塞，导致停顿
GC日志：且停顿时GC日志中有大量的“Allocation Stall”日志
解决方案：

• 增大修正系数-XX:ZAllocationSpikeTolerance，更早出发GC
• 开启“基于固定时间间隔”的GC触发机制，-XX:ZCollectionInterval（JDK 11）
• JDK 17用：ZProactive参数启用主动 GC（空闲时预防性回收，默认开启）

2、压测时，cpu出现抖动

原因：开启“固定时间间隔”的GC触发机制，ZCollectionInterval设置过小，导致GC比较频繁
GC日志：日志中关键字是“Timer”
解决方案：调大“固定时间间隔”，使“固定时间间隔”的GC触发机制作为兜底策略，调小并发线程数ConcGCThreads

3、压测时，性能尖刺

性能尖刺一般两个原因：

• CPU负载过高，不能及时处理请求任务
• GC导致STW
  原因：内存和回收速率过慢，引起内存分配阻塞，导致停顿，频繁GC
  GC日志：日志中关键字是“Allocation Rate”
  解决方案：增大并发标记和并行回收速率速度，调整ConcGCThreads和ParallelGCThreads参数，反复调整压测

4、单次GC时间（20ms）与预期的10ms差距较大

原因：dump内存文件，发现系统中ClassLoader实例比较多，ClassLoader属于GC Roots一部分，切ZGC停顿时间与GC Roots的数量成正比
GC日志:观察ZGC日志统计（group:name），发现“Pause Roots ClassLoaderDataGraph”一项耗时较长。
解决方案：服务是之前两个项目合并的，很多重复无用代码，优化无用代码，删除业务中不使用的类

5、长时间不重启，接口性能变差

分析：通过arthas分析+dump内存分析，发现耗时的原因主要是因为日志打印，最终定位org.apache.logging.log4j.util.StackLocator:calcLocation()的耗时
stackLocator：calcLacation
解决方案：

• 要改bug，jkd维度团队段时间无法支持，最终通过升级jdk 17解决
• log4j打印日志时避免打印日志类和行（会导致定位问题困难）

StackLocator:calcLocation()耗时原因：
Log4j2 打异步日志的时候，如果需要保留日志产生的类还有行号，需要缓存堆栈，通过StackWalker来获取线程的调用堆栈；JVM查找方法时会调用"ResolvedMethodTable::lookup"，而ResolvedMethodTable是一个只有1007个bucket的hash表，因为bucket较小，产生冲突的可能性较大，处理冲突的办法是开链法。当链表越来越长时，查找的性能将急剧下降。每次调用StackWalker遍历栈帧的时候，每个栈帧都会生成一个ResolvedMethodName对象放到jvm中的ResolvedMethodTable中，但jdk11的zgc不能有效清理其中不用的对象。因为ResolvedMethodTable是个定容的hashtable，随着其中的数据越来越多，每个bucket的单链表越来越长，查询效率会越来越慢
触发条件：jdk11+zgc+log4j
参考文档：
https://cloud.tencent.com/developer/article/1778169
https://blog.csdn.net/My_Way666/article/details/110857839