依赖包滥用System.gc()导致的Full GC

简书 涤生。
转载请注明原创出处，谢谢！

介绍

业务部门的一个同事遇到个奇怪的Full GC问题，有个服务迁移到新的应用后，一直频繁Full GC。新应用机器的配置是4c 8g，老应用是4c 4g，老应用GC都很正常，并且代码没有变更，所以比较奇怪。

现象

问题的现象是，从监控图上看一直有大量的Full GC

GC 监控图

排查

遇到这个问题，一般都是先看看各个区的内存占用情况：

old young gen监控图

perm gen监控图

从监控图上看Old Gen、Young Gen、Perm Gen，没什么问题，不会触发Full GC，当然这里看各个Gen是否会触发Full GC需要结合JVM参数配置来看。

顺便也看了下GC日志，一直狂暴CMS GC日志，而且可以看到老年代使用空间也不大，细心可以发现，大量的CMS GC中夹杂着Young、Perm区的回收，所以其实是Full GC。GC日志如下：

GC日志

老应用的jvm参数配置

老应用的jvm参数配置

新应用的jvm参数配置

新应用的jvm参数配置

通过上面的观察，再根据一般触发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()的代码呢？

当时就想如果是System.gc()引起的频繁Full GC，jstack线程堆栈应该能看到一些信息，果不其然，确实通过线程堆栈找到了。

jstack线程堆栈

jstack作用非常大，很多问题都能从这里发现，而且比较轻量，对应用基本无影响。某次的jstack信息只代表那个时刻的线程堆栈，有时只看一个jstack信息可能看不出什么问题，一般可以多jstack几次，然后对比去看，基本就能发现一些问题。
（当然该问题，也可能不是频繁的Full GC，可能通过jstack定位不到问题，可以jstat -gccause pid 1000，来查看gc原因。）

很明显，是由于jxl这个包中的close方法显示调用了System.gc()导致的问题。

跟了下代码，自然确实存在这段代码，不过有个设置开关，可以disable这个功能，所以在使用的时候可以设置setGCDisabled(true)，关闭触发System.gc()。

触发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，非常影响应用性能。