解決伺服器程序退出問題(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退出 只能/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表示式的地方都會生成一個如xxLambda$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,會影響到玩家體驗,可能會造成流失.
看完三件事❤️
如果你覺得這篇內容對你還蠻有幫助,我想邀請你幫我三個小忙:
-
點贊,轉發,有你們的 『點贊和評論』,才是我創造的動力。
-
關注公眾號 『 java爛豬皮 』,不定期分享原創知識。
-
同時可以期待後續文章ing