雙12壓測引出的線上Full GC排查

這個(gè)Full GC問題是去年雙12壓測的時(shí)候觸發(fā)的，中間排查的過程和踩的坑給大家借鑒一下。

線上問題

雙12之前壓測的時(shí)候起了很小的量，直接觸發(fā)了Full GC，嚇尿了，因?yàn)轳R上雙12大促預(yù)熱就要開始了，這搞不好妥妥的3.25啦。

趕緊拉群，把相關(guān)同學(xué)拉在一起排查問題。

第一時(shí)間查看GC日志：

可以看到原因是超過了Metadata GC的閾值，觸發(fā)了Full GC，Metaspace從243M 回收到231M，基本沒怎么回收掉，所以稍微再來點(diǎn)量，很容易再次觸發(fā)Metaspace 的回收。

知識儲備

GC問題排查需要很多儲備知識，最主要是JVM相關(guān)的，之前文章已經(jīng)講過一些了，這里主要講Matespace是什么？后面講怎么做的GC問題的排查。

這里有二個(gè)知識點(diǎn)：

• Matespace（元空間）是什么？在JVM中扮演什么角色，也就是存放什么的？
• Full GC跟Matespace 大小設(shè)置有什么關(guān)系？

Matespace叫做元空間，從JDK 8開始，永久代(PermGen)的概念被廢棄掉了，取而代之的是一個(gè)稱為Metaspace的存儲空間。

Metaspace用來存放：Class文件在JVM 里的運(yùn)行時(shí)數(shù)據(jù)結(jié)構(gòu)；以及存Klass相關(guān)的其他的內(nèi)容，比如Method，ConstantPool等。

Metaspace使用的是本地內(nèi)存，而不是堆內(nèi)存，也就是說在默認(rèn)情況下Metaspace的大小只與本地內(nèi)存大小有關(guān)。但是很容易有個(gè)誤區(qū)是Matespace可以隨便用，不管使用多少，只要不超本地內(nèi)存就不會觸發(fā)GC，這是錯(cuò)誤的。

Matespace的設(shè)置方式是：-XX: MetaspaceSize=**M, 這個(gè)JVM參數(shù)的作用是讓Matespace 達(dá)到MetaspaceSize時(shí)觸發(fā)Full GC, 如果不設(shè)置Matespace, 默認(rèn)值很小，也就 20M左右(不同系統(tǒng)會有一點(diǎn)差別)，如果程序Load Class比較多，很容易觸發(fā)Full GC。這里要明白的是Class信息和加載Class 的ClassLoader 都存放在Metaspace，我們知道一個(gè)類是由這個(gè)類的類加載器加上全限定名（由包名&類名組成）確定唯一性的。

所以大家可以檢查一下自己應(yīng)用JVM Metaspace 設(shè)置的大小，如果沒設(shè)置可以通過 -XX:+PrintFlagsInitial 查看一下默認(rèn)值。

（之前文章發(fā)過GC日志的詳細(xì)講解以及JVM 參數(shù)的配置說明，如果有疑問的同學(xué)可以去看看歷史文章。）

問題排查

剛開始看到 Full GC頻繁，查看日志是由于Metaspace 空間不夠造成的，第一反應(yīng)是調(diào)整Metaspace 大小，把MetaspaceSize 從256M提高到了512M。但是發(fā)現(xiàn)Metaspace引發(fā)的Full GC還是沒有消除。

立即dump了二臺機(jī)器的日志，第一次分析GC 日志文件，沒發(fā)現(xiàn)異常，這里有個(gè)注意的地方，大家dump文件時(shí)機(jī)很重要，有時(shí)候dump 的GC 日志沒問題是因?yàn)閯偤?Full GC完成之后dump的，內(nèi)存回收的干干凈凈，有些內(nèi)存緩慢增加的問題一定要在Full GC前dump。

