天天看點

揪出一個導緻GC慢慢變長的JVM設計缺陷

今天要給大家分享的内容和 YGC(Young GC)有關,是我最近碰到的一個案例,希望将排查思路分享給大家,如果大家後面碰到類似的問題,可以直接作為一個經驗來排查。

我之前在公衆号裡其實寫過幾篇 YGC 的文章,也許其中有人已經看過了,沒看過的可以去看看,那兩個坑在這裡就不再描述,大家可以直接當經驗使用。

Java 堆分為新生代和老生代,YGC 其實就是針對新生代的垃圾回收,對象都是優先在新生代配置設定的,是以當新生代記憶體不夠配置設定的時候就會觸發垃圾回收,正常情況下可能觸發一次 YGC 就可以解決問題并正常配置設定的,當然也有極端情況可能要進行大掃除,對整個堆進行回收,也就是我們說的 Full GC,這種情況發生就會比較悲劇了。

這裡再提一下,YGC 也是會 STW(stop the world) 的,也就是會暫停整個應用,不要覺得 YGC 發生頻繁不是問題。

說實話我比較不喜歡排查 YGC 的問題,因為 YGC 的日志太簡單了,正常情況下隻能知道新生代記憶體從多少變到了多少,花了多長時間,再無其它資訊了。

是以當有人來咨詢為什麼我的程式 YGC 越來越長的問題的時候,我其實是抗拒的,不過也無奈,總得嘗試去幫人家解決,包括前面說的那兩個問題,也是費了不少精力查出來的,希望大家珍惜。。。

有些時候你越想逃避,偏偏就會找上你,YGC 的問題最近說實話找我的挺多的,不過有好些都是踩過的坑,是以能順利幫人家解決,但是今天要說的這個問題是之前從未碰到過的,是一個全新的問題,是以也費了我不少精力,也因為其他問題要查被拖延了幾天。

這個問題最終排查下來其實是 JVM 本身設計上面的一個缺陷,我改天也會提到 openjdk 社群去和大家一起讨論下這個設計,希望能徹底根治這個問題。

這個問題現象也很明顯,就是發現 YGC 的時間越來越長,從 20ms 慢慢增加到100ms+,甚至還一直在漲。

不過這個增長過程還是挺緩慢的,其實 YGC 時間在幾十毫秒我個人認為算正常現象,沒必要去深究,再說了還是經過壓測了一個晚上才漲上來的,是以平時應該也不是啥問題吧,不過這次正巧趕上年中大促,是以大家對時間也比較敏感,便接手來排查這個案例了。

首先排除了之前碰到的幾種情況,然後我要同僚加了一個我們 alijdk 特定的參數,可以列印 YGC 過程裡具體各個階段的耗時情況,可惜的是并沒有找出問題,因為我們漏掉了一些點,導緻沒有直接定位出來。

于是我懷疑那些沒跟蹤到的邏輯,首先懷疑的就是引用這塊的處理,是以叫同僚加上了 -XX:+PrintReferenceGC 這個參數,這個參數會列印各種引用的處理時間,大概如下:

揪出一個導緻GC慢慢變長的JVM設計缺陷

從當時的那個日志裡,我發現了一個現象,就是随着 YGC 時間的增長,JNI Weak Reference 的處理耗時也在不斷增長,是以基本就定位到了 YGC 增長的直接原因。

JNI Weak Reference 到底是什麼呢?大家都知道 Java 層面有各種引用,包括 SoftReference,WeakReference 等,其中 WeakReference 可以保證在 GC 的時候不會阻礙其引用對象的回收,同樣的在 native 代碼裡,我們也可以做類似的事情,有個叫做 JNIHandles::make_weak_global 的方法來達到這樣的效果。

于是我開始修改 JVM,嘗試列印一些資訊出來,不知道大家注意過,我們 dump 線程的時候,使用 jstack 指令,最後一條輸出裡會看到類似 JNI global references: 328 的日志,這裡其實就是列印了 JNI 裡的兩種全局引用總數,分别是 _global_handles 和 _weak_global_handles。

于是嘗試将這兩種情況分開來,看具體哪種有多少個,于是改了第一個版本,從修改之後的輸出來看,_global_handles 的引用個數基本穩定不變,但是 _weak_global_handles 的變化卻比較明顯。

至此也算佐證了 JNI Weak Reference的問題,于是我想再次修改 JVM,列印了這些 JNI Weak Reference 引用的具體對象是什麼對象。

在每次我執行 jstack 時,就會順帶把那些對象都列印出來,當然那個時候是為了性能,畢竟程式還跑線上上,不敢動太大,比如要是大量輸出日志不可控,那就麻煩了,是以就借助 jstack 來手動觸發這個邏輯。

從輸出來看,看到了大量的下面的内容:

揪出一個導緻GC慢慢變長的JVM設計缺陷

于是詢問同僚是不是存在大量的 Java 對 JavaScript 的調用,被告知确實有使用,那問題點基本算定位到了,我馬上要同僚針對他們的用法寫一個簡單的 demo 出來複現下問題。

