likes
comments
collection
share

一次由热部署导致的OOM排查经历

作者站长头像
站长
· 阅读数 8

开发中，将代码部署到 test 环境测试的时候，容器经常因为 OOM 重启，而相同的代部署在 prod 环境则没有问题，怀疑是因为近期 test 环境更换了热部署基础镜像包导致的(由于我们的服务只能在 test 环境进行测试，因此使用了公司的代码修改热部署插件)。于是想通过一些 JVM 工具排查下 OOM 原因，最终发现了历史代码中存在的 bug，同时新的热部署基础镜像包放大了这种影响，导致 metaspace 内存泄漏，排查过程如下：

1、查看 JVM 的内存使用情况

观察JVM的内存使用情况，主要用了 Arthas 的 dashboard 命令和jdk自带的 jstat 工具。 首先，查看 arthas 的 dashboard 数据面板的 Memory 区域，发现 metaspace 区内存使用率一致在增加，直到超过 MaxMetaspaceSize 设置的值，发生 metaspace 的OOM。

一次由热部署导致的OOM排查经历

进一步，通过jdk的 jstat 工具查看gc情况，上一次gc是因为 metaspace 内存占用超过了gc 阈值，同时 metaspace 的使用率一直在90%以上，更加验证了 metaspace OOM：

一次由热部署导致的OOM排查经历

2、分析 MetaSpace OOM 原因

JDK8 之后，metaspace 对应于java运行时数据区的 方法区 ，用于存储已被虚拟机加载的类型信息、常量、静态变量、即时编译器编译后的代码缓存等数据，采用本地内存(Native Memory)来实现 方法区 ，本身没有大小限制(受物理内存大小限制)，但可以使用 -XX:MaxMetaspaceSize 参数设置上限，我们这边设置的是2G。

既然是因为类的元数据信息撑爆了元空间，那就看一下类的装载和卸载情况吧，使用 jstat 工具看下类加载情况，并对比 test 和 prod 两个环境的差异：

test 一次由热部署导致的OOM排查经历

prod 一次由热部署导致的OOM排查经历

prod 环境的服务加载了很多类也卸载了很多类(这其实是个线上问题，通过这次排查才发现的，后面分析原因)，而 test 更加严重，加载了很多类，但几乎没有卸载过类。

重点看下 test 服务的类加载情况，使用 Arthas 的 classloader 命令：

一次由热部署导致的OOM排查经历

第一眼就觉得 AviatorClassLoader 比较可疑，其他加载器都是spring和jdk的，这个是谷歌的，同时这个类加载器的实例数量和加载的类的数量非常大，同时随着服务的运行在不断的增长。仅仅是类加载器的实例数量大倒还好，毕竟它的 Class 对象就一份，不会撑爆元空间，但它加载的 Class 会有问题，因为判断是不是同一个类，是由 加载它的类加载器+全限定类名 一起决定，于是乎，可以从这个类加载器入手，代码中全局搜索一下，果然找到了引入点。

3、快速止血

我们的项目是接手的一个报表类的服务，项目中用到了一个表达式计算引擎 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 关键字做同步。我们的业务场景对这个方法的调用量非常大，每个指标的计算都会调用这个方法。至此，有以下结论：

  1. synchronized 同步和线程封闭每个线程私有一个对象二者选其一就行；
  2. 如果 AviatorEvaluator 是线程安全的话，使用单例模式就行，可以减轻堆区的内存压力；

谷歌出品的工具类不是线程安全的？不会吧？

查阅资料得知，AviatorEvaluator 的 execute 方法是线程安全的，代码里的使用姿势不对，修改代码如下，重新发布，不再OOM了。

// 删除 synchronized
public static Object process(Map<String, Object> eleMap, String expression) {
   AviatorEvaluator.execute(expression, eleMap, true); // true 表示使用缓存
}

4、代码分析

但是，还是有两点难以解释： 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虚拟机》中的解释：

一次由热部署导致的OOM排查经历

因为大量的 AviatorEvaluatorInstance 创建了大量的 AviatorClassLoader ，并被热部署 agent 强引用了，得不到回收，那么这些类加载器加载的 Script_* 的Class对象也得不到卸载，直到 metaspace OOM。

通过 JVM 参数 -Xlog:class+load=info 、-Xlog:class+unload=info 看下 prod 环境的类加载和类卸载日志，确实有大量 Script_* 类的加载和卸载:

一次由热部署导致的OOM排查经历

一次由热部署导致的OOM排查经历

而 test 环境这没有此种类的卸载，这边就不再贴图了。

此刻，我比较好奇的是热部署包里的什么类型的对象强引用了我们的自定义类加载器？使用 jprofiler 看下两个环境的堆转储文件，不看不知道，一看吓一跳，问题比想象的更加严重：

prod 一次由热部署导致的OOM排查经历

test 一次由热部署导致的OOM排查经历

对比 prod 和 test 环境的引用情况，test 环境存在热更新类 WatchHandler 对象到 AviatorClassLoader 的强引用，而 prod 环境不存在； 进一步，选择一个具体的 AviatorClassLoader 实例看下引用情况，又有了重大发现：

prod 一次由热部署导致的OOM排查经历

test 一次由热部署导致的OOM排查经历

prod 环境的 AviatorClassLoader 除了加载我们业务需要的自定义类 Script_*，还加载了很多热更新相关的类，同时不同 AviatorClassLoader 实例加载的热更新相关的类的 hashcode 也是不同了，说明每个 AviatorClassLoader 实例都加载了一轮，这才是元空间占用内存的大头。

当然，在正确使用 AviatorEvaluator 的情况下(使用单例模式)，就不会出现这么严重的问题了，但依然存在热部署 agent 对自定义 classloader 的强引用问题。

5、总结

这是我第一次系统地排查 OOM 问题，把之前一些零散模糊的知识点给串起来的，下面总结了一些本次排查涉及到的 JVM 基础概念和工具：

元空间： segmentfault.com/a/119000001…

类加载器： segmentfault.com/a/119000003… segmentfault.com/a/119000002…

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    多功能诊断命令行工具