记一次服务Full GC背后的内存泄漏问题，真是匪夷所思

最近所负责的服务略频繁地收到4xx告警

1、查业务日志，没发现相关错误的日志

2、查nginx access log，发现返回的状态码都是499，从request_uri查了一遍发现不是集中在某一个请求上，说明应该不是某个接口的问题了，有可能进程层面问题了。

通过对upstream_addr 分类，可以看到问题基本都是集中在 某一台这台机器上

3、网上资料了解到，499 是 nginx 扩展的 4xx 错误，代表客户端请求还未返回时，客户端主动断开连接。原因有几种，不过大部分原因都说到有可能服务器upstream处理过慢，导致用户提前关闭连接。那就先往这个方向排查，登录机器查看实际的access.log

发现upstream response都是10s以上。这就证明了上游服务器处理10秒还没有响应，因此nginx提前关闭链接，返回499

4、为什么进程响应如此慢，10秒太不正常了。考虑到那段时间就只有一台机器有问题，而且是进程层面的问题，首先想到的是GC，于是再次登录到机器上查看gc log。发现有Full GC，时间点和告警的时间也吻合。 惊呆的是，这次FullGC耗时长达19.07秒，由于我们的服务使用的是jdk8默认的ParallelGC，FullGC期间，整个应用Stop The World的。这是非常恐怖的一件事

由此看来，4xx告警的初步原因已经定位到，就是FullGC导致的。

那么究竟为什么会发生FullGC呢？需要深入分析一下。

借助服务治理平台的JVM监控观察了几天。期间不同机器不同时间也发生了几次FullGC。从监控发现，基本每台机器隔两天就会发生一次FullGC，每次FullGC后年老代回收的垃圾不算多，使用比例还是挺高的。

为什么年老代空间占用这么多？

继续分析上面那条full gc log，

1、发生full gc时，年老代内存已经占用了99.98%了（1048397/1048576）。看起来因为年老代满了而触发的FullGC了。

2、full gc回收了年老代大约302M的垃圾，回收后年老代占用70.4%（738282/1048576）。这占用率还是比较高的。

1、首先jmap简单打印一下所有对象的信息。发现有ClassPathList和ClassClassPath两个类的对象数量高达1000多万，并且这两个数量是一样的。仿佛嗅到了内存泄漏的味道。

2、只依靠对象统计信息，不足以定位问题，需要使用完整HeapDump，通过MAT进一步分析

jmap把完整堆heapDump下来

隔一段时间后，继续jmap，这次只取存活对象的dump（实际效果是先执行一次FULL GC）

可以看到，经过Full GC后，ClassPathList对象没有被回收，数量反而继续增加。到这里，基本可以确定，ClassPathList是存在泄漏了。

那么，ClassPathList究竟被谁引用着，导致回收不掉呢？

通过MAT的OQL过滤出老生代的ClassPathList对象，从对象的关联关系上继续深入分析。

首先需要知道老生代的地址区间，可以使用vjtools

通过vjmap的address命令，快速打印各代地址。

可以得知，oldGen的下界是0x80000000，上界是0xc0000000（注意OQL中使用时要把数值前的那串0去掉）。

执行OQL只查询年老代中的ClassPathList对象：执行OQL只查询年老代中的ClassPathList对象：

抽取其中一个对象分析，可以发现这个ClassPathList对象被一连串不同ClassPathList对象的next属性引用着。看起来是个链表的结构

再看看GCRoot，发现是被AppClassLoader也就是我们的应用类加载器引用着。除非这个加载器卸载了，否则ClassPathList对象是不会被GC掉了。

分析到这里，似乎离真相越来越近了。到底这个ClassPathList在项目中哪里使用到了？

通过前面的分析知道了ClassPathList的整体引用关系链：

AppClassLoader ->ClassPool类的defaultPool字段 ->ClassPoolTail类的source字段 ->ClassPathList类的pathList

可以看到，ClassPathList有两个属性，一个是next，结合之前MAT的分析，ClassPathList的确就是一个链表的结构。随着时间的增长，ClassPathList不断新增，链表也随之变得越来越大，最后内存占用逐渐上升。

