JVM Metaspace内存溢出问题

一、现象

x项目线上环境因为jvm报OOM的异常而报警,导致整个服务不可用并被拉出集群,现象如下:

当时的解决方案是增加metaspace的容量: -XX:MaxMetaspaceSize=512m, 从原来默认的256m改为512m, 虽然没有再出现oom,但这个只是临时解决方案,通过hickwall观察metaspace的使用情况还是在上升,后面随着业务访问量越来越大还是有可能达到阈值。

二、分析

Metaspace元空间主要是存储类的元数据信息, 我们的应用里加载的各种类描述信息,比如类名,属性,方法,访问限制等,按照一定的结构存储在Metaspace里,Metaspace空间增长是由于反射类加载,动态代理生成的类加载等导致的,也就是说Metaspace的大小和加载类的数据有关系, 加载的类越多,metaspace占用的内存也就越大。

根据当时的业务场景了解到是因为有个“用户服务”访问“订单详情”接口的访问量突然上升，以及查看clog的eroor日志发现大部分都是"订单详情"接口先报出的这个问题:java.lang.OutOfMemoryError: Metaspace。我在测试环境的jvm里增加-XX:+TraceClassLoading -XX:+TraceClassUnloading记录下类的加载和卸载情况,然后通过jmeter多个线程调用"订单详情"接口模拟metaspace溢出的现象。

发现在catalina.out文件里输出的除了业务上用到的类外还有大量的反射类,如下

[Unloading class sun.reflect.GeneratedSerializetiononConstructorAccessor12 0x0000000100289809]
[Unloading class sun.reflect.GeneratedSerializetiononConstructorAccessor11 0x0000000100289603]
[Unloading class sun.reflect.GeneratedSerializetiononConstructorAccessor10 0x0000000100289556]
[Unloading class sun.reflect.GeneratedSerializetiononConstructorAccessor9 0x0000000100289543]
[Unloading class sun.reflect.GeneratedSerializetiononConstructorAccessor8 0x0000000100289526]
[Unloading class sun.reflect.GeneratedSerializetiononConstructorAccessor7 0x0000000100289453]
[Unloading class sun.reflect.GeneratedSerializetiononConstructorAccessor6 0x0000000100289451]
[Unloading class sun.reflect.GeneratedSerializetiononConstructorAccessor5 0x0000000100289333]
[Unloading class sun.reflect.GeneratedConstructorAccessor8 0x00000001001e3c28]
[Unloading class sun.reflect.GeneratedConstructorAccessor7 0x00000001001e3823]
[Unloading class sun.reflect.GeneratedConstructorAccessor6 0x00000001001e3422]
[Unloading class sun.reflect.GeneratedSerializetiononConstructorAccessor4 0x0000000100188e31]
[Unloading class sun.reflect.GeneratedSerializetiononConstructorAccessor3 0x0000000100188028]
[Unloading class sun.reflect.GeneratedSerializetiononConstructorAccessor2 0x0000000100187322]
[Unloading class java.lang.invoke.LambdaForm$BMH/1682092198 0x000000010010D428]
[Unloading class java.lang.invoke.LambdaForm$BMH/1682092658 0x000000010010D021]
[Unloading class java.lang.invoke.LambdaForm$BMH/1682096534 0x000000010010Ba28]
[Unloading class java.lang.invoke.LambdaForm$BMH/1682097434 0x000000010010D423]
[Unloading class java.lang.invoke.LambdaForm$BMH/1682096438 0x0000000100102424]
[Unloading class sun.reflect.GeneratedSerializetiononConstructorAccessor1 0x0000000100187c32]
[Loading class sun.reflect.GeneratedSerializetiononConstructorAccessor12 from __JVM_DefineClass__]
[Loading class sun.reflect.GeneratedSerializetiononConstructorAccessor11 from __JVM_DefineClass__]
[Loading class sun.reflect.GeneratedSerializetiononConstructorAccessor10 from __JVM_DefineClass__]
[Loading class sun.reflect.GeneratedSerializetiononConstructorAccessor9 from __JVM_DefineClass__]
[Loading class sun.reflect.GeneratedSerializetiononConstructorAccessor8 from __JVM_DefineClass__]
[Loading class sun.reflect.GeneratedSerializetiononConstructorAccessor7 from __JVM_DefineClass__]
[Loading class sun.reflect.GeneratedConstructorAccessor8 from __JVM_DefineClass__]
[Loading class sun.reflect.GeneratedSerializetiononConstructorAccessor6 from __JVM_DefineClass__]
[Loading class sun.reflect.GeneratedSerializetiononConstructorAccessor5 from __JVM_DefineClass__]
[Loading class sun.reflect.GeneratedSerializetiononConstructorAccessor4 from __JVM_DefineClass__]
[Loading class sun.reflect.GeneratedSerializetiononConstructorAccessor3 from __JVM_DefineClass__]
[Loading class sun.reflect.GeneratedSerializetiononConstructorAccessor2 from __JVM_DefineClass__]
[Loading class sun.reflect.GeneratedSerializetiononConstructorAccessor1 from __JVM_DefineClass__]
[Loading class sun.reflect.GeneratedConstructorAccessor7 from __JVM_DefineClass__]
[Loading class sun.reflect.GeneratedConstructorAccessor6 from __JVM_DefineClass__]
[Loading class sun.reflect.GeneratedConstructorAccessor5 from __JVM_DefineClass__]

