当前位置：网站首页>JVM-SANDBOX导致目标服务JVM Metaspace OOM的调查始末

JVM-SANDBOX导致目标服务JVM Metaspace OOM的调查始末

2022-07-16 21:12:00 【InfoQ】

背景

放火平台是公司内部研发的平台:遵循混沌工程理念通过故障注入模式对系统进行演练的实施平台，提供丰富的故障场景模拟，以可视化、自动化的方式实施故障演练。 

放火平台利用字节增强框架
JVM-SANDBOX
对java类型的服务进行故障注入。在业务线使用的过程中发现在放火平台对某个java进程故障注入后故障没有生效
 
在经过排查后发现主要是开源项目
JVM-SANDBOX
的bug，其中涉及到ThreadLocal，ClassLoader，Metaspace等相关知识，具体的分析以及优化过程可以往下看。

注入流程

放火平台注入java故障的流程:
在注入故障时放火平台会把故障指令下发到目标机器的chaos-agent上，chaos-agent利用开源项目jvm-sandbox对目标jvm进行故障注入和故障清除。

null
关于jvm-sandbox的工作流程和原理可以参考之前的文章:
透过JVM-SANDBOX源码，了解字节码增强框架的底层实现原理

排查过程

日志表现

在注入无效后登陆目标机器上观察日志，首先发现jvm-sandbox在attach目标jvm时失败了

null
其次看到更关键的日志:Metaspace 溢出了！！！

null
 

Metaspace

Metaspace是什么，引用官方介绍
Metaspace is a native (as in: off-heap) memory manager in the hotspot.
It is used to manage memory for class metadata. Class metadata are allocated when classes are loaded. Their lifetime is usually scoped to that of the loading classloader - when a loader gets collected, all class metadata it accumulated are released in bulk.
简单来说：Metapace是一块非堆内存，用来存储类的元数据，当加载类的时候会在Metaspace中分配空间存储类的元数据，当某个ClassLoader关闭时会对应释放掉对类元数据的引用，当触发GC时这部分类元数据占用的空间即可在Metaspace中被回收掉。

null
 在jdk1.8以前jvm中有一块区域叫永久代（PermGen）大家肯定都不陌生，永久代中有包含方法区以及常量池。不过在1.8的时候将永久代彻底移出jvm，将永久代中存储的数据转移到了Java Heap 或 Metaspace
  • 方法区迁移到Java Metaspace中
  • 字符串常量池则由永久代迁移到了Java Heap中

相关参数:
  • -XX:MetaspaceSize 
    是分配给类元数据空间（以字节计）的初始大小(Oracle逻辑存储上的初始高水位，the initial high-water-mark )，此值为估计值。MetaspaceSize的值设置的过大会延长垃圾回收时间。垃圾回收过后，引起下一次垃圾回收的类元数据空间的大小可能会变大。
  • -XX:MaxMetaspaceSize
     是分配给类元数据空间的最大值，超过此值就会触发Full GC，此值默认没有限制，但应取决于系统内存的大小。JVM会动态地改变此值。
  • -XX:MinMetaspaceFreeRatio
     表示一次GC以后，为了避免增加元数据空间的大小，空闲的类元数据的容量的最小比例，不够就会导致垃圾回收。
  • -XX:MaxMetaspaceFreeRatio 
    表示一次GC以后，为了避免增加元数据空间的大小，空闲的类元数据的容量的最大比例，不够就会导致垃圾回收。
关于Metaspace 就不展开讲了,目前介绍的内容足够我们向下排查和分析，感兴趣的同学可以搜索相关资料。

分析原因

通过注入流程以及Metaspace的介绍，我们了解到在故障注入时会将jvm-sandbox动态的挂载(attach)到目标进程JVM上,在attach后会加载sandbox内部jar以及sandbox的自定义模块jar等，在这个过程中会加载大量的类，当加载类时会分配Metaspace空间存储类的元数据。
 
到这里思考了两个点:
  • 第一直观感受是这个流程没毛病呀，会不会是因为业务服务JVM的Metaspace空间设置的太小？
  • Metaspace的GC 没有触发或者是有泄露导致类的元数据回收不掉？
 

null
 

尝试解决

登陆到目标机器上利用jinfo观察jvm的参数,发现MaxMetaspaceSize设置了128M，这个值确实不大，因为MaxMetaspaceSize的默认是-1(无限制，受限于本地内存)。
让业务服务调整MaxMetaspaceSize参数改为256M，然后重启java进程，再次故障注入 确实没问题了，故障正常生效了。

但实际问题没怎么简单，在连续注入多次后依然出现Metaspace OOM 故障依旧无效。看来应该是故障清除时无法回收掉Metaspace中对应的空间。这个问题就比较严重了，如果不解决业务服务是不敢用放火平台进行java类型的故障注入了。
 
不过到这里 我们已经清晰知道这个问题的复现途径了，就是不断的故障注入以及故障清除在达到一定次数后就会Metaspace OOM，本地复现接着排查吧。

本地复现

利用JVM-SANDBOX提供的demo模块做验证，看一下会不会出现Metaspace OOM。

