(转载)一次生产系统 Full GC 问题分析与排查总结

一次生产系统 Full GC 问题分析与排查总结

 

转载请注明 AIQ - 最专业的机器学习大数据社区  http://www.6aiq.com

AIQ 机器学习大数据 知乎专栏 点击关注

一次生产系统 Full GC 问题分析与排查总结

背景

最近某线上业务系统生产环境频频 CPU 使用率太低，频繁告警，经过重启能够缓解，可是过了一段时间又会继续预警，线上两个服务节点相继出现 CPU 资源紧张，致使服务器卡死不可用，经过告警信息能够看到如下问题：

从上图能够看到，目前 zabbix 监控展现 CPU 空闲时间已经低于预警线，证实目前 CPU 资源占用太高，考虑到最近并无特别开发任务上线，可是最近有发布过一个新的营销活动，有多是由于忽然用户量增加进一步凸显该问题。

从 Pinpoint APM 监控工具看到，从 9 月 3 号下午开始，系统开始出现频繁 full gc 的状况，而恰好 9 月 3 号下午发布了一个新活动，基本能够判定这多是用户量忽然激增，凸显潜伏已久的系统问题，因而接下来方向就能够往 full gc 方向去排查，找出引发 full gc 的代码。

侦查思路

往 FULL GC 方向侦查，怀疑存在内存泄露

排查路线：

既然上面已经定位到是 FULL GC 问题，咱们就能够用经常使用 FULL C 的手段去解决。在此次故障分析咱们是利用 MAT 去作分析，主要对如下几点作排查：

• 程序是否内存泄露

• 程序中是否存在不合理的大对象占用

• 程序中部分对象产生内存是否能够优化

导出 JVM dump 文件和 jstack 线程日志, 保留案发现场

由于公司不容许我的访问线上服务器，因而让运维同窗在服务器出现故障时导出 jvm dump 文件和 jstack 线程日志，若是本身有权限去生产服务器的话，能够经过如下指令导出 jvm dump 文件

jmap -dump:format=b,file=文件名 [服务进程ID]

结合 MAT 分析工具, 找出可疑对象

使用 MAT 前，先简单介绍下 MAT 的一些经常使用的指标和功能概念：

• Shallow Heap 指标：对象自己占用内存的大小，不包含对其余对象的引用，也就是对象头加成员变量（不是成员变量的值）的总和

• Retained Heap 指标：是该对象本身的 shallow size，加上从该对象能直接或间接访问到对象的 shallow size 之和。换句话说，retained size 是该对象被 GC 以后所能回收到内存的总和。

• Histogram 动做：列出每一个类的实例数

• Dominator Tree 动做：列出最大的对象以及它们保存的内容

• Top Consumers 动做: 按照类和包分组打印花费最高的实例

• Duplicate Classes 动做: 检测由多个类加载器加载的类

• Leak Suspects 报告: 包括泄密嫌疑人和系统概述

• Top Components 报告：列出大于总堆的 1％的组件的报告

经过 Leak Suspects 排查内存泄露

在Ecplise Memory Analyzer导入 JVM dump 文件，点击工具栏上的 Leak Suspects 菜单项来生成内存泄露分析报告，也能够直接点击饼图下方的 Reports->Leak Suspects连接来生成报告。如图：

MAT 工具分析了 heap dump 后在界面上很是直观的展现了一个饼图，该图深色区域被怀疑有内存泄漏，能够发现整个 heap 才 1.5G 内存，深色区域就占了 57.76%。接下来是一个简短的描述，MAT 告诉咱们存在两个可疑问题

• Problem Suspect 1：告诉咱们java.lang.Thread线程实例占用了大量内存，一共存在5154个实例，而且明确指出system class loader加载的java.lang.Thread实例占据了643,021,136 (41.03%)字节 ，并建议用关键字 "java.lang.Thread" 进行检查。因此，MAT 经过简单的两句话就说明了问题所在，就算使用者没什么处理内存问题的经验。在下面还有一个 "Details" 连接，MAT 给了一个参考类。如图：

• Problem Suspect 2: 告诉咱们jdk.nashorn.internal.runtime.Context线程实例占用了大量内存, 而且明确指出sun.misc.Launcher$ExtClassLoader @ 0x9000cf78加载的jdk.nashorn.internal.runtime.Context实例占据了262,229,320 (16.73%)字节，并建议用关键字sun.misc.Launcher$ExtClassLoader @ 0x9000cf78 jdk.nashorn.internal.runtime.Context进行检查

经过 Top Consumers 定位大对象

点击 Actions->Top Consumers , 查看大对象有哪些

从上图能够看出，java.lang.Thread、jdk.nashorn.*和javax.script.*这些类实例占据了大部份内存

问题分析

从上面分析报告，可疑大胆推断如下结论：

• 大量java.lang.Thread实例，明显不合理是线程使用不合理，怀疑有地方不断建立线程，没有使用线程池致使

