解決服務(wù)器進(jìn)程退出問題(metaspace溢出)

• 現(xiàn)象
  • 策劃反應(yīng)服務(wù)器進(jìn)不去,遠(yuǎn)程看了一下進(jìn)程消失了(crash)
  • 有時(shí)候也會(huì)出現(xiàn)能登錄，但是無法執(zhí)行操作(進(jìn)程還在),無法被正常shutdown
  • 進(jìn)程根目錄下出現(xiàn)了java_pid16298.hprof文件扶叉，一看到就是內(nèi)存溢出了
    • 覺得奇怪咧叭，應(yīng)該不會(huì)是堆內(nèi)存溢出履婉，因?yàn)槿藬?shù)不多欠啤，初步懷疑是永久區(qū)溢出(Java8#Metaspace)，下面果然得到驗(yàn)證
  • 因?yàn)閱?dòng)參數(shù)加了-XX:+HeapDumpOnOutOfMemoryError
  • 還出現(xiàn)了hs_err_pid.log斋竞，即JVM致命錯(cuò)誤日志
• 日志查詢(vim/grep/less/more)
  • vim std.log
    • esc /OutOfMemoryError ?OutOfMemoryError
    • n/N 下一個(gè)
  • less std.log | grep OutOfMemoryError
    • Caused by: java.lang.OutOfMemoryError: Metaspace
  • grep OutOfMemory std.log -A 50 -B 50 | less
    • /OutOfMemoryError n 下一個(gè) q退出
  • less std.log
    • 出現(xiàn)冒號(hào) /OutOfMemoryError 搜索 q退出 也可以?OutOfMemoryError
  • more std.log
    • /OutOfMemoryError 搜索 q退出 只能/
• 從日志輸出上看是: Metaspace內(nèi)存溢出,我這邊啟動(dòng)參數(shù)設(shè)置的大小是48M
  • -XX:MaxMetaspaceSize=48m
• 從致命日志的輸出看:也是jvm在Metaspace::allocate時(shí)出現(xiàn)了致命錯(cuò)誤
  • Metaspace used 47519K, capacity 48950K, committed 49152K, reserved 1093632K...
  • 也能看到類似日志 發(fā)現(xiàn)確實(shí)Metaspace幾乎已被占滿
