20

解决服务器进程退出问题(metaspace溢出)实战

 3 years ago
source link: https://club.perfma.com/article/1926136
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.

现象

策划反应服务器进不去,远程看了一下进程消失了(crash),有时候也会出现能登录,但是无法执行操作(进程还在),无法被正常shutdown,进程根目录下出现了 java_pid16298.hprof 文件,一看到就是内存溢出了,觉得奇怪,应该不会是堆内存溢出,因为人数不多,初步怀疑是永久区溢出(Java8#Metaspace),下面果然得到验证,因为启动参数加了 -XX:+HeapDumpOnOutOfMemoryError ,还出现了 hs_err_pid.log ,即JVM致命错误日志。

日志查询(vim/grep/less/more)

  1. vim std.log
    esc /OutOfMemoryError ?OutOfMemoryError
    n/N 下一个
  2. less std.log | grep OutOfMemoryError
    Caused by: java.lang.OutOfMemoryError: Metaspace
  3. grep OutOfMemory std.log -A 50 -B 50 | less
    /OutOfMemoryError n 下一个 q退出
  4. less std.log
    出现冒号 /OutOfMemoryError 搜索 q退出 也可以?OutOfMemoryError
  5. more std.log
    /OutOfMemoryError 搜索 q退出 只能/
Caused by: java.lang.OutOfMemoryError: Metaspace
        at java.lang.ClassLoader.defineClass1(Native Method) ~[na:1.8.0_40]
        at java.lang.ClassLoader.defineClass(ClassLoader.java:760) ~[na:1.8.0_40]
        at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142) ~[na:1.8.0_40]
        at java.net.URLClassLoader.defineClass(URLClassLoader.java:467) ~[na:1.8.0_40]
        at java.net.URLClassLoader.access$100(URLClassLoader.java:73) ~[na:1.8.0_40]
        at java.net.URLClassLoader$1.run(URLClassLoader.java:368) ~[na:1.8.0_40]
        at java.net.URLClassLoader$1.run(URLClassLoader.java:362) ~[na:1.8.0_40]
        at java.security.AccessController.doPrivileged(Native Method) ~[na:1.8.0_40]
        at java.net.URLClassLoader.findClass(URLClassLoader.java:361) ~[na:1.8.0_40]
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[na:1.8.0_40]
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[na:1.8.0_40]
复制

从日志输出上看是: Metaspace内存溢出,我这边启动参数设置的大小是48M

-XX:MaxMetaspaceSize=48m

从致命日志的输出看:也是jvm在Metaspace::allocate时出现了致命错误 Metaspace used 47519K , capacity 48950K , committed 49152K , reserved 1093632K …也能看到类似日志 发现确实Metaspace几乎已被占满。

why?

Metaspace概念理解: JVM源码分析之Metaspace解密

java7和java8中部分原来在permgen的数据已经被转移到堆,从JDK7开始永久代的移除工作,贮存在永久代的一部分数据已经转移到了Java Heap或者是Native Heap。但永久代仍然存在于JDK7,并没有完全的移除:符号引用(Symbols)转移到了native heap;字面量(interned strings)转移到了java heap;类的静态变量(class statics)转移到了java heap。

In JDK 8, classes metadata is now stored in the native heap and this space is called Metaspace.

哪些占用了空间(个人分析 主要是生成的类)

fastjson#asm(通过debug调试)

  • deserializer

ASMDeserializerFactory#createJavaBeanDeserializer ,当调用如 JSON#parseObject(String text, Class clazz) ,都会生成一个和clazz对应的如 FastjsonASMDeserializer_53_xx 类,用来进行反序列化,目前用到的地方包括配置文件,数据表,玩家相关数据等。

  • serializer

ASMSerializerFactory#createJavaBeanSerializer,当调用如JSON.toJSONString(Object object),也会生成一个和object#clazz对应的如ASMSerializer_1_xx类,用来write/序列化。

二者加起来大约200个左右。

lambda表达式内部类,所有使用lambda表达式的地方都会生成一个如xx$Lambda$1的类 大约150个左右,其他如protobuf生成的类,大约200多个,其他查看了一下$的内部类,也未发现有特殊的如生成的类,搜索包含数字的类,因为通常动态生成的类似都有数字等,发现了大量的 sun.reflect.GeneratedMethodAccessor344 …大概有350多个,同时发现了有同样数目的sun.reflect.DelegatingClassLoader(是只有一个类,只不过有对应数目的实例)…,同样 sun.reflect.GeneratedConstructorAccessor …分析-这个是是反射的优化, It can use a JNI accessor, or a Java bytecode accessor
JVM刚开始默认使用JNI的方式调用,当同一个类调用次数达到一定值后改为Java bytecode调用(会有一个新的classloader和一个clazz)

网上有很多内容是关于因为这个的内存溢出问题,可以自行搜索查阅

目前业务逻辑中频繁调用反射的地方:

  • handler逻辑方法的反射执行
  • protobuf的反序列化
  • 其他三方库的反射等

工具使用

jvisualvm#载入hprof#可安装插件

 生成的日期: Mon Sep 25 14:30:30 CST 2017
    文件: D:\xx\landon\task\2017.9\server_err\java_pid16298.hprof
    文件大小: 56.1 MB

    字节总数: 47,508,830
    类总数: 7,743
    实例总数: 568,577
    类加载器: 380
    垃圾回收根节点: 2,703
    等待结束的暂挂对象数: 0

    在出现 OutOfMemoryError 异常错误时进行了堆转储
    导致 OutOfMemoryError 异常错误的线程: queue-executor-handler-8
