1. 程式人生 > >線上服務的FGC問題排查,看這篇就夠了!

線上服務的FGC問題排查,看這篇就夠了!

線上服務的GC問題,是Java程式非常典型的一類問題,非常考驗工程師排查問題的能力。同時,幾乎是面試必考題,但是能真正答好此題的人並不多,要麼原理沒吃透,要麼缺乏實戰經驗。 過去半年時間裡,我們的廣告系統出現了多次和GC相關的線上問題,有Full GC過於頻繁的,有Young GC耗時過長的,這些問題帶來的影響是:GC過程中的程式卡頓,進一步導致服務超時從而影響到廣告收入。 這篇文章,我將以一個FGC頻繁的線上案例作為引子,詳細介紹下GC的排查過程,另外會結合GC的執行原理給出一份實踐指南,希望對你有所幫助。內容分成以下3個部分: > 1、從一次FGC頻繁的線上案例說起 > > 2、GC的執行原理介紹 > > 3、排查FGC問題的實踐指南 >
### **01 從一次FGC頻繁的線上案例說起** 去年10月份,我們的廣告召回系統在程式上線後收到了FGC頻繁的系統告警,通過下面的監控圖可以看到:平均每35分鐘就進行了一次FGC。而程式上線前,我們的FGC頻次大概是2天一次。下面,詳細介紹下該問題的排查過程。 ![](https://img2020.cnblogs.com/blog/2015191/202006/2015191-20200614231632162-1641513891.png)
1. 檢查JVM配置 通過以下命令檢視JVM的啟動引數: ps aux | grep "applicationName=adsearch" >-Xms4g -Xmx4g -Xmn2g -Xss1024K >-XX:ParallelGCThreads=5 >-XX:+UseConcMarkSweepGC >-XX:+UseParNewGC >-XX:+UseCMSCompactAtFullCollection >-XX:CMSInitiatingOccupancyFraction=80 可以看到堆記憶體為4G,新生代為2G,老年代也為2G,新生代採用ParNew收集器,老年代採用併發標記清除的CMS收集器,當老年代的記憶體佔用率達到80%時會進行FGC。 進一步通過 jmap -heap 7276 | head -n20 可以得知新生代的Eden區為1.6G,S0和S1區均為0.2G。
2. 觀察老年代的記憶體變化
通過觀察老年代的使用情況,可以看到:每次FGC後,記憶體都能回到500M左右,因此我們排除了記憶體洩漏的情況。 ![](https://img2020.cnblogs.com/blog/2015191/202006/2015191-20200614231937405-1362921392.png)
3. 通過jmap命令檢視堆記憶體中的物件 通過命令 jmap -histo 7276 | head -n20 ![](https://img2020.cnblogs.com/blog/2015191/202006/2015191-20200614232026609-1545555997.png) 上圖中,按照物件所佔記憶體大小排序,顯示了存活物件的例項數、所佔記憶體、類名。可以看到排名第一的是:int[],而且所佔記憶體大小遠遠超過其他存活物件。至此,我們將懷疑目標鎖定在了 int[] .
4. 進一步dump堆記憶體檔案進行分析
鎖定 int[] 後,我們打算dump堆記憶體檔案,通過視覺化工具進一步跟蹤物件的來源。考慮堆轉儲過程中會暫停程式,因此我們先從服務管理平臺摘掉了此節點,然後通過以下命令dump堆記憶體: jmap -dump:format=b,file=heap 7276 通過JVisualVM工具匯入dump出來的堆記憶體檔案,同樣可以看到各個物件所佔空間,其中int[]佔到了50%以上的記憶體,進一步往下便可以找到 int[] 所屬的業務物件,發現它來自於架構團隊提供的codis基礎元件。 ![](https://img2020.cnblogs.com/blog/2015191/202006/2015191-20200614232149171-294044029.png)
5. 通過程式碼分析可疑物件
通過程式碼分析,codis基礎元件每分鐘會生成約40M大小的int陣列,用於統計TP99 和 TP90,陣列的生命週期是一分鐘。而根據第2步觀察老年代的記憶體變化時,發現老年代的記憶體基本上也是每分鐘增加40多M,因此推斷:這40M的int陣列應該是從新生代晉升到老年代。 我們進一步查看了YGC的頻次監控,通過下圖可以看到大概1分鐘有8次左右的YGC,這樣基本驗證了我們的推斷:因為CMS收集器預設的分代年齡是6次,即YGC 6次後還存活的物件就會晉升到老年代,而codis元件中的大陣列生命週期是1分鐘,剛好滿足這個要求。 ![](https://img2020.cnblogs.com/blog/2015191/202006/2015191-20200614232233434-734001373.png) 至此,整個排查過程基本結束了,那為什麼程式上線前沒出現此問題呢?通過上圖可以看到:程式上線前YGC的頻次在5次左右,此次上線後YGC頻次變成了8次左右,從而引發了此問題。
6. 解決方案 為了快速解決問題,我們將CMS收集器的分代年齡改成了15次,改完後FGC頻次恢復到了2天一次,後續如果YGC的頻次超過每分鐘15次還會再次觸發此問題。當然,我們最根本的解決方案是:優化程式以降低YGC的頻率,同時縮短codis元件中int陣列的生命週期,這裡就不做展開了。
### **02 GC的執行原理介紹** 上面整個案例的分析過程中,其實涉及到很多GC的原理知識,如果不懂得這些原理就著手處理,其實整個排查過程是很抓瞎的。 這裡,我選擇幾個最核心的知識點,展開介紹下GC的執行原理,最後再給出一份實踐指南。
1. 堆記憶體結構 大家都知道: GC分為YGC和FGC,它們均發生在JVM的堆記憶體上。先來看下JDK8的堆記憶體結構: ![](https://img2020.cnblogs.com/blog/2015191/202006/2015191-20200614233000407-1687109238.png) 可以看到,堆記憶體採用了分代結構,包括新生代和老年代。新生代又分為:Eden區,From Survivor區(簡稱S0),To Survivor區(簡稱S1區),三者的預設比例為8:1:1。另外,新生代和老年代的預設比例為1:2。 堆記憶體之所以採用分代結構,是考慮到絕大部分物件都是短生命週期的,這樣不同生命週期的物件可放在不同的區域中,然後針對新生代和老年代採用不同的垃圾回收演算法,從而使得GC效率最高。
2. YGC是什麼時候觸發的? 大多數情況下,物件直接在年輕代中的Eden區進行分配,如果Eden區域沒有足夠的空間,那麼就會觸發YGC(Minor GC),YGC處理的區域只有新生代。因為大部分物件在短時間內都是可收回掉的,因此YGC後只有極少數的物件能存活下來,而被移動到S0區(採用的是複製演算法)。 當觸發下一次YGC時,會將Eden區和S0區的存活物件移動到S1區,同時清空Eden區和S0區。當再次觸發YGC時,這時候處理的區域就變成了Eden區和S1區(即S0和S1進行角色交換)。每經過一次YGC,存活物件的年齡就會加1。
3. FGC又是什麼時候觸發的? 下面4種情況,物件會進入到老年代中: >1、YGC時,To Survivor區不足以存放存活的物件,物件會直接進入到老年代。 > >2、經過多次YGC後,如果存活物件的年齡達到了設定閾值,則會晉升到老年代中。 > >3、動態年齡判定規則,To Survivor區中相同年齡的物件,如果其大小之和佔到了 To Survivor區一半以上的空間,那麼大於此年齡的物件會直接進入老年代,而不需要達到預設的分代年齡。 > >4、大物件:由-XX:PretenureSizeThreshold啟動引數控制,若物件大小大於此值,就會繞過新生代, 直接在老年代中分配。
當晉升到老年代的物件大於了老年代的剩餘空間時,就會觸發FGC(Major GC),FGC處理的區域同時包括新生代和老年代。除此之外,還有以下4種情況也會觸發FGC: >1、老年代的記憶體使用率達到了一定閾值(可通過引數調整),直接觸發FGC。 > >2、空間分配擔保:在YGC之前,會先檢查老年代最大可用的連續空間是否大於新生代所有物件的總空間。如果小於,說明YGC是不安全的,則會檢視引數 HandlePromotionFailure 是否被設定成了允許擔保失敗,如果不允許則直接觸發Full GC;如果允許,那麼會進一步檢查老年代最大可用的連續空間是否大於歷次晉升到老年代物件的平均大小,如果小於也會觸發 Full GC。 > >3、Metaspace(元空間)在空間不足時會進行擴容,當擴容到了-XX:MetaspaceSize 引數的指定值時,也會觸發FGC。 > >4、System.gc() 或者Runtime.gc() 被顯式呼叫時,觸發FGC。
4. 在什麼情況下,GC會對程式產生影響? 不管YGC還是FGC,都會造成一定程度的程式卡頓(即Stop The World問題:GC執行緒開始工作,其他工作執行緒被掛起),即使採用ParNew、CMS或者G1這些更先進的垃圾回收演算法,也只是在減少卡頓時間,而並不能完全消除卡頓。 那到底什麼情況下,GC會對程式產生影響呢?根據嚴重程度從高到底,我認為包括以下4種情況: >1、FGC過於頻繁:FGC通常是比較慢的,少則幾百毫秒,多則幾秒,正常情況FGC每隔幾個小時甚至幾天才執行一次,對系統的影響還能接受。但是,一旦出現FGC頻繁(比如幾十分鐘就會執行一次),這種肯定是存在問題的,它會導致工作執行緒頻繁被停止,讓系統看起來一直有卡頓現象,也會使得程式的整體效能變差。 > >2、YGC耗時過長:一般來說,YGC的總耗時在幾十或者上百毫秒是比較正常的,雖然會引起系統卡頓幾毫秒或者幾十毫秒,這種情況幾乎對使用者無感知,對程式的影響可以忽略不計。但是如果YGC耗時達到了1秒甚至幾秒(都快趕上FGC的耗時了),那卡頓時間就會增大,加上YGC本身比較頻繁,就會導致比較多的服務超時問題。 > >3、FGC耗時過長:FGC耗時增加,卡頓時間也會隨之增加,尤其對於高併發服務,可能導致FGC期間比較多的超時問題,可用性降低,這種也需要關注。 > >4、YGC過於頻繁:即使YGC不會引起服務超時,但是YGC過於頻繁也會降低服務的整體效能,對於高併發服務也是需要關注的。 其中,「FGC過於頻繁」和「YGC耗時過長」,這兩種情況屬於比較典型的GC問題,大概率會對程式的服務質量產生影響。剩餘兩種情況的嚴重程度低一些,但是對於高併發或者高可用的程式也需要關注。
### **03 排查FGC問題的實踐指南** 通過上面的案例分析以及理論介紹,再總結下FGC問題的排查思路,作為一份實踐指南供大家參考。
1. 清楚從程式角度,有哪些原因導致FGC? >1、大物件:系統一次性載入了過多資料到記憶體中(比如SQL查詢未做分頁),導致大物件進入了老年代。 > >2、記憶體洩漏:頻繁建立了大量物件,但是無法被回收(比如IO物件使用完後未呼叫close方法釋放資源),先引發FGC,最後導致OOM. > >3、程式頻繁生成一些長生命週期的物件,當這些物件的存活年齡超過分代年齡時便會進入老年代,最後引發FGC. (即本文中的案例) > >4、程式BUG導致動態生成了很多新類,使得 Metaspace 不斷被佔用,先引發FGC,最後導致OOM. > >5、程式碼中顯式呼叫了gc方法,包括自己的程式碼甚至框架中的程式碼。 > >6、JVM引數設定問題:包括總記憶體大小、新生代和老年代的大小、Eden區和S區的大小、元空間大小、垃圾回收演算法等等。
2. 清楚排查問題時能使用哪些工具 >1、公司的監控系統:大部分公司都會有,可全方位監控JVM的各項指標。 > >2、JDK的自帶工具,包括jmap、jstat等常用命令: > >檢視堆記憶體各區域的使用率以及GC情況 >jstat -gcutil -h20 pid 1000 > >檢視堆記憶體中的存活物件,並按空間排序 >jmap -histo pid | head -n20 > >dump堆記憶體檔案 >jmap -dump:format=b,file=heap pid > >3、視覺化的堆記憶體分析工具:JVisualVM、MAT等
3. 排查指南 >1、檢視監控,以瞭解出現問題的時間點以及當前FGC的頻率(可對比正常情況看頻率是否正常) > >2、瞭解該時間點之前有沒有程式上線、基礎元件升級等情況。 > >3、瞭解JVM的引數設定,包括:堆空間各個區域的大小設定,新生代和老年代分別採用了哪些垃圾收集器,然後分析JVM引數設定是否合理。 > >4、再對步驟1中列出的可能原因做排除法,其中元空間被打滿、記憶體洩漏、程式碼顯式呼叫gc方法比較容易排查。 > >5、針對大物件或者長生命週期物件導致的FGC,可通過 jmap -histo 命令並結合dump堆記憶體檔案作進一步分析,需要先定位到可疑物件。 > >6、通過可疑物件定位到具體程式碼再次分析,這時候要結合GC原理和JVM引數設定,弄清楚可疑物件是否滿足了進入到老年代的條件才能下結論。
### **04 最後的話** 這篇文章通過線上案例並結合GC原理詳細介紹了FGC的排查過程,同時給出了一份實踐指南。 後續會以類似的方式,再分享一個YGC耗時過長的案例,希望能幫助大家吃透GC問題排查,如果覺得本文對你有幫助,請大家關注我的個人公眾號!
- End -

作者簡介:程式設計師,985碩士,前亞馬遜Java工程師,現58轉轉技術總監。持續分享技術和管理方向的文章。如果感興趣,可微信掃描下面的二維碼關注我的公眾號:『IT人的職場進階』