現象
-
QA同學反映登錄不上服務器
排查問題1–日志級別
-
查看log,發現玩家登錄的時候拋出了一個java.lang.OutOfMemoryError
-
大概代碼是向Redis序列化一個PlayerMirror鏡像資料,但是在JSON.toJSONString的時候出現了錯誤.比較清晰,即序列化的時候expandCapacity,記憶體不足,
-
又看了一下日志,有好幾個OutOfMemoryError,都是類似于用fastjson序列化PlayerMirror報的錯誤
-
又仔細看了一下server目錄,發現了幾個.hprof,說明確實發生了堆記憶體溢位,因為啟動引數增加了’-XX:+HeapDumpOnOutOfMemoryError’
-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等
看完三件事??
如果你覺得這篇內容對你還蠻有幫助,我想邀請你幫我三個小忙:
-
點贊,轉發,有你們的 『點贊和評論』,才是我創造的動力,
-
關注公眾號 『 java爛豬皮 』,不定期分享原創知識,
-
同時可以期待后續文章ing??
作者:landon30
出處:https://club.perfma.com/article/1656271
轉載請註明出處,本文鏈接:https://www.uj5u.com/houduan/226048.html
標籤:Java