复制

从两个个hprof看,均是差不多载入了7700多个类的时候抛出了内存溢出错误,OQL控制台#右下方#保存的查询#PermGen分析#类加载器类型,发现了一个有意思的:发现了大量的xx$Lambda$143这样的类,Lambda表达式是要生成内部类的,从输出看,Lambda表达式生成的内部类编号是从1开始,然后++,目前看到的有151个Lambda内部类,可直接在类信息下面搜索匹配。

使用mat

open heap dump

Size: 22.6 MB Classes: 7.5k Objects: 578k Class Loader: 357

JavaBasics#class loader explorer

Class Name                                           | Defined Classes | No. of Instances
------------------------------------------------------------------------------------------
sun.misc.Launcher$ExtClassLoader @ 0x800230b0        |           4,312 |           93,289
<system class loader>                                |           2,617 |          484,122
com.alibaba.fastjson.util.ASMClassLoader @ 0x805fd848|             129 |              129
com.alibaba.fastjson.util.ASMClassLoader @ 0x805e2858|              73 |               73
------------------------------------------------------------------------------------------
复制
Class Name                                               | Shallow Heap | Retained Heap
----------------------------------------------------------------------------------------
class sun.reflect.GeneratedMethodAccessor344 @ 0x80593e18|            0 |           568
class sun.reflect.GeneratedMethodAccessor343 @ 0x80593ee0|            0 |           568
class sun.reflect.GeneratedMethodAccessor342 @ 0x80593fa8|            0 |           568
class sun.reflect.GeneratedMethodAccessor341 @ 0x80594070|            0 |           568
class sun.reflect.GeneratedMethodAccessor340 @ 0x80594138|            0 |           568
class sun.reflect.GeneratedMethodAccessor339 @ 0x80594200|            0 |           568
class sun.reflect.GeneratedMethodAccessor338 @ 0x805942c8|            0 |           568
class sun.reflect.GeneratedMethodAccessor337 @ 0x80594390|            0 |           568
class sun.reflect.GeneratedMethodAccessor336 @ 0x80594458|            0 |           568
...
----------------------------------------------------------------------------------------
复制
Class Name                                                     | Defined Classes | No. of Instances
----------------------------------------------------------------------------------------------------
sun.misc.Launcher$ExtClassLoader @ 0x800230b0                  |           4,312 |           93,289
<system class loader>                                          |           2,617 |          484,122
com.alibaba.fastjson.util.ASMClassLoader @ 0x805fd848          |             129 |              129
com.alibaba.fastjson.util.ASMClassLoader @ 0x805e2858          |              73 |               73
javax.management.remote.rmi.NoCallStackClassLoader @ 0x806fc4f8|               1 |                0
javax.management.remote.rmi.NoCallStackClassLoader @ 0x806fc5d0|               1 |                0
sun.reflect.DelegatingClassLoader @ 0x80593db8                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x80593e80                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x80593f48                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x80594010                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x805940d8                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x805941a0                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x80594268                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x80594330                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x805943f8                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x805944c0                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x80594588                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x80594650                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x805947c8                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x80594890                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x80594958                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x80594a20                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x80594ae8                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x80594bb0                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x80594c78                 |               1 |                1
sun.reflect.DelegatingClassLoader @ 0x80594d40                 |               1 |                1
----------------------------------------------------------------------------------------------------

复制

主要的几个 classloader#sun.misc.Launch$ExtClassLoader#defined class 4312

com.alibaba.fastjson.util.ASMClassLoader(Deserializer_)#129

com.alibaba.fastjson.parser.deserializer.FastjsonASMDeserializer_53_xxConfig,这里需要排查为什么所有的Config对象都被生成了反序列化的内部类?还有其他如xx_RedisConfig等(了解fastjson#asm原理即可)

com.alibaba.fastjson.serializer.ASMSerializer_70_xxConfig

这里看了代码发现有一个xxMonsterConfig,这个是在序列化到redis的时候没有加SerializerFeature.IgnoreNonFieldGetter,序列化mongo的player已经统一加上了这个feature.

这里解释一下为什么这里是ExtClassLoader加载了业务中的大部分类,因为我这边启动是用-Djava.ext.dirs=lib,即ExtClassLoader加载的,而非AppClassLoader,二者都可以使用OQL,OQL Syntax,SELECT DISTINCT OBJECTS classof(s) FROM “com.xx.*” s

查询对象所属的类在com.xx包下大约有600多个。

总结和解决办法

从上面分析看,确实应该是metaspace分配的空间过少 48M 准备调整为128M 再实际跑跑测试

  • Lambda表达式会生成内部类
  • 反射调用频繁JVM也会生成相应的类

总结

因为进程crash的代价很大,虽然可以设置一个较大的metaspace,但是如果泄露了,进程直接crash,影响会非常大

所以还是建议不设置这个参数,jvm自己调节。如果真出现了泄露,那么内存会一直疯长的

而此时我们的运维监控系统是可以监听到的,可以即时报警,然后走正常的shutdown(shutdown之前可以jmap hprof),然后排查问题.

ps:OutOfMemory crash的时候会执行shutdownhook的,不过虽然如此但是进程突然crash,会影响到玩家体验,可能会造成流失.


About Joyk


Aggregate valuable and interesting links.
Joyk means Joy of geeK