記一次，線上服務頻繁FGC排查過程

一、問題

最近接到運營部門的反饋網站時常會出現小批量的502且在網站出現502以前反應特別慢,刷新幾回之後又能夠正常訪問了。

二、排查過程

項目部署了兩臺機器，其中一臺出現重啓的狀況，部分用戶在訪問當前服務器時正好機器重啓了，致使訪問異常。

2.一、查看日誌文件

查看生產環境日誌發現其中一臺機器重啓了屢次，從warpper log中能夠發現warpper在屢次ping不通時自動重啓了屢次，從運維那邊確認這臺服務器屢次出現無響應的狀況。此時第一時間想到OOM進一步查看日誌並無發現OutOfMemoryException拋出，也沒有StackOverflowException。

2.二、生產環境資源、GC狀況

經過top命令查看生產環境CPU佔用一直很是高，load也一直高居不下，GC長時間佔用CPU資源。

進一步查看GC狀況，發如今重啓後很短的時間內FGC 次數達7W+；Old Generation 持續佔用100%,而每次FGC的時間又很是的短.

jstat -gcUtil [pid] 1000

在經過jmap -histo [pid]查看內存實例狀況也沒有發現異常。

是什麼致使如此頻繁的 FGC?。

2.三、查看堆棧信息

因爲沒有觸發OOM手動添加如下啓動參數，打印FGC 先後堆內存狀況

-XX:+HeapDumpBeforeFullGC
-XX:+HeapDumpAfterFullGC
-XX:HeapDumpPath=/tmp
複製代碼

果真，重啓後短期內開始輸出 dump

接下來使用jvisualvm (JDK 自帶的內存分析工具) 查看堆dump文件。 如下列出FGC先後的堆dump類視圖

• FGC前

  

• FGC後

• 

對比FGC先後發如今FGC以前存在大量的int[]和char[]數組,且數組的length都很是大,而這些大數組在FGC以後又被有效的回收了。對jvm垃圾回收有了解的同窗應該知道，jvm爲了不頻繁的移動大對象會將大對象直接建立在Old Generation。此時開始懷疑是否是Old Generation的空間不夠了，逐一排查線上環境的jvm啓動參數。

-Xms 2048
-Xmx 2048
...

-Xmn 2000
-
複製代碼

......

最後發現，因爲這臺機器內存只有2G而新生代分配的內存卻達到了2000M剩下的內存只有48M。而大數組又會直接分配到Old Generation當Old Generation沒有足夠的空間來存放大數組對象時，就可能觸發FGC修改 -Xmn 683默認新生代和老年代的比值爲1:2。從新發布問題解決，top、jstat -gc查看服務器狀態各項數據都很是可愛。

三、覆盤

因爲項目已經跑了好幾年，一開始的思路都在查找項目代碼層面的問題，絲毫沒有意Jvm啓動參數的問題，其實對一些有經驗的同窗來講發現問題蒐集到的一些信息就能夠定位問題。如：

1. GC那張圖就能夠明顯的看出問題。FGC 異常頻繁（7W+），但FGCT卻不高（1.9W），這說明每次 FGC的效率很是高。而每次FGC的時候New Generation的佔用卻很是少，能夠排除是由於程序問題短期內產生大量新對象觸發的 FGC，這些都提供了直接的排查方向應該從:致使FGC 觸發的條件入手，而不是找程序的問題。
2. dump中存在大量無引用的對象，也從側面反應出在FGC以前沒有有效的觸發YGC。

還有一點值得注意，jvm啓動參數的默認值在絕大多數狀況下均可以完美的運行，不到系統優化的最後一步儘可能使用默認配置，最後還有一點疑問大量的int[]、char[]數組是從那裏來得？經過分析項目中的代碼，以及FGC前存在大量的pattern(正則表達式)相關對象分析，初步懷疑是由於項目中大量不規範的使用Pattern致使的。

四、總結排查過程

1. 查看日誌是否有OutOfMemoryException、StackOverflowException拋出。
2. 查看線上服務器狀態、GC狀況。
3. 分析GC先後的dump文件。
4. 定位問題。