• 大量jdk.nashorn.internal._和javax.script._相关实例，而jdk.nashorn.*这个包是 Nashorn JavaScript 引擎的包，主要是 nashorn 用于在 JVM 上以原生方式运行动态的 JavaScript 代码来扩展 Java 的功能，javax.script包用于 javascript 与 java 交互操做。因而能够基本判定这是跟 javascript 脚本相关操做有关，应该是有地方不断建立 javascript 脚本相关对象没有被回收。

结合以上两点，推测应用程序线程和脚本操做部分出现问题，与该系统相关开发人员沟通，确实该系统是有大量 javascript 脚本操做，是经过 Javascript 脚本作一些特性开发，而后在在 java 调用执行。尝试使用包名jdk.nashorn查找运维导出的 jstack 线程日志，看看最接近的业务代码是什么

果真看到了线程日志里面找到了疑似线程操做的业务代码，经过查看源码，一步步查看调用链，发现了有个地方会每次实例初始化都会建立一份脚本引擎

这段代码大概做用是把每一个任务的规则脚本存放在脚本引擎，而后存放在threadLocal里，每一个MissionEventHandler实例初始化都会建立一个threadLocal用于存放当前线程任务脚本，以防多线程操做同一个MissionEventHandler实例会引发脚本因并发被篡改问题。而通过沿着调用链查看源码了解，这些MissionEventHandler实例只会业务人员点击任务下线的时候才会进行销毁处理，那就是只要任务不下线，这些任务会一直存活在内存中。

可是只要MissionEventHandler实例数量控制好，应该是不会出现上述大量脚本相关实例引起频繁 FULL GC 问题，接下来咱们的侦查方向就是查看MissionEventHandler实例建立源头，** 是否系统存在批量建立该实例的代码？** 继续沿着调用链查看源代码，发现了一个异步观察者类，它是用来通知消息事件的，如下是其中一个方法

这里是使用了CompletableFuture的supplyAsync(Supplier supplier)方法进行异步处理，再进一步查看supplyAsync的源码

从上面代码能够看到，supplyAsync有 2 个重载方法，当咱们不指定线程池，它默认是调用第一个方法，ForkJoinPool.getCommonPoolParallelism() > 1才会使用 commonPool 线程池，不然该方法默认会每次建立一条新的线程去处理。那有没有多是ForkJoinPool.getCommonPoolParallelism()<=1致使每次都建立新的线程呢?咱们进一步查看ForkJoinPool.getCommonPoolParallelism()源码，发现这方法使用 Java 8 中的ForkJoinPool.commonPool()可使用一个特殊的 ForkJoinPool。该池使用一个取决于可用内核数量的预设并行度。通常状况下，预设的并行度是CPU 内核数 -1，该系统在生产环境运行的服务器核数为 2，那就是并行度为 1，即这里的ForkJoinPool.getCommonPoolParallelism()=1, 意味着CompletableFuture的supplyAsync方法在这里处理业务是每次都建立一条新的线程去处理。

总结

根据上面的分析，一切都真相大白，以前看到的大量java.lang.Thread实例就是由于处理业务时，默认每次都会开启一条新的线程，致使出现大量的线程实例，而这些大量的线程实例又会引起大量的通知消息操做，致使持有的脚本相关实例无法被回收，从而引起了大量jdk.nashorn.internal.*和javax.script.*占据堆内存。

解决方案

这里的解决方案很简单，这里引起的问题都是由于没有使用到线程池致使的，能够采起如下两种措施:

• 经过在 tomcat 配置 jvm 启动参数-Djava.util.concurrent.ForkJoinPool.common.parallelism=2, 可让supplyAsync(Supplier supplier)方法启动默认的ForkJoinPool.commonPool()去执行

• 改成调用CompletableFuture supplyAsync(Supplier supplier,Executor executor)，给方法指定线程池 (推荐)

在本次改造是使用第二个方案，建立了一个自定义线程池，而后指定线程池去执行操做，修改后代码以下 (高亮部分)：

上线后观察监控

上线后经过 PINPOINT 观察，再也没出现 FULL GC 问题，以下图所示：

Java 引用法则说明

从最强到最弱，不一样的引用（可到达性）级别反映了对象的生命周期。

• Strong Ref(强引用)：一般咱们编写的代码都是 Strong Ref，于此对应的是强可达性，只有去掉强可达，对象才被回收。

• Soft Ref(软引用)：对应软可达性，只要有足够的内存，就一直保持对象，直到发现内存吃紧且没有 Strong Ref 时才回收对象。通常可用来实现缓存，经过 java.lang.ref.SoftReference 类实现。

• Weak Ref(弱引用)：比 Soft Ref 更弱，当发现不存在 Strong Ref 时，马上回收对象而没必要等到内存吃紧的时候。经过 java.lang.ref.WeakReference 和 java.util.WeakHashMap 类实现。

• Phantom Ref(虚引用)：根本不会在内存中保持任何对象，你只能使用 Phantom Ref 自己。通常用于在进入 finalize() 方法后进行特殊的清理过程，经过 java.lang.ref.PhantomReference 实现。