1. 程式人生 > >深入JVM徹底剖析前面ygc越來越慢的case

深入JVM徹底剖析前面ygc越來越慢的case

阿里JVM團隊的同學幫助從JVM層面繼續深入的剖析了下前面那個ygc越來越慢的case,分析文章相當的贊,思路清晰,工具熟練,JVM程式碼熟練,請看這位同學(阿里JVM團隊:寒泉子)寫的文章,我轉載到這。

 

Demo分析


雖然這個demo程式碼邏輯很簡單,但是其實這是一個特殊的demo,並不簡單,如果我們將XStream物件換成Object物件,會發現不存在這個問題,既然如此那有必要進去看看這個XStream的建構函式(請大家直接翻XStream的程式碼,這裡就不貼了)。

這個建構函式還是很複雜的,裡面會建立很多的物件,上面還有一些方法實現我就不貼了,總之都是在不斷構建各種大大小小的物件,一個XStream物件構建出來的時候大概好像有12M的樣子。

那到底是哪些物件會導致ygc不斷增長呢,於是可能想到逐步替換上面這些邏輯,比如將最後一個建構函式裡的那些邏輯都禁掉,然後我們再跑測試看看還會不會讓ygc不斷惡化,最終我們會發現,如果我們直接使用如下建構函式構造物件時,如果傳入的classloader是AppClassLoader,則會發現這個問題不再出現了,程式碼如下:

public static void main(String[] args) throws Exception {
    int i=0;
    while (true) {
        XStream xs = new XStream(null,null, new ClassLoaderReference(XStreamTest.class.getClassLoader()),null, new DefaultConverterLookup());
        xs.toString();
        xs=null;
    }
}

是不是覺得很神奇,由此可見,這個classloader至關重要。

 

不得不說的類載入器


這裡著重要說的兩個概念是初始類載入器和定義類載入器。舉個栗子說吧,AClassLoader->BClassLoader->CClassLoader,表示AClassLoader在載入類的時候會委託BClassLoader類載入器來載入,BClassLoader載入類的時候會委託CClassLoader來載入,假如我們使用AClassLoader來載入X這個類,而X這個類最終是被CClassLoader來載入的,那麼我們稱CClassLoader為X類的定義類載入器,而AClassLoader和BClassLoader分別為X類的初始類載入器,JVM在載入某個類的時候對這三種類載入器都會記錄,記錄的資料結構是一個叫做SystemDictionary的hashtable,其key是根據ClassLoader物件和類名算出來的hash值,而value是真正的由定義類載入器載入的Klass物件,因為初始類載入器和定義類載入器是不同的classloader,因此算出來的hash值也是不同的,因此在SystemDictionary裡會有多項key值的value都是指向同一個Klass物件。

那麼JVM為什麼要分這兩種類載入器呢,其實主要是為了快速找到已經載入的類,比如我們已經通過AClassLoader來觸發了對X類的載入,當我們再次使用AClassLoader這個類載入器來載入X這個類的時候就不需要再委託給BClassLoader去找了,因為載入過的類在JVM裡有這個類載入器的直接載入的記錄,只需要直接返回對應的Klass物件即可。

 

Demo中的類載入器是否會載入類


我們的demo裡發現構建了一個CompositeClassLoader的類載入器,那到底有沒有用這個類載入器載入類呢,我們可以設定一個斷點在CompositeClassLoader的loadClass方法上,可以看到會進入斷點。

可見確實有類載入的動作,根據類載入委託機制,在這個Demo中我們能肯定類是交給AppClassLoader來載入的,這樣一來CompositeClassLoader就變成了初始類載入器,而AppClassLoader會是定義類載入器,都會在SystemDictionary裡存在,因此當我們不斷new XStream的時候會不斷new CompositeClassLoader物件,載入類的時候會不斷往SystemDictionary裡插入記錄,從而使SystemDictionary越來越膨脹,那自然而然會想到如果GC過程不斷去掃描這個SystemDictionary的話,那隨著SystemDictionary不斷膨脹,那麼GC的效率也就越低,抱著驗證下猜想的方式我們可以使用perf工具來看看,如果發現cpu佔比排前的函式都是操作SystemDictionary的,那就基本驗證了我們的想法,下面是perf工具的截圖,基本證實了這一點。

 