期間我們還發(fā)現(xiàn)緩存相關(guān)的對象占用內(nèi)存較高，但是經(jīng)過分析，緩存對象生命周期本身就比較長，所以常駐在堆上，沒有問題，繼續(xù)看。

排查發(fā)現(xiàn)Metaspace內(nèi)存占用是隨著雙12新接口壓測流量的增長而增長，所以可以確定是新接口代碼引入。

分析GC dump日志發(fā)現(xiàn)可疑點(diǎn)，同一個(gè)ClassCloader 加載了接近3000個(gè)，如下圖所示，前面我們說過，ClassCloader 信息在Metaspace 區(qū)域。

破案了，fastjson使用不當(dāng)引入了ASM Serializer的坑。

故障定位&修復(fù)

FastJson之所以快，原因就是使用asm字節(jié)碼增強(qiáng)替代了反射。所以肯定是代碼中應(yīng)用了fastjson的ASM處理數(shù)據(jù)時(shí)造成的頻繁加載同一個(gè)類，基本問題清楚了，那就是擼代碼了，很快就定位了問題代碼。

因?yàn)楸Ｃ茉颍环奖惴旁即a，安琪拉擼了個(gè)類似邏輯的代碼：

for(Item item -> arrays) {
  SerializeConfig serializeConfig = new SerializeConfig();
   serializeConfig.put(Custom.class, new CustomSerializer());
   jsonString = JSON.toJSONString(item, serializeConfig);
}

這段代碼是自定義了一個(gè)序列化實(shí)現(xiàn)類CustomSerializer，在進(jìn)行序列化時(shí)進(jìn)行了一個(gè)類似AOP的切面處理，對所有Custom類型的字段進(jìn)行統(tǒng)一自定義序列化（使用CustomSerializer）。

實(shí)現(xiàn)原理上是對需要序列化的Class使用asm動態(tài)生成了代理類，在這里就是Item類，使用SerializeConfig配置動態(tài)生成字節(jié)碼代理類: com.alibaba.fastjson.serializer.ASMSerializer_1_Item，但是每次new SerializeConfig對象（內(nèi)存地址不一樣），F(xiàn)astJson會當(dāng)作每次代理的目標(biāo)是不一樣的，導(dǎo)致每次會使用一個(gè)新的類加載器ASMClassLoader，所以Metaspace很快就滿了，觸發(fā)了頻繁Full GC。

如果希望深入研究可以看下FastJson源碼：

com.alibaba.fastjson.serializer.SerializeConfig#createASMSerializer

問題修復(fù)：

注冊O(shè)bjectSerializer，讓ObjectSerializer 成為全局唯一的，相當(dāng)于是單例的。

SerializeConfig.getGlobalInstance().put(Character.class, new CharacterSerializer());

SerializeConfig 改成單例的后，每次序列化不用重復(fù)加載。

類似問題排查 & 調(diào)優(yōu)

1. 如果dump 日志發(fā)現(xiàn)很多classloader 名稱前綴相同，排查是否有這種動態(tài)代理技術(shù)的使用，可能在不斷生成代理對象。
2. 發(fā)現(xiàn)內(nèi)存緩慢增長，GC回收不掉，dump GC日志，查看是否有類被重復(fù)加載；
3. Metaspace調(diào)優(yōu)，比如我們現(xiàn)在生產(chǎn)環(huán)境 Metaspace 基本會設(shè)置256M 或者512M，可以根據(jù)應(yīng)用的類型和機(jī)器內(nèi)存配置來決定，因素：1. 是否會加載比較多的類，2. 機(jī)器內(nèi)存允許, 可以適當(dāng)調(diào)大Metaspace。

以上就是雙12壓測GC問題完整的排查方法論、詳細(xì)過程和解決方案。

已是深夜，碼字不易，如果覺得看完有那么一點(diǎn)點(diǎn)收獲，可以分享和轉(zhuǎn)發(fā)，你輕輕的一個(gè)轉(zhuǎn)發(fā)，是對作者最大的鼓勵(lì)，筆芯！