一次由热部署导致的 OOM 排查经历转载
开发中,将代码部署到 test
环境测试的时候,容器经常因为 OOM 重启,而相同的代部署在 prod
环境则没有问题,怀疑是因为近期 test
环境更换了热部署基础镜像包导致的(由于我们的服务只能在 test
环境进行测试,因此使用了公司的代码修改热部署插件)。于是想通过一些 JVM 工具排查下 OOM 原因,最终发现了历史代码中存在的 bug,同时新的热部署基础镜像包放大了这种影响,导致 metaspace
内存泄漏,排查过程如下:
查看 JVM 的内存使用情况
观察JVM的内存使用情况,主要用了 Arthas
的 dashboard
命令和jdk自带的 jstat
工具。首先,查看 arthas
的 dashboard
数据面板的 Memory
区域,发现 metaspace
区内存使用率一致在增加,直到超过 MaxMetaspaceSize
设置的值,发生 metaspace
的OOM。
观察JVM的内存使用情况
进一步,通过jdk的 jstat
工具查看gc情况,上一次gc是因为 metaspace
内存占用超过了gc 阈值,同时 metaspace
的使用率一直在90%以上,更加验证了 metaspace
OOM:
观察JVM的内存使用情况
分析 MetaSpace OOM 原因
JDK8 之后,metaspace
对应于java运行时数据区的 方法区
,用于存储已被虚拟机加载的类型信息、常量、静态变量、即时编译器编译后的代码缓存等数据,采用本地内存(Native Memory)来实现 方法区
,本身没有大小限制(受物理内存大小限制),但可以使用 -XX:MaxMetaspaceSize
参数设置上限,我们这边设置的是2G。
既然是因为类的元数据信息撑爆了元空间,那就看一下类的装载和卸载情况吧,使用 jstat
工具看下类加载情况,并对比 test
和 prod
两个环境的差异:
「test」
分析 MetaSpace OOM 原因
「prod」
分析 MetaSpace OOM 原因
prod
环境的服务加载了很多类也卸载了很多类(这其实是个线上问题,通过这次排查才发现的,后面分析原因),而 test
更加严重,加载了很多类,但几乎没有卸载过类。
重点看下 test
服务的类加载情况,使用 Arthas
的 classloader
命令:
分析 MetaSpace OOM 原因
第一眼就觉得 AviatorClassLoader
比较可疑,其他加载器都是spring和jdk的,这个是谷歌的,同时这个类加载器的实例数量和加载的类的数量非常大,同时随着服务的运行在不断的增长。仅仅是类加载器的实例数量大倒还好,毕竟它的 Class
对象就一份,不会撑爆元空间,但它加载的 Class
会有问题,因为判断是不是同一个类,是由 「加载它的类加载器+全限定类名」 一起决定,于是乎,可以从这个类加载器入手,代码中全局搜索一下,果然找到了引入点。
快速止血
我们的项目是接手的一个报表类的服务,项目中用到了一个表达式计算引擎 AviatorEvaluator
,用来根据表达式字符串计算复合指标,其伪代码如下表示:
public static synchronized Object process(Map<String, Object> eleMap, String expression) {
// 表达式引擎实例
AviatorEvaluatorInstance instance = AviatorEvaluator.newInstance();
// 生产表达式对象
Expression compiledExp = instance.compile(expression, true);
// 计算表达式结果
return compiledExp.execute(eleMap);
}
其中 expression
是表达式字符串,eleMap
是表达式中变量名和具体值的键值对,比如 expression
对应 a+b
,eleMap对应的键值对为 {"a":10, "b":20}
,则process
方法的结果为30
。
之前从未仔细看过这段代码,现在看下来似乎有点不太对劲:synchronized
和 newInstance
是重复了吗?synchronized
是用来做同步的,说明这段代码中有共享资源竞争的情况,应该就是 AviatorEvaluator
实例了,目前的逻辑每次执行 process
都会实例化一个 AviatorEvaluator
对象,这已经不仅仅是线程私有了,而是每一个线程每次调用这个方法都会实例化一个对象,已经属于 「线程封闭」 的场景了,不需要用 synchronized
关键字做同步。我们的业务场景对这个方法的调用量非常大,每个指标的计算都会调用这个方法。至此,有以下结论:
-
synchronized
同步和线程封闭每个线程私有一个对象二者选其一就行; -
如果 AviatorEvaluator
是线程安全的话,使用单例模式就行,可以减轻堆区的内存压力;
谷歌出品的工具类不是线程安全的?不会吧?
查阅资料得知,AviatorEvaluator
的 execute
方法是线程安全的,代码里的使用姿势不对,修改代码如下,重新发布,不再OOM了。
// 删除 synchronized
public static Object process(Map<String, Object> eleMap, String expression) {
AviatorEvaluator.execute(expression, eleMap, true); // true 表示使用缓存
}
代码分析
但是,还是有两点难以解释:a) 为什么是 metaspace
?b) 为什么使用热部署镜像的 test
环境出现 OOM,而 prod
没有出现 OOM?
如果是因为 AviatorEvaluator
对象太多导致的,那也应该是堆区 OOM;同时,prod
环境的请求量远大于 test
环境,如果是像目前 test
这种 metaspace
的膨胀速度,线上肯定也是会 OOM 的,差异在于 test
用的热部署的基础镜像包。
「首先探寻第一个问题的答案,为什么是 metaspace
?」
热部署?ClassLoader? 方法区?此时,脑海里回想起一道经典八股文:动态代理的两种方式?(JDK动态代理和CGLIB动态代理的区别?AOP的实现原理?运行期、类加载期的字节码增强?)
感觉这次 OOM 很大可能是 ** 「ClassLoader」 和 ** 「热部署(字节码增强)」** 撞出的火花 ...**
通过阅读 AviatorEvaluator
的源码,发现调用链简化后大概是这样:
public Object execute(final String expression, final Map<String, Object> env, final boolean cached) {
Expression compiledExpression = compile(expression, expression, cached); // 编译生成 Expression 对象
return compiledExpression.execute(env); // 执行表达式,输出结果
}
private Expression compile(final String cacheKey, final String exp, final String source, final boolean cached) {
return innerCompile(expression, sourceFile, cached); // 编译生成 Expression 对象
}
private Expression innerCompile(final String expression, final String sourceFile, final boolean cached) {
ExpressionLexer lexer = new ExpressionLexer(this, expression);
CodeGenerator codeGenerator = newCodeGenerator(sourceFile, cached); //!!这个方法 new AviatorClassLoader 的实例
return new ExpressionParser(this, lexer, codeGenerator).parse();
}
public CodeGenerator newCodeGenerator(final String sourceFile, final boolean cached) {
// 每个 AviatorEvaluatorInstance 一个 AviatorClassLoader 的实例作为成员变量
AviatorClassLoader classLoader = this.aviatorClassLoader;
//!!这个方法通过上面的类加载器不断生成并加载新的Class对象
return newCodeGenerator(classLoader, sourceFile);
}
public CodeGenerator newCodeGenerator(final AviatorClassLoader classLoader, final String sourceFile) {
ASMCodeGenerator asmCodeGenerator =
// 使用字节码工具ASM生成内部类
new ASMCodeGenerator(this, sourceFile, classLoader, this.traceOutputStream);
}
public ASMCodeGenerator(final AviatorEvaluatorInstance instance, final String sourceFile,
final AviatorClassLoader classLoader, final OutputStream traceOut) {
// 生成了唯一的内部类
this.className = "Script_" + System.currentTimeMillis() + "_" + CLASS_COUNTER.getAndIncrement();
}
这时候原因差不多清晰了,使用 AviatorEvaluatorInstance
对象计算表达式会使用成员变量里的一个 AviatorClassLoader
加载自定义的字节码生成 CodeGenerator
对象。AviatorEvaluatorInstance
用单例模式使用固然没什么问题,但是如果每次都 new 一个AviatorEvaluatorInstance
对象的话,就会有成百上千的 AviatorClassLoader
对象,这也解释了上面通过 Arthas
查看 classloader
会有这么多对应的实例,但 metaspce
的 Class
还是只有一份的,问题不大。同时看到生成的字节码对象都是 Script_
开头的,使用 arthas
的 sc
命令看下满足条件的类(数量非常多,只截取了部分),果然找到了 OOM 的元凶:
OOM 的元凶
「第二个疑问:为什么 prod
没有OOM?」
上面通过 jstat
发现 prod
卸载了很多类,而 test
几乎不卸载类,两个环境唯一的区别是 test
用了热部署的基础镜像。
咨询了负责热部署的同事,了解到热部署 agent 会对 classloader
有一些 强引用
,监听 classloader
的加载的一些类来监听热更新,这会导致内存泄漏的问题。同时得到反馈,热部署后面会用 弱引用
优化。这里引用下《深入理解java虚拟机》中的解释:
弱引用优化
因为大量的 AviatorEvaluatorInstance
创建了大量的 AviatorClassLoader
,并被热部署 agent 强引用了,得不到回收,那么这些类加载器加载的 Script_*
的Class对象也得不到卸载,直到 metaspace
OOM。
通过 JVM 参数 -Xlog:class+load=info
、-Xlog:class+unload=info
看下 prod
环境的类加载和类卸载日志,确实有大量 Script_*
类的加载和卸载:
类的加载和卸载
类的加载和卸载
而 test
环境这没有此种类的卸载,这边就不再贴图了。
此刻,我比较好奇的是热部署包里的什么类型的对象强引用了我们的自定义类加载器?使用 jprofiler
看下两个环境的堆转储文件,不看不知道,一看吓一跳,问题比想象的更加严重:
「prod」
堆转储文件
「test」
堆转储文件
对比 prod
和 test
环境的引用情况,test
环境存在热更新类 WatchHandler
对象到 AviatorClassLoader
的强引用,而 prod
环境不存在;进一步,选择一个具体的 AviatorClassLoader
实例看下引用情况,又有了重大发现:
「prod」
AviatorClassLoader
「test」
AviatorClassLoader
prod
环境的 AviatorClassLoader
除了加载我们业务需要的自定义类 Script_*
,还加载了很多热更新相关的类,同时不同 AviatorClassLoader
实例加载的热更新相关的类的 hashcode
也是不同了,说明每个 AviatorClassLoader
实例都加载了一轮,这才是元空间占用内存的大头。
当然,在正确使用 AviatorEvaluator
的情况下(使用单例模式),就不会出现这么严重的问题了,但依然存在热部署 agent 对自定义 classloader 的强引用问题。
总结
这是我第一次系统地排查 OOM 问题,把之前一些零散模糊的知识点给串起来的,下面总结了一些本次排查涉及到的 JVM 基础概念和工具:
「元空间:」
-
https://segmentfault.com/a/1190000012577387
「类加载器:」
-
https://segmentfault.com/a/1190000037574626
-
https://segmentfault.com/a/1190000023666707
「JDK工具:」
-
jps:JVM Process Status Tool 进程状况工具 -
jstat:JVM Statistics M onitoring Tool 统计信息监视工具 -
jinfo:Configuration Info for Java Java配置信息工具 -
jmap:Memory Map for Java 内存映像工具 -
jhat:JVM Heap Analysis Tool 堆转储快照分析工具 -
jstack:Stack Trace for Java 堆栈跟踪工具 -
Jcmd:多功能诊断命令行工具