依赖包滥用System.gc()导致的频繁Full GC
简书 涤生。
转载请注明原创出处,谢谢!
如果读完觉得有收获的话,欢迎点赞加关注。
介绍
业务部门的一个同事遇到个奇怪的Full GC问题,有个服务迁移到新的应用后,一直频繁Full GC。新应用机器的配置是4c 8g,老应用是4c 4g,老应用GC都很正常,并且代码没有变更,所以比较奇怪。
现象
问题的现象是,从监控图上看一直有大量的Full GC排查
遇到这个问题,一般都是先看看各个区的内存占用情况:从监控图上看Old Gen、Young Gen、Perm Gen,没什么问题,不会触发Full GC,当然这里看各个Gen是否会触发Full GC需要结合JVM参数配置来看。
顺便也看了下GC日志,一直狂暴CMS GC日志,而且可以看到老年代使用空间也不大,细心可以发现,大量的CMS GC中夹杂着Young、Perm区的回收,所以其实是Full GC。GC日志如下:通过上面的观察,再根据一般触发CMS GC几个可能性:
- Old Gen使用达到一定的比率,默认为92%,这里看CMSInitiatingOccupancyFraction=80%,而实际才使用2%(看监控图表)不到,所以排除这种情况。
- 配置了CMSClassUnloadingEnabled,且Perm Gen的使用达到一定的比率默认为92%,这里看CMSInitiatingPermOccupancyFraction=80%,而实际才使用30%(看监控图表)不到,所以排除这种情况。
- 配置了ExplictGCInvokesConcurrent且未配置DisableExplicitGC的情况下显示调用了System.gc()。
- Hotspot自己根据估计决定是否要触法,如CMS悲观策略,这类可以通过GC日志分析。
大致判断很可能是System.gc()导致的问题,但是怎么定位调用System.gc()的代码呢?
jstack作用非常大,很多问题都能从这里发现,而且比较轻量,对应用基本无影响。某次的jstack信息只代表那个时刻的线程堆栈,有时只看一个jstack信息可能看不出什么问题,一般可以多jstack几次,然后对比去看,基本就能发现一些问题。
(当然该问题,也可能不是频繁的Full GC,可能通过jstack定位不到问题,可以jstat -gccause pid 1000,来查看gc原因。)
很明显,是由于jxl这个包中的close方法显示调用了System.gc()导致的问题。
跟了下代码,自然确实存在这段代码,不过有个设置开关,可以disable这个功能,所以在使用的时候可以设置setGCDisabled(true),关闭触发System.gc()。但是为什么老应用没有问题呢,主要是因为它 -XX:+DisableExplicitGC,屏蔽了System.gc()动作,新应用的JVM没有这个配置。
可能大家还有个疑问,都知道System.gc()会触发Full GC,那为什么一直进行CMS GC(通过GC日志)呢?
主要是因为这个参数-XX:+ExplicitGCInvokesConcurrent,打开此参数后,会做并行Full GC,只有配置-XX:+UseConcMarkSweepGC这个参数,该参数才会生效。因此,System.gc()时Old区会进行CMS GC,可提高Full GC效率。
总结
尽量减少显示使用System.gc()来触发Full GC,这会导致频繁Full GC,非常影响应用性能。