当小白遇到FullGC

Tech 导读 本文记录了一次排查FullGC导致的TP99过高过程，介绍了一些排查时思路，线索以及工具的使用，希望能够帮助一些新手在排查问题没有很好的思路时，提供一些思路，让小白也能轻松解决FullGC问题；文中实际提到的参数配置不一定适合其他业务场景，在调优自己的项目时还是需要实际试验过才能得出最佳参数配置。

01

前言

在今年的敏捷团队建设中，我通过Suite执行器实现了一键自动化单元测试。Juint除了Suite执行器还有哪些执行器呢？由此我的Runner探索之旅开始了！

本文记录了一次排查FullGC导致的TP99过高过程,介绍了一些排查时思路,线索以及工具的使用,希望能够帮助一些新手在排查问题没有很好的思路时,提供一些思路,让小白也能轻松解决FullGC问题,文中实际提到的参数配置不一定适合其他业务场景,在调优自己的项目时还是需要实际试验过才能得出最佳参数配置。

因为线上服务器,大部分人是没有SSH权限的,没有办法直接执行命令获取容器信息,所以排查过程中只能借助平台提供的工具,平台提供的工具还是挺全的,本文主要用到的工具有: JDOS容器智能监控,JDOS进程查询,SGM容器监控信息,SGM方法调用查询。

以下几个工具简单介绍:

JDOS容器智能监控: 查看容器的CPU,内存,磁盘,IO等信息
JDOS进程查询: 查看Java进程编号,执行常用的Java内存进程查看命令
SGM容器监控信息: 查看JVM虚拟机内存变更历史记录
SGM方法调用查询: 查看某一次关键接口调用的上下依赖,时间分布

02

起因-偶尔出现接口超时

理解，首先 MCube 会依据模板缓存状态判断是否需要网络获取最新模板，当获取到模板后进行模板加载，加载阶段会将产物转换为视图树的结构，转换完成后将通过表达式引擎解析表达式并取得正确的值，通过事件解析引擎解析用户自定义事件并完成事件的绑定，完成解析赋值以及事件绑定后进行视图的渲染，最终将目标页面展示到屏幕。

一开始偶尔会收到报警邮件，显示有些接口调用时间比较长，抽查了一些接口，发现大部分都是调用下游JSF时间比较长，导致响应比较慢，这时候就没太在意，接下来继续观察了几天，发现一个规律，大部分邮件都是每天10点。

图1.问题统计详情

03

排查定位问题

理解，首先 MCube 会依据模板缓存状态判断是否需要网络获取最新模板，当获取到模板后进行模板加载，加载阶段会将产物转换为视图树的结构，转换完成后将通过表达式引擎解析表达式并取得正确的值，通过事件解析引擎解析用户自定义事件并完成事件的绑定，完成解析赋值以及事件绑定后进行视图的渲染，最终将目标页面展示到屏幕。

1.首先确认了10点这个时间点有没有定时任务之类的操作,经过询问确定这个时间点是仓库出库高峰期,导致业务量出现峰值(调用量变大可能是激发FullGC问题,成为问题暴漏的导火线)。

2.第二步就是确认是数据库原因,还是业务代码,还是JSF下游接口达到极限原因,到这一步还是未知的,在这用到了SGM的接口调用查询工具,下图中可以看到,这次调用JSF也是挺高的(这个没有太好办法,除非让下游优化,所以暂时忽略),但是还有一个是logic,这个就是逻辑处理,如果没有那个FullGC提示,就需要去分析代码的处理是否有问题,这通过那行红色字体的提示,很显然确定了是FullGC导致的问题

3.去查看一下容器的FullGC情况,确实发现这个时间点的FullGC特别频繁,到此已经把问题范围定位到就是FullGC导致的。

4.图示

图2、3、4.

04

FullGC问题排查

理解，首先 MCube 会依据模板缓存状态判断是否需要网络获取最新模板，当获取到模板后进行模板加载，加载阶段会将产物转换为视图树的结构，转换完成后将通过表达式引擎解析表达式并取得正确的值，通过事件解析引擎解析用户自定义事件并完成事件的绑定，完成解析赋值以及事件绑定后进行视图的渲染，最终将目

4.1 Full GC触发条件

到这里需要确定一个问题 : “触发FullGC的条件是什么？”，新手可以去博客搜索，当然最好是能记住这个知识点。注意这不是确定“什么原因导致的FullGC？”，因为这个问题原因太多了，要一步一步排查。下面是查到的资料，分享到这里供参考。

1.Minor GC触发条件：当Eden区满时，触发Minor GC。

2.Full GC触发条件：

（1）调用System.gc()时，系统建议执行Full GC，但是不必然执行

（2）老年代空间不足

（3）方法区空间不足

（4）通过Minor GC后进入老年代的平均大小大于老年代的可用内存

（5）由Eden区、From Space区向To Space区复制时，对象大小大于To Space可用内存，则把该对象转存到老年代

这里在代码中并没有找到System.gc()的显示调用,一般也不会调用这个方法,所以直接看第二种情况,到SGM中查看老年代变化,结果发现老年代频繁达到90%,而这个时间正好可以跟上面GC时间对上。

图5.老年代频繁达到90%

4.2 对象进入老年代的几种情况

大家都知道,老年代的对象应该是存活时间很长的对象,但是发现这些对象都在FullGC时被释放掉了,他们为什么到了老年代呢? 这时候需要确定的第二个问题是:“什么情况下对象会进入老年代？” 查资料后有以下几种情况：

1.年龄够了: 躲过15次(默认配置是15次) minorGC 之后从新生代进入老年代；