• why?
  • Metaspace概念理解
    • JVM源碼分析之Metaspace解密
    • java7和java8中部分原來在permgen的數(shù)據(jù)已經(jīng)被轉(zhuǎn)移到堆
    • 從JDK7開始永久代的移除工作钻蔑，貯存在永久代的一部分?jǐn)?shù)據(jù)已經(jīng)轉(zhuǎn)移到了Java Heap或者是Native Heap啥刻。但永久代仍然存在于JDK7，并沒有完全的移除：符號(hào)引用(Symbols)轉(zhuǎn)移到了native heap;字面量(interned strings)轉(zhuǎn)移到了java heap;類的靜態(tài)變量(class statics)轉(zhuǎn)移到了java heap
    • In JDK 8, classes metadata is now stored in the native heap and this space is called Metaspace.
  • 哪些占用了空間(個(gè)人分析 主要是生成的類)
    • fastjson#asm(通過debug調(diào)試)
      • deserializer
        • ASMDeserializerFactory#createJavaBeanDeserializer
        • 當(dāng)調(diào)用如JSON#parseObject(String text, Class<T> clazz),都會(huì)生成一個(gè)和clazz對(duì)應(yīng)的如FastjsonASMDeserializer_53_xx類,用來進(jìn)行反序列化
        • 目前用到的地方包括配置文件,數(shù)據(jù)表,玩家相關(guān)數(shù)據(jù)等
      • serializer
        • ASMSerializerFactory#createJavaBeanSerializer
        • 當(dāng)調(diào)用如JSON.toJSONString(Object object),也會(huì)生成一個(gè)和object#clazz對(duì)應(yīng)的如ASMSerializer_1_xx類咪笑，用來write/序列化
      • 二者加起來大約200個(gè)左右
    • lambda表達(dá)式內(nèi)部類
      • 所有使用lambda表達(dá)式的地方都會(huì)生成一個(gè)如xx1的類 大約150個(gè)左右
    • 其他如protobuf生成的類,大約200多個(gè)
    • 其他查看了一下$的內(nèi)部類可帽，也未發(fā)現(xiàn)有特殊的如生成的類
    • 搜索包含數(shù)字的類，因?yàn)橥ǔ?dòng)態(tài)生成的類似都有數(shù)字等
      • 發(fā)現(xiàn)了大量的sun.reflect.GeneratedMethodAccessor344...
      • 大概有350多個(gè),同時(shí)發(fā)現(xiàn)了有同樣數(shù)目的sun.reflect.DelegatingClassLoader(是只有一個(gè)類窗怒，只不過有對(duì)應(yīng)數(shù)目的實(shí)例)..
      • 同樣sun.reflect.GeneratedConstructorAccessor...
      • 分析-這個(gè)是是反射的優(yōu)化,It can use a JNI accessor, or a Java bytecode accessor
        • JVM剛開始默認(rèn)使用JNI的方式調(diào)用映跟，當(dāng)同一個(gè)類調(diào)用次數(shù)達(dá)到一定值后改為Java bytecode調(diào)用(會(huì)有一個(gè)新的classloader和一個(gè)clazz)
      • 關(guān)于反射調(diào)用方法的一個(gè)log
        • 網(wǎng)上有很多內(nèi)容是關(guān)于因?yàn)檫@個(gè)的內(nèi)存溢出問題,可以自行搜索查閱
      • 目前業(yè)務(wù)邏輯中頻繁調(diào)用反射的地方
        • handler邏輯方法的反射執(zhí)行
        • protobuf的反序列化
        • 其他三方庫的反射等
  • 工具使用
    • jvisualvm#載入hprof#可安裝插件
      • 從兩個(gè)個(gè)hprof看,均是差不多載入了7700多個(gè)類的時(shí)候拋出了內(nèi)存溢出錯(cuò)誤
      • OQL控制臺(tái)#右下方#保存的查詢#PermGen分析#類加載器類型
      • 發(fā)現(xiàn)了一個(gè)有意思的:發(fā)現(xiàn)了大量的xx143這樣的類
        • Lambda表達(dá)式是要生成內(nèi)部類的
        • 從輸出看,Lambda表達(dá)式生成的內(nèi)部類編號(hào)是從1開始蓄拣，然后++
        • 目前看到的有151個(gè)Lambda內(nèi)部類
      • 可直接在類信息下面搜索匹配
    • 使用mat
      • open heap dump
        • Size: 22.6 MB Classes: 7.5k Objects: 578k Class Loader: 357
      • JavaBasics#class loader explorer

        • 主要的幾個(gè)classloader#sun.misc.Launch$ExtClassLoader#defined class 4312

        • com.alibaba.fastjson.util.ASMClassLoader(Deserializer_)#129
          > com.alibaba.fastjson.parser.deserializer.FastjsonASMDeserializer_53_xxConfig,這里需要排查為什么所有的Config對(duì)象都被生成了反序列化的內(nèi)部類?還有其他如xx_RedisConfig等(了解fastjson#asm原理即可)

          com.alibaba.fastjson.serializer.ASMSerializer_70_xxConfig
          這里看了代碼發(fā)現(xiàn)有一個(gè)xxMonsterConfig,這個(gè)是在序列化到redis的時(shí)候沒有加SerializerFeature.IgnoreNonFieldGetter,序列化mongo的player已經(jīng)統(tǒng)一加上了這個(gè)feature.

        • system class loader#2617

      • 這里解釋一下
        • 為什么這里是ExtClassLoader加載了業(yè)務(wù)中的大部分類
        • 因?yàn)槲疫@邊啟動(dòng)是用-Djava.ext.dirs=lib,即ExtClassLoader加載的，而非AppClassLoader
    • 二者都可以使用OQL
      • OQL Syntax
      • SELECT DISTINCT OBJECTS classof(s) FROM "com.xx.*" s
        • 查詢對(duì)象所屬的類在com.xx包下
        • 大約有600多個(gè)
• 總結(jié)和解決辦法
  • 從上面分析看,確實(shí)應(yīng)該是metaspace分配的空間過少 48M 準(zhǔn)備調(diào)整為128M 再實(shí)際跑跑測(cè)試
  • Lambda表達(dá)式會(huì)生成內(nèi)部類
  • 反射調(diào)用頻繁JVM也會(huì)生成相應(yīng)的類
• 總結(jié)-2017.9.28
  • 因?yàn)檫M(jìn)程crash的代價(jià)很大努隙，雖然可以設(shè)置一個(gè)較大的metaspace,但是如果泄露了球恤，進(jìn)程直接crash，影響會(huì)非常大
    • 所以還是建議不設(shè)置這個(gè)參數(shù)荸镊，jvm自己調(diào)節(jié)咽斧。如果真出現(xiàn)了泄露，那么內(nèi)存會(huì)一直瘋長的
    • 而此時(shí)我們的運(yùn)維監(jiān)控系統(tǒng)是可以監(jiān)聽到的躬存，可以即時(shí)報(bào)警张惹，然后走正常的shutdown(shutdown之前可以jmap hprof)，然后排查問題.
    • ps:OutOfMemory crash的時(shí)候會(huì)執(zhí)行shutdownhook的,不過雖然如此但是進(jìn)程突然crash,會(huì)影響到玩家體驗(yàn)岭洲，可能會(huì)造成流失.
• 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

    字節(jié)總數(shù): 47,508,830
    類總數(shù): 7,743
    實(shí)例總數(shù): 568,577
    類加載器: 380
    垃圾回收根節(jié)點(diǎn): 2,703
    等待結(jié)束的暫掛對(duì)象數(shù): 0

    在出現(xiàn) OutOfMemoryError 異常錯(cuò)誤時(shí)進(jìn)行了堆轉(zhuǎn)儲(chǔ)
    導(dǎo)致 OutOfMemoryError 異常錯(cuò)誤的線程: 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
----------------------------------------------------------------------------------------------------