记录参与jvm调优的经历及复盘

 2023-01-18
原文作者:活脱的鳄龟 原文地址:https://juejin.cn/post/7015974547845283848

记录参与jvm调优的经历及复盘

问题出现

在实习的过程中,我们组上线了一个功能,内容大致为查询店的每月数据并按项分类,同时带有导出功能。为确保服务不会出现崩溃,先没有进行全量开放,但是在上线一段时间之后,监控持续报警,并在报警一段时间之后服务进行了自动重启。

发现问题所在

在发现告警之后,我与组长和组员一起第一时间查看了监控,发现CPU有一个高点,以为是CPU飙升导致重启,但是通过获取java进程id并通过stack查看之后,定位到的代码并非执行大型处理逻辑的代码,而是属于自动日志记录部分,所以直接排除了CPU飙升导致容器重启的原因。之后就直接将关注点转向了内存部分,发现内存长时间处在较高水平,约占堆内存的45%-55%,并在容器重启前后出现过多次的上升与下降,经过判断可能是GC方面出现了问题,查阅GC日志后发现,约每5s-8s就会触发一次FULL GC,至此问题找到。

分析问题并规划解决方案

通过监控分析问题

通过GC日志发现FULL GC高频率的出现是导致告警的直接原因,我们在测试环境下对服务进行了压测并通过jvisualvm进行监控。通过使用Jmeter,模拟HTTP请求进行压测,压测参数为50线程,每1s执行一次,执行时间为6h。经过6h的运行后,观察jvisualvm的监控情况。某个时间的GC情况如图所示。

202301011541372411.png

通过观察图能够看出除了频繁的YoungGC之外,old区的内存也在持续上升并最终触发了FULL GC。分析原因可能在于在Eden区的对象是朝生夕死的,但是由于大对象创建过快,导致在YoungGC将Eden区清理之前,由于内存分配机制,大对象直接被分配到了老年代,这才导致了FULL GC的频繁发生。同时,通过监控也证明了这点

202301011541378322.png

根据监控可以看出,我们项目中的一个VO对象被大量创建,同时由于VO对象中的属性为String,也解释了char数组和String对象为第一第二多的原因。

解决问题

根据测试和监控,我们明白了问题主要出现在新生代的大小上,同时由于服务器为多核,我们将新生代的垃圾收集器更换为并行的ParNew垃圾回收器。以提高回收效率,同时我们也决定提高新生代的大小,由于这些大对象都是朝生夕死的,所以为了确定新生代大致所需求的空间,首先我们对这个VO对象进行了分析。首先这个对象中包含了7个String类型的属性,根据对象结构(如下图所示)

202301011541383963.png

一个空的String对象占4字节,对象头为16字节,但由于开启了指针压缩所以为12字节,所以一个空的对象首先为12+4*7=40,由于对象占用大小需要为8的倍数,所以一个空的VO对象为48字节,我们当时通过查看数据库,得到了一个综合计算的平均值,最终计算出一个对象大约为120字节,数据库中的总数据量为2千万左右,每次查询可能涉及到的数量为几十万到几百万条不等,所查询产生的对象暂时以100万计算,那大致所占空间为120* 1000000,约为114MB,若以50的并发量计算,若每次查询到的对象都不同,不考虑缓存的情况下,内存大概会占据5.566GB左右,所以在这样的情况下,最终我们确定的解决方案为,因为查询的数据属于半静态化数据,从数据库缓存和redis两方面着手,尽量将实时生成对象占据内存控制下来,在加上缓存和对象复用,使得新生代大小在4G左右,以使对象尽可能在新生代中被回收掉,同时也不至于因为新生代空间增长太快使得对象进入老年代导致FULL GC。在仅对jvm参数做出修改后,GC情况以及抽样情况如下图所示。

202301011541390414.png

202301011541395295.png 而之后的优化主要针对YoungGC进行优化,使得GC情况更加平稳。