记录一次Metaspace OOM的问题

事件

4.13号测试部署的服务突然爆oom异常

第一次OOM异常如下：

2020-04-14 14:42:43.092 - - [ERROR] Druid-ConnectionPool-Create-755299134 DruidDataSource  (DruidDataSource.java:2699) create connection SQLException, url: jdbc:m
ysql://10.24.65.26:4000/trade_event?characterEncoding=UTF8&socketTimeout=60000&allowMultiQueries=true, errorCode 0, state S1000
java.sql.SQLException: java.lang.OutOfMemoryError: Metaspace
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:964) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:897) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:886) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:860) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:877) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:873) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:443) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:389) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:330) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.alibaba.druid.pool.DruidAbstractDataSource.createPhysicalConnection(DruidAbstractDataSource.java:1596) ~[druid-1.1.18.jar!/:1.1.18]
        at com.alibaba.druid.pool.DruidAbstractDataSource.createPhysicalConnection(DruidAbstractDataSource.java:1662) ~[druid-1.1.18.jar!/:1.1.18]
        at com.alibaba.druid.pool.DruidDataSource$CreateConnectionThread.run(DruidDataSource.java:2697) [druid-1.1.18.jar!/:1.1.18]
Caused by: java.lang.OutOfMemoryError: Metaspace
2020-04-14 14:42:44.943 - - [ERROR] Druid-ConnectionPool-Create-755299134 DruidDataSource  (DruidDataSource.java:2699) create connection SQLException, url: jdbc:mysql://10.24.65.26:4000/trade_event?characterEncoding=UTF8&socketTimeout=60000&allowMultiQueries=true, errorCode 0, state S1000
java.sql.SQLException: java.lang.OutOfMemoryError: Metaspace
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:964) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:897) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:886) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:860) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:877) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:873) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:443) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:389) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:330) ~[mysql-connector-java-5.1.44.jar!/:5.1.44]
        at com.alibaba.druid.pool.DruidAbstractDataSource.createPhysicalConnection(DruidAbstractDataSource.java:1596) ~[druid-1.1.18.jar!/:1.1.18]
        at com.alibaba.druid.pool.DruidAbstractDataSource.createPhysicalConnection(DruidAbstractDataSource.java:1662) ~[druid-1.1.18.jar!/:1.1.18]
        at com.alibaba.druid.pool.DruidDataSource$CreateConnectionThread.run(DruidDataSource.java:2697) [druid-1.1.18.jar!/:1.1.18]

分析

1、Metaspace区域的oom 多考虑
1）类重复加载
2）加载的class过大
3）类加载器过多导致Metaspace碎片化严重
2、将oom时的内存快照dump下来，使用MAT或者visualvm进行分析

​

确实有很多类被加载了

3、分析gc日志

由于metaspace太小 导致频繁fullgc

4、查看线上对JVM的监控

查看从部署到OOM期间 fullGC次数、metaspace使用情况
结合突增的时间点查看当时的rpc请求、MQ消费等

5、新增两个JVM参数 -XX:+TraceClassLoading -XX:+TraceClassUnloading，观察是什么类创建比较频繁
但是log4j std.log并没有打印出来，需要将结果输出出来

形如这种参数： java -XX:+TraceClassLoading -jar demo-0.0.1-SNAPSHOT.jar > /Users/detail.log

将控制台信息输出到detail.log

而项目中的脚本是这样的 java [jvm参数] -jar xx.jar 2>&1 ，需要改动一下

6、对有改动的代码进行压测 看是否能复现
暂时没有复现

2021-05-24 更新：
使用了新的分析工具Jprofile对之前的内存文件进行分析
可以进行引用源头分析

总结

1、-XX:MetaspaceSize参数
这个参数的含义是 当Metaspace的使用达到size值时，会触发fullgc。
所以这个值如果太小，在项目启动的时候加载的类太多，就会fullgc，导致启动变慢

2、对于项目确实要加载很多类的情形，需要根据实际情况设置
-XX：MaxMetaspaceSize

3、-XX:+UnlockDiagnosticVMOptions,方便后续对JVM情况观察

jcmd 238794  GC.class_stats
238794:
GC.class_stats command requires -XX:+UnlockDiagnosticVMOptions