JVM metaspace outofmemory

作者: landon30 | 来源:发表于2018-09-14 17:53 被阅读0次

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

现象
- 策划反应服务器进不去,远程看了一下进程消失了(crash)
- 有时候也会出现能登录，但是无法执行操作(进程还在),无法被正常shutdown
- 进程根目录下出现了java_pid16298.hprof文件，一看到就是内存溢出了
  - 觉得奇怪，应该不会是堆内存溢出，因为人数不多，初步怀疑是永久区溢出(Java8#Metaspace)，下面果然得到验证
- 因为启动参数加了-XX:+HeapDumpOnOutOfMemoryError
- 还出现了hs_err_pid.log，即JVM致命错误日志
日志查询(vim/grep/less/more)
- vim std.log
  - esc /OutOfMemoryError ?OutOfMemoryError
  - n/N 下一个
- less std.log | grep OutOfMemoryError
  - Caused by: java.lang.OutOfMemoryError: Metaspace
- grep OutOfMemory std.log -A 50 -B 50 | less
  - /OutOfMemoryError n 下一个 q退出
- less std.log
  - 出现冒号 /OutOfMemoryError 搜索 q退出也可以?OutOfMemoryError
- more std.log
  - /OutOfMemoryError 搜索 q退出只能/
从日志输出上看是: 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<T> 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)
    - 关于反射调用方法的一个log
      - 网上有很多内容是关于因为这个的内存溢出问题,可以自行搜索查阅
    - 目前业务逻辑中频繁调用反射的地方
      - handler逻辑方法的反射执行
      - protobuf的反序列化
      - 其他三方库的反射等
- 工具使用
  - jvisualvm#载入hprof#可安装插件
    - 从两个个hprof看,均是差不多载入了7700多个类的时候抛出了内存溢出错误
    - OQL控制台#右下方#保存的查询#PermGen分析#类加载器类型
    - 发现了一个有意思的:发现了大量的xx143这样的类
      - 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
      - 主要的几个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.
      - system class loader#2617
    - 这里解释一下
      - 为什么这里是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也会生成相应的类
总结-2017.9.28
- 因为进程crash的代价很大，虽然可以设置一个较大的metaspace,但是如果泄露了，进程直接crash，影响会非常大
  - 所以还是建议不设置这个参数，jvm自己调节。如果真出现了泄露，那么内存会一直疯长的
  - 而此时我们的运维监控系统是可以监听到的，可以即时报警，然后走正常的shutdown(shutdown之前可以jmap hprof)，然后排查问题.
  - ps:OutOfMemory crash的时候会执行shutdownhook的,不过虽然如此但是进程突然crash,会影响到玩家体验，可能会造成流失.
std.log

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]

hs_err_pid.log

Stack: [0x00007f03927ff000,0x00007f0392900000],  sp=0x00007f03928fe340,  free space=1020k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0xaaca9a]  VMError::report_and_die()+0x2ba
V  [libjvm.so+0x4f2de9]  report_fatal(char const*, int, char const*)+0x59
V  [libjvm.so+0xab3d6a]  VMThread::execute(VM_Operation*)+0x2ca
V  [libjvm.so+0x47ecf0]  CollectorPolicy::satisfy_failed_metadata_allocation(ClassLoaderData*, unsigned long, Metaspace::MetadataType)+0x150
V  [libjvm.so+0x8928c5]  Metaspace::allocate(ClassLoaderData*, unsigned long, bool, MetaspaceObj::Type, Thread*)+0x315
V  [libjvm.so+0x8a5a26]  MethodCounters::allocate(ClassLoaderData*, Thread*)+0x26
V  [libjvm.so+0x89d811]  Method::build_method_counters(Method*, Thread*)+0x71
V  [libjvm.so+0x8a01f0]  BreakpointInfo::set(Method*)+0x3a0
V  [libjvm.so+0x796cd6]  JvmtiBreakpoint::each_method_version_do(void (Method::*)(int))+0x56
V  [libjvm.so+0xab5ac5]  VM_Operation::evaluate()+0x55
V  [libjvm.so+0xab3e9a]  VMThread::evaluate_operation(VM_Operation*)+0xba
V  [libjvm.so+0xab421e]  VMThread::loop()+0x1ce
V  [libjvm.so+0xab4690]  VMThread::run()+0x70
V  [libjvm.so+0x910ee8]  java_start(Thread*)+0x108

java visualvm#载入信息

 生成的日期: 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

lambda$

com.xx.achilles.spurs.gs.model.combat.CombatService$$Lambda$143
com.xx.achilles.spurs.gs.model.raid.daily.DailyRaidManager$$Lambda$142
com.xx.achilles.spurs.gs.model.daily.DailyManager$$Lambda$141
...

mat#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
------------------------------------------------------------------------------------------
...

sun.reflect.GeneratedMethodAccessor

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
...
----------------------------------------------------------------------------------------

sun.reflect.DelegatingClassLoader

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
----------------------------------------------------------------------------------------------------

JVM metaspace outofmemory

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

相关文章

网友评论

延伸阅读

深度阅读

栏目导航

热点阅读