SystemDictionary為什麼會影響GC過程


想象一下這麼個情況,我們載入了一個類,然後構建了一個物件(這個物件在eden裡構建)當一個屬性設定到這個類裡,如果gc發生的時候,這個物件是不是要被找出來標活才行,那麼自然而然我們載入的類肯定是我們一項重要的gc root,這樣SystemDictionary就成為了gc過程中的被掃描物件了,事實也是如此,可以看vm的具體程式碼(程式碼在:SharedHeap::process_strong_roots,感興趣的同學可以直接翻這部分程式碼)。

看上面的SH_PS_SystemDictionary_oops_do task就知道了,這個就是對SystemDictionary進行掃描。

但是這裡要說的是雖然有對SystemDictionary進行掃描,但是ygc的過程並不會對SystemDictionary進行處理,如果要對它進行處理需要開啟類解除安裝的vm引數,CMS演算法下,CMS GC和Full GC在開啟CMSClassUnloadingEnabled的情況下是可能對類做解除安裝動作的,此時會對SystemDictionary進行清理,所以當我們在跑上面demo的時候,通過jmap -dump:live,format=b,file=heap.bin <pid>命令執行完之後,ygc的時間瞬間降下來了,不過又會慢慢回去,這是因為jmap的這個命令會做一次gc,這個gc過程會對SystemDictionary進行清理。

 

修改VM程式碼驗證


很遺憾hotspot目前沒有對ygc的每個task做一個時間的統計,因此無法直接知道是不是SH_PS_SystemDictionary_oops_do這個task導致了ygc的時間變長,為了證明這個結論,我特地修改了一下程式碼,在上面的程式碼上加了一行:

GCTraceTime t("SystemDictionary_OOPS_DO",PrintGCDetails,true,NULL);

然後重新編譯,跑我們的demo,測試結果如下:

2016-03-14T23:57:24.293+0800: [GC2016-03-14T23:57:24.294+0800: [ParNew2016-03-14T23:57:24.296+0800: [SystemDictionary_OOPS_DO, 0.0578430 secs]
: 81920K->3184K(92160K), 0.0889740 secs] 81920K->3184K(514048K), 0.0900970 secs] [Times: user=0.27 sys=0.00, real=0.09 secs]
2016-03-14T23:57:28.467+0800: [GC2016-03-14T23:57:28.468+0800: [ParNew2016-03-14T23:57:28.468+0800: [SystemDictionary_OOPS_DO, 0.0779210 secs]
: 85104K->5175K(92160K), 0.1071520 secs] 85104K->5175K(514048K), 0.1080490 secs] [Times: user=0.65 sys=0.00, real=0.11 secs]
2016-03-14T23:57:32.984+0800: [GC2016-03-14T23:57:32.984+0800: [ParNew2016-03-14T23:57:32.984+0800: [SystemDictionary_OOPS_DO, 0.1075680 secs]
: 87095K->8188K(92160K), 0.1434270 secs] 87095K->8188K(514048K), 0.1439870 secs] [Times: user=0.90 sys=0.01, real=0.14 secs]
2016-03-14T23:57:37.900+0800: [GC2016-03-14T23:57:37.900+0800: [ParNew2016-03-14T23:57:37.901+0800: [SystemDictionary_OOPS_DO, 0.1745390 secs]
: 90108K->7093K(92160K), 0.2876260 secs] 90108K->9992K(514048K), 0.2884150 secs] [Times: user=1.44 sys=0.02, real=0.29 secs]

我們會發現YGC的時間變長的時候,SystemDictionary_OOPS_DO的時間也會相應變長多少,因此驗證了我們的說法。

有同學提到如果Demo程式碼改成不new XStream,而是直接new CompositeClassLoader或CustomClassLoader則不會出問題,按照上面的分析也很容易解釋,就是因為如果直接new CustomClassLoader的話,並沒觸發loadClass這動作,而new XStream的話在構造器裡就在loadClass。

有同學提到在JDK 8中跑這個case不會出現問題,原因是:jdk8在對SystemDictionary掃描時做了優化,增加了一層cache,大大減少了需要掃描的入口數。

 

相關文章:

一個jstack/jmap等不能用的case

上篇文章中ygc越來越慢的case的原因解讀