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。