沒想到很快就寫好,而且真的很容易複現,大概邏輯如下:

揪出一個導緻GC慢慢變長的JVM設計缺陷

于是我開始 debug,最終确認和上面的 demo 完全等價于下面的 demo。

揪出一個導緻GC慢慢變長的JVM設計缺陷

是以大家直接運作上面的 demo 就能複現問題,JVM 參數如下:

-Xmx300M -Xms300M -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+PrintReferenceGC

對了,運作平台是 JDK 8,JDK 6 是不存在這個問題的,因為 invokedynamic 指令以及 nashorn 是在 JDK 6 裡不存在的。

上面的 demo 看起來是不是沒毛病,但是卻真的會讓你的 GC 越來越慢,通過對 JVM 進行 debug 的方式抓出了下面的類似堆棧。

在 JDK 層面的棧如下:

揪出一個導緻GC慢慢變長的JVM設計缺陷

最上面的 resolve 方法是一個 native 方法,這個方法發現可以直接調用到上面提到的 JNIHandles::make_weak_global 方法。

揪出一個導緻GC慢慢變長的JVM設計缺陷

JNIHandles::make_weak_global 方法其實就是建立了一個 JNI Weak Reference。

在這裡我要稍微描述下了,因為太繁瑣就不準備貼代碼了。

JVM 裡有個資料結構叫做 JNIHandleBlock,之前提到了 global_handles 和 _weak_global_handles,其實他們都是一個 JNIHandleBlock 連結清單。

可以想象下裡面有個 next 字段鍊到下一個 JNIHandleBlock,同時裡面還有一個數組 _handle[],長度是 32,當我們要配置設定一個 JNI Weak Reference 的時候,就相當于在這個 JNIHandleBlock 連結清單裡找一個空閑的位置(就是那些 _handle 數組),如果發現每個 JNIHandleBlock 的 _handle 數組都滿了,就會建立一個新的 JNIHandleBlock,然後加到鍊裡,注意這個鍊可以無限長,是以問題就來了,假如我們上層代碼不斷觸發底層調用 JNIHandles::make_weak_global 來建立一個 JNI Weak Reference,那是不是意味着這個 JNIHandleBlock 鍊會不斷增長,那會不會無窮增長呢,答案是肯定的,既然有建立 JNI Weak Reference 的 API,是不是也存在銷毀 JNI Weak Reference 的 API?

當然是存在的,可以看到有 JNIHandles::destroy_weak_global 方法,這個實作其實很簡單,就是相當于設計一個标記,表示這個數組裡的這個位置是可以重用的了,在 GC 發生的時候,如果發現這個坑被标記了,于是就将這個坑加入到一個 free_list 裡,當我們下面再想要配置設定一個 JNI Weak Reference 的時候,就可以有機會從 free_list 裡去配置設定一個重用了。

但是這個 api 是在什麼情況下才能調用的呢,其實隻有在類解除安裝的時候才會去調用這個 api,那到底是什麼類被解除安裝了,那就是調用了 MethodHandles.lookup() 這個方法的那個類,從我們上面的 demo 來看,就是 MHTest 這個主類本身,從同僚給我的 demo 來看,其實是 jdk.nashorn.internal.runtime.Context 這個類,但是這個類其實是被 ext_classloader 加載的,也就是說這個類根本就不會被解除安裝,不能解除安裝那問題就嚴重了,意味着 GC 發生的時候并不能将那些引用對象已經死掉的坑置空,這樣在我們需要再次配置設定 JNI Weak Reference 的時候,沒有機會來重用那些坑,最終的結果就是不斷地建立新的 JNIHandleBlock 加到連結清單裡,導緻連結清單越來越長,然而 GC 的時候是會去不斷掃描這個連結清單的,是以看到 GC 的時候也會越來越長。

那還有一個問題,假如說調用 MethodHandles.lookup() 的類真的被解除安裝了還存在這個問題嗎,答案是 GC 時間不會再惡化了,但是之前已經達到的惡化結果已經無法再修複了。

是以,這算是一個 JVM 設計上的缺陷吧,隻要 Java 層面能觸發不斷調用到JNIHandles::make_weak_global,那這個問題将會立馬重制。

其實解決方案我也想了一個,就是在周遊這些 JNIHandleBlock 的時候,如果發現對應的_handle數組全是空的話,那就直接将 JNIHandleBlock 回收掉,這樣在 GC 發生的過程中并不會掃描到很多的 JNIHandleBlock 而耗時掉。

至于同僚的那個問題的解決方案,其實也簡單,對于同一個 JavaScript 腳本,不要每次都去調用 eval 方法,可以緩存起來,這樣就減少了不斷去觸發調用 JNIHandles::make_weak_global 的動作進而可以避免 JNIHandleBlock 不斷增長的問題。

文章轉載自阿裡雲 MVP李嘉鵬,

檢視原文