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

大家好，我是你假笨，來自阿里 JVM 團隊，花名寒泉子，工作快 7 年了，之前一直負責支付寶開發框架 SOFA 的研發，從 2014 年底開始從事 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 (Allocation Failure) [ParNew[SoftReference, 0 refs, 0.0001451 secs][WeakReference, 8 refs, 0.0001191 secs][FinalReference, 0 refs, 0.0001226 secs][PhantomReference, 0 refs, 0 refs, 0.0001833 secs][JNI Weak Reference

, 0.0111948 secs]: 81926K->6K(92160K), 0.0141540 secs] 82337K->417K(296960K), 0.0145097 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]

從當時的那個日誌里，我發現了一個現象，就是隨著 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 來手動觸發這個邏輯。

從輸出來看，看到了大量的下面的內容：

a java/lang/invoke/MemberName = :createProgramFunction (Ljdk/nashorn/internal/runtime/ScriptObject;)Ljdk/nashorn/internal/runtime/ScriptFunction; in jdk/nashorn/internal/scripts/Script$^eval\_

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

沒想到很快就寫好，而且真的很容易復現，大概邏輯如下：

public class ScriptTest {

private static final String SCRIPT = "var index = 1;return 3";

private static ScriptEngineManager scriptEngineManager = new ScriptEngineManager();

private static ScriptEngine scriptEngine = scriptEngineManager.getEngineByName("js");

public static void main(String[] args) {

while(true) {

try {

StringBuilder scriptBuilder = new StringBuilder();

scriptBuilder.append("function test(url) {");

scriptBuilder.append(SCRIPT);

scriptBuilder.append("}");

scriptEngine.eval(scriptBuilder.toString());

} catch (Throwable e) {

e.printStackTrace();

}

}

}

}

於是我開始 debug，最終確認和上面的 demo 完全等價於下面的 demo。

public class MHTest {

static MethodHandles.Lookup lookup = MethodHandles.lookup();

public static void main(String args[]){

while(true){

MethodType type = MethodType.methodType(double.class, double.class);

try {

MethodHandle mh = lookup.findStatic(Math.class, "log", type);

} catch (NoSuchMethodException e) {

e.printStackTrace();

} catch (IllegalAccessException e) {

e.printStackTrace();

}

}

}

}

所以大家直接運行上面的 demo 就能復現問題，JVM 參數如下：

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

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

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

在 JDK 層面的棧如下：

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

#0 JNIHandles::make_weak_global (obj=...)

#1 0x00007ffff5e7e34a in InstanceKlass::add_member_name (this=0x10015ec28, mem_name=...)

#2 0x00007ffff60e3556 in MethodHandles::init_method_MemberName (mname=..., info=...)

#3 0x00007ffff60e8290 in MethodHandles::resolve_MemberName (mname=..., caller=..., __the_thread__=0x7ffff5651000)

#4 0x00007ffff60e84d2 in MHN_resolve_Mem (env=, igcls=, mname_jh=, caller_jh=0x0)

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 不斷增長的問題。

今天的分享就差不多到這裡了，最後我打兩個小廣告：

第一個是我維護著一個微信公眾號，名字就叫「你假笨」，主要圍繞 JVM 寫了一系列的文章， 這些文章大部分來自工作中給同事們解決的各類 JVM 相關的經典問題，當然也存在部分介紹 JVM 原理性的文章，不過從閱讀量來看，大家還是偏向於看和案例綁定的文章，感興趣可以通過以下二維碼關注。

Q&A

提問1：鏈表中每一個節點都包含一個長度為 32 的數組嗎？尋找空位的演算法是怎樣的？是順序遍歷嗎？這樣隨著時間的推移，尋找空位的效率也會越來越低吧？

回答：是的，是順序遍歷，不過還有個細節，就是存在一個 free_list 的欄位，它將收集過來後續節點裡空的節點。

提問2：升級到 Java 8 之後，很多之前的 JVM 參數不好使了。能否介紹下 Java 8 常用的 JVM 參數呢？

回答：Java 8 其實大部分都差不多，只是有些參數的默認值可能已經變了，另外比較明顯的變化是分層編譯默認已經開啟，同時 Metaspace 取代了 Perm。

提問3：我想問個問題，有什麼辦法能看本地方法棧的信息呢？

回答：正常情況下我們通過 jstack -m 就可以看到本地方法棧，不過不是很建議大家用，因為這個走的是 SA 的路徑，性能會影響嚴重，可能還會 hung 住你這個進程。

提問4：分享中提到的是使用了 js 腳本的情況，有沒有其他的比較常見的使用場景會導致這種情況的發生？

回答：lambda 其實也是使用 invokedynamic 指令的，也存在風險，不過我還沒細看這種情況。

提問5：jstat 看內存堆棧的時候，經常能看到 wait 某個資源，資源是一個內存地址，有沒有工具能知道內存地址代表的什麼東西嗎？

回答：你說的應該是 jstack 看線程棧吧，你如果要看可以通過 HSDB 這個工具來看。

喜歡這篇文章嗎？立刻分享出去讓更多人知道吧！