参数设置

启动参数设置了MaxMetaspaceSize=30M，因为demo模块类非常少，其次为了快速的复现OOM。
TraceClassLoading和TraceClassUnloding参数则是为了观察JVM-SANDBOX在故障注入和清除时加载/卸载类的信息。

null
在启动服务后观察目标服务的Metaspace小于7M
null

首次注入

./sandbox.sh -p 19264 -d 'broken-clock-tinker/repairCheckState'
null
看到确实加载了很多jvm-sandbox的类，Metaspace 也上升到了14M，这个属于正常情况。

null

故障清除

./sandbox.sh -p 19264 -S
null
在故障清除时没有看到UnLoad类的相关信息，Metaspace也没有被回收还是14M
null

多次注入&清除

在多次注入以及清除的操作后，复现了线上业务出现的Metaspace OOM，可以看到在多次注入的过程中，Metaspace一直没有被回收过，占用空间曲线是一路上升。

null

null

问题排查

ClassLoader 关闭失败

上面的分析以及复现都可以确认Metaspace OOM就是因为Metaspace没有进行过回收，Metaspace回收的前提是ClassLoader关闭，在之前的
文章
中介绍了JVM-SANDBOX在shutdown时会关闭ClassLoader。
在JVM-SANDBOX中自定义的ClassLoader都是继承了URLClassLoader，URLClassLoader的关闭方法 官方介绍：
How to Close a URLClassLoader?
The URLClassLoader close() method effectively eliminates the problem of how to support updated implementations of the classes and resources loaded from a particular codebase, and in particular from JAR files. In principle, once the application clears all references to a loader object, the garbage collector and finalization mechanisms will eventually ensure that all resources (such as the JarFile objects) are released and closed.
简单来说：当classLoader加载的所有类没有被引用时即可被关闭。
 
看到这里严重怀疑:
当故障清除时jvm-sandbox中的类还有被引用的情况导致classloader 关闭失败了。

验证猜想

在故障清除后，在目标服务的方法上debug看一下线程信息，果然在threadLocal中找到了两个jvm-sandbox的内部类（EventProcesser$Process,SandboxProtector）的引用。说明猜想是对的，问题的原因就是出现在这里了。
下一步就是分析在jvm-sandbox执行故障清除后为什么还有对这两个类的引用。

null
 

EventProcessor

在JVM-SANDBOX中
EventProcessor
是事件处理器，其中包含了用户自定义的 listener 以及 listenerId，在执行增强代码时会记录调用的堆栈。记录堆栈利用ThreadLocal 将真正的处理单元
Process
对象包装起来，目的就是每个调用都可以正确记录自己的堆栈。
final ThreadLocal<Process> processRef = new ThreadLocal<Process>() {
 @Override
 protected Process initialValue() {
 return new Process();
 }
};
&nbsp;
这里的源码就不带大家分析了，主要是jvm-sandbox的代码实现有bug，在以下两种情况会导致processRef的ThreadLocal没有及时remove造成泄漏
  • 假如在执行注入故障的过程中，进行故障清除会导致泄漏。如下：

null
&nbsp;
  • 假设使用了jvm-sandbox的特性-流程变更（例如立即返回，立即抛出异常），本质也是thread local没有及时remove，导致造成了泄漏

SandboxProtector

SandboxProtector:Sandbox守护者，用来守护接口定义的方法，使得sandbox操作的事件不被响应。
在验证时我们看到SandboxProtector也有ThreadLocal泄漏的情况，这里get=0的时候应该及时remove掉。
 /**
 * 判断当前是否处于守护区域中
 *
 * @return TRUE:在守护区域中；FALSE：非守护区域中
 */
 public boolean isInProtecting() {
 return isInProtectingThreadLocal.get().get() > 0;
 }

改进验证

通过上面的分析，已经清晰的知道问题的根因，那么直接动手改代码看一下修复后的效果。

多次注入&清除

启动参数还是相同的 MaxMetaspaceSize=30M，经过优化后多次注入和清除不会出现Metaspace OOM。
下面是一些验证的过程：
null
&nbsp;
也可以看到Metaspace会进行回收了

null
&nbsp;
卸载类的信息也打印出来了

null
&nbsp;

总结

放火平台利用开源项目JVM-SANDBOX对java类服务进行故障注入，在故障清除时由于JVM-SANDBOX中对ThreadLocal使用不当导致发生泄漏，从而引发关闭ClassLoader失败，最终导致Metaspace OutOfMemoryError。

JVM-SANDBOX社区目前已经处于不活跃状态，我们将JVM-SANDBOX fork到了CNCF 沙箱项目ChaosBlade中，后面将独立维护。本次修改的相关代码已经提交到社区:
PR

在公司中有不少项目使用了JVM-SANDBOX，如果有类似这种多次挂载和卸载的操作，需要注意下这个问题。
原网站

版权声明
本文为[InfoQ]所创，转载请带上原文链接，感谢
https://xie.infoq.cn/article/b186c5a7e2fddc50bbb434f68

边栏推荐

猜你喜欢

随机推荐