fastJson 與一起堆內存溢出'血案'

現象

• QA同學反映登錄不上服務器

排查問題1–日志級別

• 查看log,發現玩家登錄的時候拋出了一個java.lang.OutOfMemoryError

• 大概代碼是向Redis序列化一個PlayerMirror鏡像數據,但是在JSON.toJSONString的時候出現了錯誤.比較清晰，即序列化的時候expandCapacity,內存不足。

• 又看了一下日志，有好幾個OutOfMemoryError,都是類似於用fastjson序列化PlayerMirror報的錯誤

• 又仔細看了一下server目錄，發現了幾個.hprof,說明確實發生了堆內存溢出，因為啟動參數增加了’-XX:+HeapDumpOnOutOfMemoryError’

 

 

 

 

at java.lang.OutOfMemoryError.<init>()V (OutOfMemoryError.java:48)

at com.alibaba.fastjson.serializer.SerializeW

riter.expandCapacity(I)V (SerializeWriter.java:249)

 

 

 

 

 

 

 

 

-rw------- 1 xx xx 2043416350 Nov 24 11:37 java_pid8068.hprof

-rw------- 1 xx xx 2028797313 Nov 24 11:17 java_pid4671.hprof

-rw------- 1 xx xx 1477222612 Nov 23 23:25 java_pid31563.hprof

 

 

 

 

排查問題2–JVM命令級別

使用了jvm命令初步排查一下問題 jstat -gcutil pid

jstat -gc pid

jmap -histo pid

jmap -heap pid

jstat看到老年代基本已經滿了

jmap看到排名前兩位的分別是Object[]和char[]

 

 

 

num #instances #bytes class name

----------------------------------------------

