1. 程式人生 > >關於GC(上):Apache的POI元件導致線上頻繁FullGC問題排查及處理全過程

關於GC(上):Apache的POI元件導致線上頻繁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記憶體佔用問題的討論:

簡單摘譯了一些,可以直接看原文。

  1. Java對堆記憶體分配是懶回收的,如果JVM不想這麼做,即使執行Runtime.gc(),也可能什麼也不做。sapiensl和Amongalen的回答
  2. 觸發FullGC,並不是因為記憶體洩漏,僅僅是因為poi佔用了太多的記憶體。Michael的回答

關於G1GC,會在後續文章中研究