在组里大佬分享ZGC后,心情激动下,整理下ZGC的东西。
安装jdk15
wget "http://cdn.arloor.com/jdk/jdk-15.0.1_linux-x64_bin.rpm" -O jdk15.rpm
rpm -ivh jdk15.rpm
update-alternatives --config java
jvm 参数
gc_option="-XX:+UseZGC -XX:-ZProactive -XX:ZCollectionInterval=300 -Xlog:safepoint,classhisto*=trace,age*,gc*=info:file=/var/log/gc-%t.log:time,tid,tags:filecount=5,filesize=50m # 简洁版 -Xlog:safepoint,classhisto*=trace,age*,gc*=info:file=/var/log/gc.log:uptime,tid,tags"
heap_option='-Xms400m -Xmx400m'
GC日志
查看gc的关键信息
# 简洁版
alias lgc='grep -E "gc,start|gc,phases.*Pause|gc,phases|gc,heap|gc,heap.*Used:.*\)"'
lgc /var/log/gc.log
# 复杂版
alias lgc='grep --color=auto -E "gc,start|gc,phases.*Pause|gc,phases|gc,heap|gc,heap.*Used:.*\)" $(ls /var/log/gc* | sort |grep -Ev "log\.[0-9]+"|tail -n 1)'
lgc
初始标记(Pause Mark Start)、再次标记(Pause Mark End)、初始转移(Pause Relocate Start)会STW;如果在GC过程中出现Used比例=100%,则有出现内存分配阻塞(Allocation Stall),也会引起应用停顿。
精简GC信息(去除统计信息)
cat /opt/proxy/gc.log |grep -v "gc,stats"|grep -v "safepoint"
GC信息统计:可以定时的打印垃圾收集信息,观察10秒内、10分钟内、10个小时内,从启动到现在的所有统计信息。利用这些统计信息,可以排查定位一些异常点。
cat /opt/proxy/gc.log|grep -E "gc,stats"
主要关注点已用红线划出:
ZGC引起的应用停顿原因:
除了ZGC时的初始标记(Pause Mark Start)、再次标记(Pause Mark End)、初始转移(Pause Relocate Start),其他引起停顿的原因有:
- 内存分配阻塞:当内存不足时线程会阻塞等待GC完成,关键字是”Allocation Stall”。
- 安全点:所有线程进入到安全点后才能进行GC,ZGC定期进入安全点判断是否需要GC。先进入安全点的线程需要等待后进入安全点的线程直到所有线程挂起。
- dump线程、内存:比如jstack、jmap命令。
ZGC触发时机
- 阻塞内存分配请求触发:当垃圾来不及回收,垃圾将堆占满时,会导致部分线程阻塞。我们应当避免出现这种触发方式。日志中关键字是“Allocation Stall”。
- 基于分配速率的自适应算法:最主要的GC触发方式,其算法原理可简单描述为”ZGC根据近期的对象分配速率以及GC时间,计算出当内存占用达到什么阈值时触发下一次GC”。自适应算法的详细理论可参考彭成寒《新一代垃圾回收器ZGC设计与实现》一书中的内容。通过ZAllocationSpikeTolerance参数控制阈值大小,该参数默认2,数值越大,越早的触发GC。我们通过调整此参数解决了一些问题。日志中关键字是“Allocation Rate”。
- 基于固定时间间隔:通过ZCollectionInterval控制,适合应对突增流量场景。流量平稳变化时,自适应算法可能在堆使用率达到95%以上才触发GC。流量突增时,自适应算法触发的时机可能会过晚,导致部分线程阻塞。我们通过调整此参数解决流量突增场景的问题,比如定时活动、秒杀等场景。日志中关键字是“Timer”。
- 主动触发规则:类似于固定间隔规则,但时间间隔不固定,是ZGC自行算出来的时机,我们的服务因为已经加了基于固定时间间隔的触发机制,所以通过-ZProactive参数将该功能关闭,以免GC频繁,影响服务可用性。 日志中关键字是“Proactive”。
- 预热规则:服务刚启动时出现,一般不需要关注。日志中关键字是“Warmup”。
- 外部触发:代码中显式调用System.gc()触发。 日志中关键字是“System.gc()”。
- 元数据分配触发:元数据区不足时导致,一般不需要关注。 日志中关键字是“Metadata GC Threshold”。
调优案例(搬运自美团技术团队博客)
我们维护的服务名叫Zeus,它是美团的规则平台,常用于风控场景中的规则管理。规则运行是基于开源的表达式执行引擎Aviator。Aviator内部将每一条表达式转化成Java的一个类,通过调用该类的接口实现表达式逻辑。
Zeus服务内的规则数量超过万条,且每台机器每天的请求量几百万。这些客观条件导致Aviator生成的类和方法会产生很多的ClassLoader和CodeCache,这些在使用ZGC时都成为过GC的性能瓶颈。接下来介绍两类调优案例。
内存分配阻塞,系统停顿可达到秒级
案例一:秒杀活动中流量突增,出现性能毛刺
日志信息:对比出现性能毛刺时间点的GC日志和业务日志,发现JVM停顿了较长时间,且停顿时GC日志中有大量的“Allocation Stall”日志。
分析:这种案例多出现在“自适应算法”为主要GC触发机制的场景中。ZGC是一款并发的垃圾回收器,GC线程和应用线程同时活动,在GC过程中,还会产生新的对象。GC完成之前,新产生的对象将堆占满,那么应用线程可能因为申请内存失败而导致线程阻塞。当秒杀活动开始,大量请求打入系统,但自适应算法计算的GC触发间隔较长,导致GC触发不及时,引起了内存分配阻塞,导致停顿。
解决方法:
(1)开启”基于固定时间间隔“的GC触发机制:-XX:ZCollectionInterval。比如调整为5秒,甚至更短。 (2)增大修正系数-XX:ZAllocationSpikeTolerance,更早触发GC。ZGC采用正态分布模型预测内存分配速率,模型修正系数ZAllocationSpikeTolerance默认值为2,值越大,越早的触发GC,Zeus中所有集群设置的是5。
案例二:压测时,流量逐渐增大到一定程度后,出现性能毛刺
日志信息:平均1秒GC一次,两次GC之间几乎没有间隔。
分析:GC触发及时,但内存标记和回收速度过慢,引起内存分配阻塞,导致停顿。
解决方法:增大-XX:ConcGCThreads, 加快并发标记和回收速度。ConcGCThreads默认值是核数的1/8,8核机器,默认值是1。该参数影响系统吞吐,如果GC间隔时间大于GC周期,不建议调整该参数。
GC Roots 数量大,单次GC停顿时间长
案例三: 单次GC停顿时间30ms,与预期停顿10ms左右有较大差距
日志信息:观察ZGC日志信息统计,“Pause Roots ClassLoaderDataGraph”一项耗时较长。
分析:dump内存文件,发现系统中有上万个ClassLoader实例。我们知道ClassLoader属于GC Roots一部分,且ZGC停顿时间与GC Roots成正比,GC Roots数量越大,停顿时间越久。再进一步分析,ClassLoader的类名表明,这些ClassLoader均由Aviator组件生成。分析Aviator源码,发现Aviator对每一个表达式新生成类时,会创建一个ClassLoader,这导致了ClassLoader数量巨大的问题。在更高Aviator版本中,该问题已经被修复,即仅创建一个ClassLoader为所有表达式生成类。
解决方法:升级Aviator组件版本,避免生成多余的ClassLoader。
案例四:服务启动后,运行时间越长,单次GC时间越长,重启后恢复
日志信息:观察ZGC日志信息统计,“Pause Roots CodeCache”的耗时会随着服务运行时间逐渐增长。
分析:CodeCache空间用于存放Java热点代码的JIT编译结果,而CodeCache也属于GC Roots一部分。通过添加-XX:+PrintCodeCacheOnCompilation参数,打印CodeCache中的被优化的方法,发现大量的Aviator表达式代码。定位到根本原因,每个表达式都是一个类中一个方法。随着运行时间越长,执行次数增加,这些方法会被JIT优化编译进入到Code Cache中,导致CodeCache越来越大。
解决方法:JIT有一些参数配置可以调整JIT编译的条件,但对于我们的问题都不太适用。我们最终通过业务优化解决,删除不需要执行的Aviator表达式,从而避免了大量Aviator方法进入CodeCache中。
值得一提的是,我们并不是在所有这些问题都解决后才全量部署所有集群。即使开始有各种各样的毛刺,但计算后发现,有各种问题的ZGC也比之前的CMS对服务可用性影响小。所以从开始准备使用ZGC到全量部署,大概用了2周的时间。在之后的3个月时间里,我们边做业务需求,边跟进这些问题,最终逐个解决了上述问题,从而使ZGC在各个集群上达到了一个更好表现。
使用jconsole连接远程jvm
远程jvm增加参数:
-Djava.rmi.server.hostname=xx.xx.xx.xx -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=8089 -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false
xx.xx.xx.xx要么是域名,要么是ip
参考文档
- 新一代垃圾回收器ZGC的探索与实践
- java9 gc log参数迁移
java -Xlog:help
中对于日志参数的说明- ZGC gc策略及回收过程-源码分析