2.大对象: 大对象直接进入老年代。有一个 JVM 参数 '-XX:PretenureSizeThreshold' 设置值为字节数，创建超过该大小的对象直接进入老年代,如果没有配置这个参数,这个值好像默认是1M；

3.动态年龄判断：当前放对象的 Survivor 区，相同年龄的一批对象（以及小于该年龄）的总内存大于该区的内存的50%，大于该年龄的其他老对象，就会进入老年代（例如1,2,3岁年龄的对象占了 S 区的50%以上，就会把大于3岁的对象移动到老年代去。所以尽量让 S 区中的对象，占比尽量少于 50%）；

4.剩的总量太多: Eden 区存活对象太多，超过了 Survivor 的大小，就直接把这些对象都转移到老年代去。（JDK1.8 空间担保机制）

首先分析第一种情况,如果出现大批量这样的对象,代码中出现了长时间引用(例如:静态Map只加不删),但是可以看到,这些对象在每次FullGC都被释放掉了,说明这批对象存活的时间并不长, 而且代码排查也没发现这种代码,暂时排除这种情况(这的代码因为是工具包的代码,所以没有太深纠,这为续集留个伏笔)。第二种情况,大对象,可以到JDOS下载下来JMap-dump内存快照和JMap-Histo对象统计信息,经过对FullGC前dump分析,结合GC前GC后对象统计结果,并没有发现大量的大对象,这个基本也排除。

通过JMAT(Eclipse Memory Analysis Tools)导入dump文件进行分析，内存泄漏问题一般直接选Leak Suspects即可，mat给出了内存泄漏的建议。另外也可以选择Top Consumers来查看最大对象报告。和线程相关的问题可以选择thread overview进行分析。除此之外就是选择Histogram类概览来自己慢慢分析，大家可以搜搜mat的相关教程。

图6、7、8.

接下来就是第三种和第四种情况,这时需要去查看年轻代三块区域的变化,尤其是Survivor区域,下图是当时一个情况,S区大小一直在变化,而且基本一致保持在50%以上,这时候想到了一个JVM高版本特性,会自动打开UseAdaptiveSizePolicy(动态调整),查资料后发现,好多人反映这个参数会导致对象跨过S区,直接跑到老年代的情况。看到在调用量持续很高的情况,竟然调整到了17M,这肯定会导致容纳不下当时存活的对象。

UseAdaptiveSizePolicy开关参数-XX:+UseAdaptiveSizePolicy是一个开关参数，当这个参数打开之后，虚拟机会根据当前系统的运行情况收集性能监控信息，动态调整这些参数以提供最合适的停顿时间或最大的吞吐量，这种调节方式称为GC自适应的调节策略（GC Ergonomics）。

图9.

4.3 定位到UseAdaptiveSizePolicy问题

既然这有问题,便尝试关闭一下这个参数看下效果,下面是老年代,S区和FullGC,在关闭前和关闭后的效果,关闭之后S区大多数时间有充足的空间,而且,老年代和FullGC图也安稳了很多。关闭AdaptiveSizePolicy的方式：

开启：-XX:+UseAdaptiveSizePolicy(JDK1.8 Parallel Scavenge收集器默认)
关闭：-XX:-UseAdaptiveSizePolicy

图10、11、12.

4.4 发现新的问题

上图中虽然已经安稳了很多,但是还是有一点小问题,频繁FullGC虽然没有了,但是一个小时还是会出现一次FullGC,而且这时候老年代还没有满,这种频率的FullGC,理论上也是不允许的。回到第一个问题,FullGC触发条件,第三个，赶紧看了下永久代,也就是元空间,如下图,这一看不得了,元空间也在频繁变动,而且达到300M左右时会触发一次FullGC释放掉。

tips: 这里是没有配置元空间的大小的,也没有配置元空间的理论上元空间无限大,不会满,查询资料后解释是,元空间也会根据当前已使用进行动态调整,当达到上次调整值90%后就会FullGC,所以每次FullGC元空间大小在200M到500M不等。

4.5 元空间内存排查

这时猜测可能是代码中出现了大量的动态类的声明,想要定位哪些类需要jvm启动参数加上打印类加载和卸载的参数,顺带把GC日志开关也打开

-XX:+TraceClassUnloading -XX:+TraceClassLoading -XX:+PrintGCDetails

图13.

打开后查看日志发现一个频繁加载和卸载的类[com.googlecode.aviator.Expression], 经查询资料,这个是aviator 工具的一个规则引擎类,在加载规则时会动态加载一个类,默认不使用缓存,可以打开缓存防止频繁声明新类。

图14、15、16.

修改代码后重新部署,一小时一次的FullGC也没了,如下图：

图17.

06

总结

理解，首先 MCube 会依据模板缓存状态判断是否需要网络获取最新模板，当获取到模板后进行模板加载，加载阶段会将产物转换为视图树的结构，转换完成后将通过表达式引擎解析表达式并取得正确的值，通过事件解析引擎解析用户自定义事件并完成事件的绑定，完成解析赋值以及事件绑定后进行视图的渲染，最终将目

本次发现的两个场景出现问题排查和解决:

问题一: AdaptiveSizePolicy导致对象提前进入老年代,老年代增长速度快,导致频繁FullGC

解决方式: 关闭：-XX:-UseAdaptiveSizePolicy

问题二: 元空间不断增长,导致一小时一次FullGC

解决方式: 修改逻辑代码防止频繁加载新类

在排查问题时尽可能先找直接原因,缩小排查跨度,不要一步就想知道根本原因,每个线索都要问个为什么,不正常的现象肯定是有原因的。

下面是FullGC排查思路参考脑图：

图18.排查思路参考脑图