1: 146219 741203672 [Ljava.lang.Object;

2: 2842356 639498168 [C

 

 

 

 

排查問題3–專業工具級別

因為了hprof,所以只需要用專業的內存分析工具mat即可 mat#Open Heap Dump,載入后直接出來一個Getting Started Wizard#Leak Suspects Report,即內存泄露的報告,選擇finish 兩個懷疑的問題:

• 其中有一個JSONArray的實例就占用了大約700M內存

• 另外一個是線程的local Variables占用了500M內存

 

 

點開問題1詳情，發現這個JSONArray是配置類PersonalityStrengthenConfig#cost字段，仔細看一下這個JSONArray#list#elementData的數組長度是可怕的183842095。

 

 

點開問題2詳情，第一張圖可以看到，fastjson內部的SerializeWriter中中buf#char[]長度竟然是可怕的262012306，而第二種圖的堆棧信息可以看到是在序列化PersonalityStrengthenConfig拋出的內存溢出。

 

 

 

結合兩個問題，比較能容易的想到答案，PersonalityStrengthenConfig中的cost字段(JSONArray)占用了大量的內存，而玩家下線或者上線的時候要序列化一部分數據到redis,其中就包括這個PersonalityStrengthenConfig，所以也要序列化這個超級大的cost，而序列化要申請空間，所以就內存溢出了。

分析問題1–觀察數據

為什么數據配置類PersonalityStrengthenConfig會被序列化呢，因為玩家下線的時候需要序列化一個玩家鏡像數據到redis Player->Hero->HeroPersonality->getConfig(PersonalityStrengthenConfig) HeroPersonality有一個get方法,而做序列化的這個同學忘記加了SerializerFeature.IgnoreNonFieldGetter這個參數，所以導致getConfig中的這個config對象被序列化進去了，修改完畢代碼后，所有的問題都沒有了。

需要確認一下:PersonalityStrengthenConfig#cost這個JsonArray為什么占這么大空間，能看一下里面都是什么？

在mat中懷疑的第一個懷疑報告中點擊PersonalityStrengthenConfig@0x8140c468對象,左側Inspector頁面有一個Attributes,找到cost右鍵->List Objects->with outgoing references

從下圖可以看到，這個JSONAray內部出了第一個元素是一個正常的JSONObject外，其他的全部為null，當然你可以從第二個懷疑報告中將SerializeWriter中的buf#char[]數據拷貝出來->單擊->Copy->Save Value to File.當然這個文件幾百M(且只有一行)，非常大，普通的文本編輯器根本看不出來(我在linux上使用了tail，然后不斷的ctrl+c 最終看到了數據的開頭),而這個數據也是當序列化到了config#cost字段時,只有一個正常的數據，其他后面全部為null，所以數據問題確認完畢:cost字段里面除了一個正常的JSONObject外，剩余的全部是null。

 

 

分析問題2–嘗試重現

最初的解決方法很簡單 嘗試通過代碼方式能否復現

即new一個HeroPersonality,其內部有一個getConfig,使用沒有加IgnoreNonFieldGetter的方式序列化,看是否會造成大內存的占用

很遺憾，未能復現

 

 

 

HeroPersonality hp = new HeroPersonality();

hp.setPersonalityLevel(1);

String str = JSON.toJSONString(hp);

 

 

 

 

然后嘗試還原數值表最近的幾個版本，看看是否有問題，這個就是懷疑策划配置表有問題 導致這個cost字段在某些特殊情況下會如可能在加載的時候就變的很大，不過很遺憾未能復現。

分析源代碼 確認是否可能啟動加載配置表后這個cost字段就很大

debug DataConfigService 發現的第一個問題是這個類混用了json-lib和fastjson(這個框架已更新，我們項目一直未更新)，這里懷疑是否是json-lib有bug，發現反序列化的過程是JSONLexer#掃描如大括號,逗號,方括號。先找到了配置表的的第一個JSONObject,然后加到cost數組(注意此時JSONArray#list的底層數組長度已經被expand到了長度10) 然后遇到RBRACKET,就結束掃描了。

看到這里就有一個想法 是否是有可能遇到了特殊字符,如fastjson中的循環引用

進而猜測到是否是策划配置的時候配置了公式？而且我也各種嘗試在json的cost字段加各種特殊字符，很遺憾，經過驗證 未能復現。

嘗試仔細看了一下堆快照，將PersonalityStrengthenConfig的10個對象內部數據都看了一下，和svn的策划表對比了一下，確認了是某個版本的數據。而這個版本的數據在本地測試是沒有任何問題的，排除策划配置數據問題。

分析問題3–山重水復疑無路

在我寫本地測試代碼重現的時候，我寫了一個反序列化HeroPersonality的例子，先用HeroPersonality序列化為一堆字符串,然后嘗試在這堆字符串加入一些額外信息,然后再反序列化，不經意的發現當進行一次HeroPersonality的反序列化后 再將原來的HeroPersonality再次序列化輸出時驚奇的發現序列化后的cost字段多了一個null，然后我就將反序列化代碼放在循環里 然后再次輸出 發現cost字段被加了很多null。

偽測試代碼

 

 

 

PersonalityStrengthenConfig config = DataConfigService.

getSettingById(PersonalityStrengthenConfig.class, 1);

 

System.out.println("dcs.config1:" + config.cost);

System.out.println("dcs.config1:" + config.attr_num);

 

for (int i = 0; i < 10; i++) {

String str1 = "{...}";

JSON.parseObject(str1, HeroPersonality.class);

}

 

System.out.println("dcs.config2:" + config.cost);

System.out.println("dcs.config2:" + config.attr_num);

 

 

 

 

結果輸出：

 

 

這個結果讓我驚喜，讓我非常的肯定，cost中的大量null就是這樣產生的,而且我最早就懷疑HeroPersonality中有一些非序列化的get方法有一些問題;而同樣的attr_num也是JSONArray類型，就沒有任何問題.問題初步鎖定在HeroPersonality中的一個get方法.

分析問題4–源代碼跟蹤

需要源代碼debug，為什么在不斷的調用反序列化的時候，cost被加入了大量的null，下面這個是HeroPersonality的兩個get方法，可以看到其中的getNextTrainCost調用了getConfig字段cost字段,下面從源代碼debug的角度看一下為什么會每次反序列化都多了很多null。首先getNextTrainCost這個getter中的nextTrainCost被當成了一個field，因為其返回值是一個JSONArray,其本身是可以作為setter用到的。其反序列化，用json中"nextTrainCost"相關反序列化

該字符串是[{".config.cost[0]"} 即使用了fastjson的循環引用,這個反序列化出來為[null] (因為本身config壓根就不屬於field,只是一個get方法而已)

然后調用setter(本身就是一個setter),得到cost,然后將這個[null] add到cost上

然后每反序列化一次都向cost中加入一個[null],進而使cost越來越大(JSONArray#底層數組還會自動expand)

 

 

 

public JSONArray getNextTrainCost() {

return ((PersonalityStrengthenConfig) getConfig()).cost;

}

 

@Override

public DataConfigItem getConfig() {

return DataConfigService.getSettingById(PersonalityStrengthenConfig.class,

personalityLevel);

}

 

 

 

 

反序列化nextTrainCost

 

 

 

// FieldDeserializer#setValue 其中method就是getNextTrainCost() 即獲取方法的返回值然后加了一個null

Collection collection = (Collection) method.invoke(object);

if (collection != null) {

collection.addAll((Collection) value);

}

 

 

 

 

分析問題5–問題初步總結

第一個問題出在了HeroPersonality中的getNextTrainCost方法引用了getConfig中的cost，導致在反序列化的時候每次會將json#nextTrainCost中反序列化出來的JSONArray#add到cost上(相當於調用了setter方法)

注意即使json#nextTrainCost不是循環引用(fastjson可關閉),即值就是引用的config#cost值,則每次反序列化一樣也會將反序列化出來的JSONArray#add到cost，只不過這次不會是null而已，第二個問題是最開始提到的我們正常序列化的時候就要帶上IgnoreNonFieldGetter這個參數，不要將非field的get方法給序列化上去，加上參數后，序列化后的json就沒有nextTrainCost了,那么也就不會有反序列化的問題了，因為壓根就掃描不到，當然HeroPersonality這個getNextTrainCost也比較奇葩，用了引用的方式，其實完全沒有必要，可以考慮干掉。

解決問題1–為什么cost會那么大

剛才我們已經基本肯定是因為錯誤模式下的反序列化會導致cost字段會越來越大，那么也不至於上億次吧?這個我大概查了一下代碼，很大幾率是好友推薦模塊和相關模塊。相關代碼需要較頻繁的對於離線鏡像反序列化或者存在類似心跳業務處理

解決辦法

很簡單，就是一定要記住fastjson序列化的時候要加上IgnoreNonFieldGetter就可以了。

擴展

mat還有很多強大的使用功能：

• Hisogram: list Number of instances per class

• Dominator: TreeList the biggest objects and what they keep alive

• Top Consumers: Print the most expensive objects grouped by class and by package

• List Objects…

此外還可以查看線程、Class Loader Explorer等

 

 

看完三件事❤️

如果你覺得這篇內容對你還蠻有幫助，我想邀請你幫我三個小忙：

 

1. 點贊，轉發，有你們的 『點贊和評論』，才是我創造的動力。

2. 關注公眾號 『 java爛豬皮 』，不定期分享原創知識。

3. 同時可以期待后續文章ing🚀

作者：landon30

出處：https://club.perfma.com/article/1656271