一次線上頻繁FullGC問題的排查和解決記錄,整理了一下通用的排查解決過程,同時介紹了一些可能會用到的工具。 ...
某線上應用在進行查詢結果導出Excel時,大概率出現持續的FullGC。解決這個問題時,記錄了一下整個的流程,也可以作為一般性的FullGC問題排查指導。
1. 生成dump文件
為了定位FullGC的原因,首先需要獲取heap dump文件,看下發生FullGC時堆記憶體的分配情況,定位可能出現問題的地方。
1. 1 通過JVM參數自動生成
可以在JVM參數中設置-XX:+ HeapDumpBeforeFullGC
參數。
建議動態增加這個參數,直接線上上鏡像中增加一方面是要重新打包發佈,另一方面風險比較高
sudo -u admin /opt/taobao/java/bin/jinfo -flag +HeapDumpBeforeFullGC pid
sudo -u admin /opt/taobao/java/bin/jinfo -flag +HeapDumpAfterFullGC pid
也可以用HeapDumpOnOutOfMemoryError這個參數,只在outOfMemoryError發生時才dump。實測只有在fullgc完成時才會產生該文件,fullgc期間看不到。
此外還需要-XX:HeapDumpPath=/home/admin/logs/java.hprof
這個參數來指定dump文件存放路徑。
1.2 通過JDK工具生成
1.2.1 jmap
先獲取java進程ID,再使用jmap進行dump。
註意,虛擬機上的jmap可能沒有做路徑映射,需要手動選擇jdk路徑下來執行
ps -aux | grep java
jmap -dump:file=test.hprof,format=b XXXX
1.2.2 通過jcmd
JDK7後新增的多功能命令,其中jcmd pid GC.heap_dump FILE_NAME
的效果和jmap -dump:file=test.hprof,format=b pid
一樣。
1.3 JConsole
可以生成本機或遠程JVM的dump。還有一些其他工具就不詳細介紹了。
2. 下載dump文件
由於使用的是阿裡雲的伺服器,可以直接將dump文件上傳到OSS上通過公司內部工具來分析,或通過OSS再下載到本地。
設置OSSCMD:
操作命令 osscmd config --host=oss-cn-hangzhou-am101.aliyuncs.com --id=** --key=**
創建bucke:osscmd cb 000001
上傳文件:osscmd put 1.txt oss://000001/
下載文件:osscmd get oss://000001/1.txt 1.txt
其他類型的Linux主機可以使用SCP命令,參考:Linux scp命令
3. 分析工具
通過dump文件來分析fullGC的原因,需要關註哪些類占用記憶體空間較多、不可到達類等。
由於使用的是公司內部工具Zprofiler和grace,詳細的使用過程這裡就不截圖了。一些其他可用的工具和命令(參考Java記憶體泄漏分析系列之六:JVM Heap Dump(堆轉儲文件)的生成和MAT的使用):
- jhat, JDK自帶,使用
jhat <heap-dump-file>
生成網頁,通過瀏覽器訪問``查看 - jvisualvm
- Eclipse Memory Analyzer(MAT)
- IBM Heap Analyzer
需要註意的是,只看dump文件有時還不能得到結論,因為占用空間大頭的有可能是String、ArrayBlockingList這樣的對象,而且內容可能是null或null對象的集合,無從排查。此時還要結合發生fullgc前後業務系統發生了什麼動作來確定。如果有條件的話可以在日常環境或預發環境重現一下。
當然,如果記憶體中的空間消耗對象是特殊的類,就比較好排查了。
4. 分析和改進
具體情況具體分析。
4.1 本次排查的場景
查詢DB中數據->在非同步線程中通過poi轉換成Excel->上傳到OSS。
示例代碼:
// 導出代碼中將變數直接作為lambda表達式的值傳入
List<XXData> data = queryData(request);
SheetDownloadProperty property = sheetDownloadProperties.get(0);
property.setTotalCount(request.getQueryRequest().getPageSize());
property.setPageSize(request.getQueryRequest().getPageSize());
property.setQueryFunction((currentPage, pageSize) -> data);
// 該組件會線上程池非同步調用poi組件轉換為excel、上傳OSS、下載
asyncDownloadService.downloadFile(downloadTask);
private List<XXData> queryData(ExportRequest request) {
//查詢DB,略
}
// 查詢方法
@FunctionalInterface
public interface PageFunction<T> {
/**
* 方法執行
*/
List<T> apply(Integer currentPage,Integer pageSize);
}
4.2 dump文件分析
通過內部工具可見,fullGC前有三個占據記憶體較高的ArrayBlockingList,裡面有大量的內容為null的Object。
這三個ArrayBlockingList所屬的中間件,雖然本身和業務流程沒有關係,但是仍不能排除嫌疑。
4.3 嘗試解決
4.3.1 方案1:poi相關解決方案
由於依賴了二方庫poi,這個庫的usermodel模式很容易引起fullGC,同時也懷疑是因為lambda表達式直接傳了變數。
把poi的usermodel改為事件模式(https://my.oschina.net/OutOfMemory/blog/1068972)可以避免這個問題。
但是該功能是一個二次封裝的三方包中的,同時其他引用該組件的應用fullgc頻率並不高,沒有採用這個方案。
4.3.2 方案2:中間件升級
持有大量null對象的中間件版本較低,且新版目前已不再維護,老版本的releas note雖然沒有提到這條bug fix,有一定嫌疑。
該中間件初始化時會創建三個容量為810241024的ArrayBlockingList,和dump文件相符合。
同樣是因為這個中間件是在三方包中封裝,不方便直接該版本,同樣沒有採用這個方案。
4.3.3 方案3:增大堆大小
可以調整metaspace參數來實現,本次想找到代碼中相關的線索來解決,未採用該方案。
4.3.4 方案4:業務代碼修改
仔細觀察了這段代碼在其他系統的的實現,發現其他系統的lambda表達式是匿名方法,而不是直接傳值,即:
property.setQueryFunction((currentPage, pageSize) -> {
// 查詢邏輯, 略
);
懷疑是直接傳變數進去導致的垃圾回收問題。更改到這種模式後,觸發下載功能時,連續長時間的fullGC仍然時有發生,沒有解決問題。
4.3.5 方案5:替換垃圾回收器
暫時能確定的原因是,公司中間件本身占用堆記憶體較多,運行poi增加了GC的頻率。但是由於它們都在二方庫的原因,不方便修改。
此時搜索到stackoverflow有關於poi反覆GC的一個問題,和我的情況類似,也是反覆GC但是仍然不能釋放記憶體。有回覆建議將GC回收器替換為G1GC,將預設的UseConcMarkSweepGC替換後效果明顯,一次FullGC就可以完成回收釋放,不會反覆FullGC,如下圖,20:30前的fullGC是CMS,持續時間長且反覆進行;20:30後是替換後第一次觸發excel轉換下載,進行了多次下載,即使發生FullGC也只有1次,大大緩解了之前的問題:
本次暫定只採用方案5。
G1GC在JDK9已替代CMS成為了正式的垃圾回收器,低版本JDK需要手動設置。具體需要設置的JVM參數:
-Xms32m
-Xmx1g
-XX:+UnlockExperimentalVMOptions
-XX:+UseG1GC
-XX:MaxHeapFreeRatio=15
-XX:MinHeapFreeRatio=5
註意前兩行一般應用都會設置,不要覆蓋掉。最後兩行需要視情況調整。另外,預設的-XX:+UseConcMarkSweepGC
需要去掉。
使用G1GC時需要確認工作線程數是否和預期一致,不要太多,一般來說和CPU核數一致即可。出現非預期數目的原因可能是,鏡像腳本指定核數時,直接按照物理機而不是虛擬機核數來生成。
查看方式是看gc日誌:
虛擬機設置核數的dokcker腳本示例:
export CPU_COUNT="$(grep -c 'cpu[0-9][0-9]*' /proc/stat)"
5. 其他
5.1 典型fullGC場景舉例
- 外部資源未釋放,如將利用tair實現的分散式鎖放在Map中,未做解鎖
- fastjson的反序列化異常拋出後沒有處理
- 框架固有缺陷,如本例apache的poi組件,使用usermodel模式做excel導出時,當操作比較頻繁或有其他記憶體泄漏有可能造成
- JVM的metaspace設置過小
5.2 core dump和heap dump
core dump是針對線程某一時刻的運行情況的,可以看到執行到哪個類哪個方法哪一行以及執行棧的;heap dump是針對記憶體某一時刻的分配情況的。
5.3 stackoverflow上關於poi記憶體占用問題的討論:
簡單摘譯了一些,可以直接看原文。
- Java對堆記憶體分配是懶回收的,如果JVM不想這麼做,即使運行Runtime.gc(),也可能什麼也不做。sapiensl和Amongalen的回答
- 觸發FullGC,並不是因為記憶體泄漏,僅僅是因為poi占用了太多的記憶體。Michael的回答
關於G1GC,會在後續文章中研究。