另一个path字段属于ClassPath类型，ClassPath是个接口，查看它的实现类，发现一个似曾相识的名称ClassClassPath，之前分析对象统计信息时，还有一个类的对象数量是和ClassPathList一样的，正是这个ClassClassPath。每新增一个ClassPathList，都会伴随着新增对应的ClassPath对象，这也解释了为什么两者数量是一致的了。

通过注释知道，这个ClassClassPath的作用大概就是，利用一个叫ClassPool的对象，可以调用其insertClassPath方法来新增一个ClassClassPath对象，insertClassPath方法内部通过头插法将ClassClassPath添加到ClassPathList链表，从而形成一个search-path，然后通过这个search-path能够获取到某一个Class类的信息。

于是尝试着搜了一下，看看项目中有没有调用到insertClassPath方法的地方。意外发现一个类，

这不就是我们项目用来打印方法入参、执行耗时、上报metrics的@AutoLog的实现类吗。

可以看到getParams方法中调用了insertClassPath，注解@AutoLog的printParams默认为true，也就是每次调用都需要打印方法入参，每次打印前都要调用getParams先获取参数名称。因此每次都会insertClassPath，从而导致ClassPathList链表越来越大。

至此，内存泄漏的元凶已经找到。解决方法也就简单了。

因为目标只是想得到方法的参数名称，通过JoinPoint其实能直接获取到，因此可以改成JoinPoint获取的方式。

为了进行对比，分别在修改前后各进行一次压测。压测JVM参数大致与线上一致，为了尽快看到效果，只是调小了heap的大小。-Xms200m -Xmx200m

ClassPathList数量不断增长

年老代每次能回收的垃圾越来越少，每次回收过后的剩余空间也越来越小。最终整个年老代被撑满

虽然还没触发OOM，但是CPU负载飙高，从基本都在处于频繁的FULLGC状态

ClassPathList已经被消灭掉了

FullGC也趋于规律化了。每次回收的垃圾大致都相同

第一种方式是在启动参数增加 -XX:+PrintHeapAtGC，每次GC都打印地址

第二种方式是使用vjmap的命令，在-old, -sur, -address 中，都会打印出该区间的地址

第三种方式，使用vjmap的address命令，快速打印各代地址，不会造成过长时间停顿。

附： 我们服务的JVM参数

在springboot-admin当中，大概会有以下几种类型的gc出现，本文我们看看他们分别是什么意思。

本文使用的垃圾收集器是jdk1.8的PS+PO。

顾名思义，就是内存分配失败导致的GC，常见于年轻代当中。

使用JNI临界区的方式操作数组或者字符串时，为了防止GC过程中jarray或者jstring发生位移，而导致数组指针失效，需要保持它们在JVM Heap中的地址在JNI Critical过程中保持不变。于是JVM实现了GC_locker，用于JNI Critical内阻止其他GC的发生。

当GCLocker被激活且需要发生GC的时候（这里是否需要GC是各种GC发生时，调用GCLocker::check_active_before_gc()函数check并设置_needs_gc = true的），就会阻塞其他线程进入JNI临界区；并且在最后一个位于JNI临界区的线程退出临界区时，发起一次CGCause为_gc_locker的GC。这里解释了GCLocker Initiated GC发生的原委。

在JVM中的垃圾收集器中的Ergonomics就是负责自动的调解gc暂停时间和吞吐量之间的平衡，使你的虚拟机性能更好的一种做法。

简单说就是内存在进行分配的时候，会通过一些算法，预估是否会出现无法分配的问题。如果符合无法分配预估值，会提前进行一次gc。

这个gc主要发生的条件是元空间，也就是Metadata的参数设置问题。

通常根据我们学习的JVM只是，元空间使用的是本地内存，所以应该与当前服务器的最大内存有关。

但实际不是这样的，在jdk1.8中，如果不设置元空间的大小，会有一个默认值是 21M 。

所以需要我们启动的时候指定一个元空间大小：

GC日志如下所示：

---