1. 程式人生 > >上篇文章中ygc越來越慢的case的原因解讀

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

上篇文章中附加了一個最近碰到的奇怪的case,有位同學看到這個後周末時間折騰了下,把原因給分析出來了,分析過程很贊(無論是思路,還是工具的使用),非常感謝這位同學(阿里的一位同事,花名叫彥貝),在徵求他的同意後,我把他寫的整個問題的分析文章轉載到這裡。

文裡圖比較多,手機上不方便看的話,建議大家電腦上直接訪問http://hellojava.info看。

上分析工具VisualVM

在解決很多問題的時候,工具起的作用往往是巨大的,很多時候通過工具分析,很快便能找到原因,但是這次並沒有,下圖是VisualVM觀察到Heap上的GC圖表。

從圖表中可以看出,Perm區空間基本水平,但是Old區空間成增長態勢與YGCT時間增長的倍率基本一致。熟悉YGC的朋友都知道YGC主要分為標記和回收兩個階段,YGCT也是基於這2個階段統計的。由於每次回收的空間大小差不多,所以懷疑是標記階段使用的時間比較長,下面回顧一下JVM的垃圾標記方式。

 

JVM垃圾回收的標記方法-列舉根節點

在Java語言裡面,可作為GC Roots的節點主要在全域性性的引用(例如常量或類靜態屬性)與執行上下文(例如棧幀中的本地變量表)中。如果要使用可達性分析來判斷記憶體是否可回收,那分析工作必須在一個能保障一致性的快照中進行——這裡“一致性”的意思是整個分析期間整個執行系統看起來就像被凍結在某個時間點上,不可以出現分析過程中,物件引用關係還在不斷變化的情況,這點不滿足的話分析結果準確性就無法保證。這點也是導致GC進行時必須“Stop The World”的其中一個重要原因,即使是號稱(幾乎)不會發生停頓的CMS收集器中,列舉根節點時也是必須要停頓的。

由於目前的主流JVM使用的都是準確式GC,所以當執行系統停頓下來之後,並不需要一個不漏地檢查完所有執行上下文和全域性的引用位置,虛擬機器應當是有辦法直接得到哪些地方存放著物件引用。在HotSpot的實現中,是使用一組稱為OopMap的資料結構來達到這個目的,在類載入完成的時候,HotSpot就把物件內什麼偏移量上是什麼型別的資料計算出來,在JIT編譯過程中,也會在特定的位置記錄下棧裡和暫存器裡哪些位置是引用。這樣GC在掃描時就就可以直接得知這些資訊了。

上面這段引用自《深入理解Java虛擬機器》,用個圖簡單表示一下,當然圖也是源於書中:

基於對GC Roots的懷疑,猜測Old區中存在越來越多的gc root節點,那什麼樣的物件是root節點呢?不懂的我趕緊google了一下。

(不要看我紅色圈出來了,第一次看到這幾個嫌疑犯時我也拿不準是哪個)

為了進一步驗證是Old區的GC Roots造成YGCT 增加的,我們來做一次full gc,幹掉Old區。程式碼如下:

public class SlowYGC {
    public static void main(String[] args) throws Exception {
        int i= 0;
        while (true) {
            XStream xs = new XStream();
            xs.toString();
            xs = null;
            if(i++ % 10000 == 0)
            {
                System.gc();
            }
        }
    }
}

可以看出Full GC後 YGCT銳減到初始狀態。那是Full GC到底回收了哪些物件?進入到下一步,增加VM引數。

 

增加VM引數

為了看到Full GC前後物件的回收情況,我們增加下面2個VM引數

-XX:+PrintClassHistogramBeforeFullGC

-XX:+PrintClassHistogramAfterFullGC。

重新執行上面的程式碼,可以觀察到下面的日誌:

上圖左邊是FGC前的物件情況,右邊是FGC後的情況,結合我之前給出的GC Root候選人中的Monitor鎖,相信你很快就找到20026個[Ljava.util.concurrent.ConcurrentHashMap$Segment物件幾乎被全部回收了,ConcurrentHashMap中正是通過Segment來實現分段鎖的。那什麼邏輯會導致出現大量的Segment鎖物件。繼續看Full GC日誌com.thoughtworks.xstream.core.util.CompositeClassLoader這個物件也差不多在FGC的時候全軍覆沒,所以懷疑是ClassLoader引起的鎖競爭,下面在ClassLoader的原始碼中繼續查詢。

 

ClassLoader中的ConcurrentHashMap

 

這裡有個拿鎖的動作,跟進去看看唄。

 

為了驗證走到這塊邏輯下了一個斷點。剩下的就是putIfAbsent方法(這裡就不詳細分析實現了)有興趣的同學可以看看原始碼中CAS和tryLock的使用。

至此基本分析和定位出了YGCT原因,在去看看Xstream的建構函式。

可以看出每次new XstreamI()的同時會new一個新的ClassLoader,基本上證明了上述懷疑和猜測。

推導一下按照上述分析,應該是所有自定義的ClassLoader都會YGCT變長的時間問題,於是手寫一個ClassLoader驗證一下。Java程式碼如下:

public class TestClassLoader4YGCT {
    public static void main(String[] args) throws Exception{
        while(true)
        {
            Object obj = newObject();
            obj.toString();
            obj = null;
        }
    }

    private static Object newObject() throws Exception
    {
        ClassLoader classLoader = new ClassLoader() {
            @Override
            public Class<?> loadClass(String s) throws ClassNotFoundException {
                try{
                    String fileName = s.substring(s.lastIndexOf(".") + 1)+ ".class";
                    InputStream inputStream = getClass().getResourceAsStream(fileName);
                    if(inputStream == null){
                        return super.loadClass(s);
                    }
                    byte[] b = new byte[inputStream.available()];
                    inputStream.read(b);
                    return defineClass(s,b,0,b.length);
                }catch (Exception e)
                {
                    System.out.println(e);
                    return null;
                }
            }
        };
        Class<?> obj = classLoader.loadClass("jvmstudy.classload.TestClassLoader4YGCT");
        return obj.newInstance();
    }
}

VM 引數

-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xms512m -Xmx512m -Xmn100m -XX:+UseConcMarkSweepGC

 

GC日誌

 

結論

當大量new自定義的ClassLoader來載入時,會產生大量ClassLoader物件以及parallelLockMap(ConcurrentHashMap)物件,導致產生大量的Segment分段鎖物件,大大增加了GC Roots的數量,導致YGC中的標記時間變長。如果能直接看到YGCT的詳細使用情況,這個結論會顯得更加嚴謹。這只是我自己的一個推導,並不一定是正確答案。

 

更多深入分析

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