这些反射类被频繁的加载和卸载是不正常的, 通过Arthas阿尔萨斯工具观察发现每次调用接口都是通过反射的方式实现的

目前我们的项目都是基于soa框架对外提供访问的, 从上图sun.reflect的调用者com.ctriposs.baiji.rpc这些命名也能看出来,

通过上图可以看出在调用底层接口时都是通过反射的方式获取类的实例, 查看com.ctriposs.baiji.rpc.client.ServiceClientBase的getInstance方法代码实现可以确认。

同样对底层接口返回的json数据反序列化时也会用到反射

public <T> T deserialize(Class<T> clazz, InputStream inputStream) throws IOException {
    Class<? extends SpecificRecord> ct = (Class<? extends SpecificRecord>) clazz;
    return (T) _serializer.deserialize(ct, inputStream);
}

继续跟代码可以看到这些反射的实现都会用到java.lang.Class里的ReflectionData对象

ReflectionData是个内部静态类被缓存起来,里面的属性就是我们做反射操作时需要用的属性Field,方法Method和构造函数等.

但是有个问题reflectionData是被SoftReference软引用修饰的,如下图:

如果是软引用的话在内存空间不足时就可能会被回收掉,如果回收掉,那下次再使用的话只能重新通过反射获取,而SoftReference是否被回收又跟SoftRefLRUPolicyMSPerMB参数的值有关系,查看我们线上JVM的配置发现-XX:SoftRefLRUPolicyMSPerMB这个参数设置的是0

SoftRefLRUPolicyMSPerMB这个参数大概意思是每1M空闲空间可保持的SoftReference对象的生存时长(单位是ms毫秒),LRU应该是Least Recently Used的缩写,最近最少使用的,这个值默认是1000ms, 如果被设置为0,就会导致软引用对象马上被回收掉,进而会导致重新频繁的生成新的类,而无法达到复用的效果,第三张图里大量的sun.reflect.GeneratedSerializationConstructorAccessor, GeneratedMethodAccessor就是这样产生的。我把这个参数改为-XX:SoftRefLRUPolicyMSPerMB=1000 (1秒), 发布到生产环境验证了下, 大概是6月10号14点发布,发布后就降下来了,到今天为止基本上比较稳定

下面是单台机器commited的曲线变化

这个是10.28.104.85的metaspace变化曲线,调整后基本上没有再出现波动

下面这个是项目调整后的情况,这个是昨天11号16点发布到线上的

三、总结

【1】目前主要是通过修改JVM的-XX:SoftRefLRUPolicyMSPerMB值来解决metaspace上升问题, 后续会持续观察变化,适当调整参数, 调整的规则可以参考下这篇文章: 【参考答案】：链接。
【2】我们的应用需要大量RPC交互, 使用SOA,CDubbo都会遇到类似的问题,通过上面的源码分析可以看出这个是无法避免的(除非是换一种序列化协议,比如hessian,不走方法反射的方式来赋值)。包括本身使用的Spring框架很多地方也是通过反射实现的比如AOP, 还有我们埋点经常使用的JsonUtils工具, 通过dump文件也能看出来存在大量的属性拷贝和反射操作。

所以我们在平时的业务代码开发中如果遇到两个对象赋值的操作尽量少用反射的方式实现, 比如下面的代码里使用了

这里做的对象拷贝操作使用的是apache common-beanutils.jar中的BeanUtils, 这个类底层采用javabeans+反射实现,性能比较差,内存开销比较大,当系统高并发的情况容易导致Metaspace空间增长过快.这个我会维护到java开发规范里, 不建议这样使用.如果字段少的话直接赋值算了, 多的话可以使用Cglib的BeanCopier类，BeanCopier类底层是采用asm字节码操作方式来进行对象拷贝操作,性能和内存开销都比较小。

还有就是我们的DTO类里也有很多注解,这些注解可能是拷贝接口契约时遗留的, 类似下面: