性能文章>解决服务器进程退出问题(metaspace溢出)实战>

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

1年前
713018

现象

策划反应服务器进不去,远程看了一下进程消失了(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,会影响到玩家体验,可能会造成流失.

请先登录,再评论

metaspace我一般都是先给512MB,上线运行稳定一段时间后以后看一下实际used多少,然后下次上线再调整

11年前

为你推荐

不起眼,但是足以让你有收获的JVM内存分析案例
分析 这个问题说白了,就是说有些int[]对象不知道是哪里来的,于是我拿他的例子跑了跑,好像还真有这么回事。点该 dump 文件详情,查看相关的 int[] 数组,点该对象的“被引用对象”,发现所
从一起GC血案谈到反射原理
前言 首先回答一下提问者的问题。这主要是由于存在大量反射而产生的临时类加载器和 ASM 临时生成的类,这些类会被保留在 Metaspace,一旦 Metaspace 即将满的时候,就会触发 Fu
关于内存溢出,咱再聊点有意思的?
概述 上篇文章讲了JVM在GC上的一个设计缺陷,揪出一个导致GC慢慢变长的JVM设计缺陷,可能有不少人还是没怎么看明白的,今天准备讲的大家应该都很容易看明白 本文其实很犹豫写不写,因为感觉没有
协助美团kafka团队定位到的一个JVM Crash问题
概述 有挺长一段时间没写技术文章了,正好这两天美团kafka团队有位小伙伴加了我微信,然后咨询了一个JVM crash的问题,大家对crash的问题都比较无奈,因为没有现场,信息量不多,碰到这类问题我
又发现一个导致JVM物理内存消耗大的Bug(已提交Patch)
概述 最近我们公司在帮一个客户查一个JVM的问题(JDK1.8.0_191-b12),发现一个系统老是被OS Kill掉,是内存泄露导致的。在查的过程中,阴差阳错地发现了JVM另外的一个Bug。这个B
JVM实战:优化我的IDEA GC
IDEA是个好东西,可以说是地球上最好的Java开发工具,但是偶尔也会卡顿,仔细想想IDEA也是Java开发的,会不会和GC有关,于是就有了接下来对IDEA的GC进行调优 IDEA默认JVM参数: -
不起眼,但是足以让你收获的JVM内存案例
今天的这个案例我觉得应该会让你涨姿势吧,不管你对JVM有多熟悉,看到这篇文章,应该还是会有点小惊讶的,不过我觉得这个案例我分享出来,是想表达不管多么奇怪的现象请一定要追究下去,会让你慢慢变得强大起来,
谨防JDK8重复类定义造成的内存泄漏
概述 如今JDK8成了主流,大家都紧锣密鼓地进行着升级,享受着JDK8带来的各种便利,然而有时候升级并没有那么顺利?比如说今天要说的这个问题。我们都知道JDK8在内存模型上最大的改变是,放弃了Perm