MAT排查案例——BeanCopy的正确使用方式
1 问题背景
线上环境和测试环境均发现过应用卡死,频繁Full GC,原因是因为Metaspace空间(JVM参数为-XX:MaxMetaspaceSize为256m)不足导致OOM,一段时间后服务自动重启,重启后服务正常。因为有配置OOM dump文件生成记录,所以获取到了当时OOM dump文件。
项目频繁发生metaspace
溢出,基于相关知识毫不犹豫的想到以下几点
- 项目中使用过多反射
- 项目中使用过多的动态代理技术
- 项目中使用过多的
lambda
2 问题分析
2.1 OOM dump文件分析
从MAT Leak Suspects分析来看:
- 不存在占用内存大的对象。
- 整体看下来无明显异常情况。
2.2 结合资料分析
Metaspace空间使用
- Metaspace 空间通过 mmap 来从操作系统申请内存,申请的内存会分成一个一个 Metachunk,以 Metachunk 为单位将内存分配给类加载器,每个 Metachunk 对应唯一一个类加载器,一个类加载器可以有多个 Metachunk。
- 通过监控可以发现,Metaspace空间使用率为:87%。可能的原因是给类加载器分配的chunk使用率太低,也就是创建了很多类加载器,而每个类加载器又加载了很少的类。
类加载器情况
- 通过arthas查看类加载器使用情况,命令:classloader
- 对应用程序执行情况如下,发现DelegatingClassLoader类加载器数量比较多。
DelegatingClassLoader分析
对dump文件进行分析
- 发现dump文件中有较多的DelegatingClassLoader,且持有GeneratedMethodAccessorXXXX,该类是反射用于加载生成的Method类时,使用的加载器。
- 通过MAT工具查看GeneratedMethodAccessorXXXX对象(List objects with incoming refenrece),发现大部分都是业务DTO字段的set方法。
2.3 关于beanCopy
运行期间最有可能引起问题的地方无疑是我们大量的使用了beanCopy
那么检查项目发现各种方式的beanCopy
都有,有apache
的BeanUtils
,有spring
的BeanUtils
,有cglib
的BeanCopy
。并且我们的很多实体都有上百个字段。
2.3.1 性能测试
当我们开启阿里代码扫描插件时,如果你使用了 Apache BeanUtils.copyProperties 进行属性拷贝,它会给你一个非常严重的警告。因为,Apache BeanUtils性能较差,可以使用 Spring BeanUtils 或者 Cglib BeanCopier 来代替。
执行以下代码,测试这三种beanCopy方法的性能
1 | private static void testCglibBeanCopier(OriginObject origin, int len) { |
分别执行1000、10000、100000、1000000次耗时数(毫秒):
工具名称 | 执行1000次耗时 | 10000次 | 100000次 | 1000000次 |
---|---|---|---|---|
Apache BeanUtils | 390ms | 854ms | 1763ms | 8408ms |
Apache PropertyUtils | 26ms | 221ms | 352ms | 2663ms |
spring BeanUtils | 39ms | 315ms | 373ms | 949ms |
Cglib BeanCopier | 64ms | 144ms | 171ms | 309ms |
结论:
- Apache BeanUtils主要集中了各种丰富的功能(日志、转换、解析等等),导致性能变差,不建议使用。
- Apache PropertyUtils100000次以内性能还能接受,到百万级别性能就比较差了,可酌情考虑。
- spring BeanUtils和BeanCopier性能较好,如果对性能有特别要求,可使用BeanCopier,不然spring BeanUtils也是可取的。
2.3.2 metaspace分析
研究完了性能,确实如阿里代码扫描插件所说,使用 Spring BeanUtils 或者 Cglib BeanCopier 是最稳妥的。但是本次的metaspace溢出,又暴露出了另一个问题:项目中 beanCopy 的使用导致 classLoader 的数量骤增。
先测试下spring
的BeanUtils
:
使用jcmd
命令查看下metaspace
的使用情况发现前15
次调用情况如下jcmd 23328 VM.classloader_stats
1 | Total = 3 1276 7915520 7636416 |
而在15
次之后的情况如下jcmd 23328 VM.classloader_stats
1 | Total = 1035 2321 14387200 10678952 |
可以看到在15
次前classloader
一直是3
个,而15
次之后增长到了1035
个往后稳定在1035
个
那么我们在同样的条件下测试下spring
提供的另一个基于cglib
的BeanCopy
结果如下:
前15
次调用
1 | Total = 3 805 6180864 5358144 |
15
次后调用
1 | Total = 4 820 6187008 5439976 |
我们发现cglib
的beanCopy
仅仅增加了一个classloader
,并且对metaspace
的使用增加幅度非常小。
意味着项目中如果大量使用了反射方式的beancopy
就会创建大量的DelegatingClassLoader
,那么这里为什么是15次之后才出现呢?我们顺着BeanUtils.copyProperties方法点进去,在使用反射调用method.Invoke()
的时候,当你的使用次数超过15
次就会为每一个method
生成一个class
。就会导致metaspace
极速膨胀。
而在cglib
方式下则是以类为单位,所以同样也走到了相关的代码,但是它只生成了一个DelegatingClassLoader
,所以它的metaspace
内存占用比反射来的小很多。
3 结论
此处我们已经很明确这个问题出在项目中大量使用的反射的beancopy
导致metaspace
溢出,理论上来说这种情况可以通过调整-XX:MaxMetaspaceSize为512m解决问题,但是更好的解决方案是尽量使用cglib
方式的beancopy
。