1. 程式人生 > >G1 收集器介紹

G1 收集器介紹

來源:https://blog.csdn.net/u013542440/article/details/79358071

一. 名詞解釋

  • MetaSpace
    在Java8之後取代永久代方法區的記憶體部分,NativeMemory

  • Mixed GC Event
    所有Young Region和一部分Old Region的混合GC時間。

  • Reclaimable
    G1 為了能夠回收,建立了一系列專門用於物件回收的Region,存放在連結串列中,只包含存活率小於-XX:G1MixedGCLIveThresholdPercent(預設是85%)的region, region的值除以整個Java堆區,如果大於-XX:G1HeapWastePercent(預設5%),則啟動回收機制

  • RSet(Remember Set)
    用於跟蹤對於Region內物件的引用,外部Region到Region內部。佔整個堆區的5%。

  • CSet(Collection Set)
    收集集合。儲存一次GC中即將進行GC的Region。佔整個堆區的1%。

  • Root Region Scan
    從RS(根區間)開始的掃描,標記所有可達物件。

  • Evacution Failure
    Promotion Failure物件記憶體分配失敗。

  • Top-at-matk-start(TAMS)
    每個Region中的兩個記憶體指標。在TAMS之上的是新分配的物件。prevTAMS、nextTAMS

  • PLAB(Promoiton Local Allocation Buffers)
    避免多執行緒競爭相同的資料,每個執行緒具有PLAB,針對Survior和Old區域,用於年輕代的回收。

  • TLAB(Thead Local Allocation Buffers)
    執行緒本地分配記憶體。對於每個執行緒分配專門的一塊Eden區域,在G1中是Region。

  • Root Set(根集合)
    每個執行緒棧中,裡面的物件引用和引用指向的物件。

  • 物件存活判斷

  1. 引用計數。無法判斷迴圈引用的物件。
  2. 可達性分析。一個物件到GC Roots沒有連結時認為是不可達物件。
  3. GCRoots.虛擬機器棧引用的物件;方法區中類靜態屬性實體引用的物件;方法區中常量引用的物件;本地方法棧中JNI引用的物件
  • Minor GC
    年輕代GC

  • Major GC(Full GC)
    發生在老年代的GC

  • 物件提升規則

    1. 物件優先分配在Eden區,Eden區滿時進行一次Minor GC。
    2. 大物件直接進入老年代中,在G1中對於大於Region大小45%的物件認定為大物件。
    3. 長期存活的物件進入老年代。物件進行一次MinorGC後進入到Survior區,之後每進行一次MinorGC物件年齡加1。對於大於閾值的物件進入到老年代,Threshold預設值為15。
    4. 物件年齡動態判斷。Survior區中相同年齡的物件大小的總和大於Survior大小的一半時,大於等於該年齡的物件進入到老年代。
    5. 空間分配擔保。進行MinorGC時,JVM會計算survior區域移到老年代區域物件的平均大小,如果這個值大於老年代的剩餘大小則進行一次FullGC,之後檢查HandlePromotionFauilue邏輯,True只進行MinorGC
  • Full GC 觸發條件

    1. 老年代空間不足
    2. 永久代空間滿OOM:PermGen Space(Java8 之前)
    3. CMS GC時出現Promotion Faield和Concurrent Model Failure
    4. 統計到升到老年代的物件的大小大大於老年代剩餘的空間大小

    二. 回收演算法介紹

    1. 標記-清除演算法

    setp 1: 從根節點開始標記所有被引用的物件

    setp 2: 遍歷整個堆,清除未標記的物件

    會產生大量記憶體碎片

    2. 複製演算法

    將堆分為兩部分,每次只使用其中的一部分。遍歷當前使用的區域,把正在使用中的物件複製到另外一個區域中,只複製存活的物件。

    消除了記憶體碎片問題,同時需要兩倍的記憶體空間

    3. 標記-壓縮演算法(標記清除+複製演算法)

    step 1: 從根節點遍歷整個堆區域,標記未被引用的物件。

    setp 2: 遍歷堆,清除未被使用的物件,並把存活的物件”壓縮”到另外一個區域,按順序排放。

    消除了碎片問題,同時避免了”複製”演算法的兩倍空間,壓縮演算法主要有TWO-Finger和Lisp演算法

    4. 分代回收演算法

    將記憶體分為多個部分,不同代之間採用不同的記憶體回收策略。HostSpot採用的年輕代(Young)、老年代(Old)、永久代(Perm,Java7開始進行永久代的遷移,Java8產生了MetaSpace代替永久代,使用Native Memory,Symbols、內部字串、類靜態屬性移植到堆區域)。

    5. 增量演算法

    為了減少系統的停頓,每次回收只回收一份,基礎仍然是標記-整理演算法,

    三. 各個收集器比較

    1. Serial/Serial Old

    Serial 採用的是複製演算法,STW,序列執行,作用於年輕代的垃圾收集。Serial Old 使用標記-壓縮演算法,序列執行,作用於老年代的垃圾收集。

    2. ParNew

    ParNew是Serial收集器的多執行緒版本,STW,序列執行,作用於年輕代垃圾收集。

    3. Parallel/Paralled Old

    與ParNew收集不同的是為了避免STW時間過久,可以設定STW的閾值。STW,序列執行,採用複製演算法。
    Paralled Old採用標記-壓縮演算法,作用於老年代的垃圾收集,java1.6之後。

    4. CMS(Concurrent Mark Sweep)

    為了減少STW的時間,出現了CMS收集器,作用於老年代的垃圾收集。主要分為初始標記、併發標記、再次標記和併發清除階段,基礎仍然是標記-壓縮演算法。

    5. G1 收集器

    JAVA8之後廣泛使用,G1 將整個對區域劃分為若干個Region,每個Region的大小是2的倍數(1M,2M,4M,8M,16M,32M,通過設定堆的大小和Region數量計算得出。
    Region區域劃分與其他收集類似,不同的是單獨將大物件分配到了單獨的region中,會分配一組連續的Region區域(Humongous start 和 humonous Contoinue 組成),所以一共有四類Region(Eden,Survior,Humongous和Old),
    G1 作用於整個堆記憶體區域,設計的目的就是減少Full GC的產生。在Full GC過程中由於G1 是單執行緒進行,會產生較長時間的停頓。
    G1的OldGc標記過程可以和yongGc並行執行,但是OldGc一定在YongGc之後執行,即MixedGc在yongGC之後執行。

    四. G1 收集器介紹

    原文1:Garbage First Garbage Collector Tuning
    原文2:Getting Started with the G1 Garbage Collector

    The G1 collector takes a different approach to allocating the heap. The pictures that follow review the G1 system step by step.

    1. G1 Heap Structure

    The heap is one memory area split into many fixed sized regions.

    image
    Region size is chosen by the JVM at startup. The JVM generally targets around 2000 regions varying in size from 1 to 32Mb.

  • G1 Heap Allocation

  • In reality, these regions are mapped into logical representations of Eden, Survivor, and old generation spaces.

    image
    The colors in the picture shows which region is associated with which role. Live objects are evacuated (i.e., copied or moved) from one region to another. Regions are designed to be collected in parallel with or without stopping all other application threads.

    As shown regions can be allocated into Eden, survivor, and old generation regions. In addition, there is a fourth type of object known as Humongous regions. These regions are designed to hold objects that are 50% the size of a standard region or larger. They are stored as a set of contiguous regions. Finally the last type of regions would be the unused areas of the heap.

    Note : At the time of this writing, collecting humongous objects has not been optimized. Therefore, you should avoid creating objects of this size.

  • Young Generation in G1

  • The heap is split into approximately 2000 regions. Minimum size is 1Mb and maximum size is 32Mb. Blue regions hold old generation objects and green regions hold young generation objects.

    image

    Note that the regions are not required to be contiguous like the older garbage collectors.

  • A Young GC in G1

  • Live objects are evacuated (i.e., copied or moved) to one or more survivor regions. If the aging threshold is met, some of the objects are promoted to old generation regions.

    image

    This is a stop the world (STW) pause. Eden size and survivor size is calculated for the next young GC. Accounting information is kept to help calculate the size. Things like the pause time goal are taken into consideration.
    This approach makes it very easy to resize regions, making them bigger or smaller as needed.

  • End of a Young GC with G1

  • Live objects have been evacuated to survivor regions or to old generation regions.

    image

    Recently promoted objects are shown in dark blue. Survivor regions in green.

    In summary, the following can be said about the young generation in G1:

    • The heap is a single memory space split into regions.
    • Young generation memory is composed of a set of non-contiguous regions. This makes it easy to resize when needed.
    • Young generation garbage collections, or young GCs, are stop the world events. All application threads are stopped for the operation.
    • The young GC is done in parallel using multiple threads.
    • Live objects are copied to new survivor or old generation regions.
    • Old Generation Collection with G1
    • Like the CMS collector, the G1 collector is designed to be a low pause collector for old generation objects. The following table describes the G1 collection phases on old generation.

    G1 Collection Phases - Concurrent Marking Cycle Phases
    The G1 collector performs the following phases on the old generation of the heap. Note that some phases are part of a young generation collection.

    Phase Description
    (1) Initial Mark(Stop the World Event) This is a stop the world event. With G1, it is piggybacked on a normal young GC. Mark survivor regions (root regions) which may have references to objects in old generation.
    (2) Root Region Scanning Scan survivor regions for references into the old generation. This happens while the application continues to run. The phase must be completed before a young GC can occur.
    (3) Concurrent Marking Find live objects over the entire heap. This happens while the application is running. This phase can be interrupted by young generation garbage collections.
    (4) Remark (Stop the World Event) Completes the marking of live object in the heap. Uses an algorithm called snapshot-at-the-beginning (SATB) which is much faster than what was used in the CMS collector.
    (5) Cleanup(Stop the World Event and Concurrent) Performs accounting on live objects and completely free regions. (Stop the world) Scrubs the Remembered Sets. (Stop the world) Reset the empty regions and return them to the free list. (Concurrent)
    (*) Copying(Stop the World Event) These are the stop the world pauses to evacuate or copy live objects to new unused regions. This can be done with young generation regions which are logged as [GC pause (young)]. Or both young and old generation regions which are logged as [GC Pause (mixed)].

    With the phases defined, let’s look at how they interact with the old generation in the G1 collector.

  • Initial Marking Phase

  • Initial marking of live object is piggybacked on a young generation garbage collection. In the logs this is noted as GC pause (young)(inital-mark).

    image

  • Concurrent Marking Phase

  • If empty regions are found (as denoted by the “X”), they are removed immediately in the Remark phase. Also, “accounting” information that determines liveness is calculated.

    image

  • Remark Phase

  • Empty regions are removed and reclaimed. Region liveness is now calculated for all regions.

    image

  • Copying/Cleanup Phase

  • G1 selects the regions with the lowest “liveness”, those regions which can be collected the fastest. Then those regions are collected at the same time as a young GC. This is denoted in the logs as [GC pause (mixed)]. So both young and old generations are collected at the same time.

    image

    After Copying/Cleanup Phase

    The regions selected have been collected and compacted into the dark blue region and the dark green region shown in the diagram.

    image

    Summary of Old Generation GC
    In summary, there are a few key points we can make about the G1 garbage collection on the old generation.

    • Concurrent Marking Phase
      • Liveness information is calculated concurrently while the application is running.
      • This liveness information identifies which regions will be best to reclaim during an evacuation pause.
      • There is no sweeping phase like in CMS.
    • Remark Phase
      • Uses the Snapshot-at-the-Beginning (SATB) algorithm which is much faster then what was used with CMS.
      • Completely empty regions are reclaimed.
    • Copying/Cleanup Phase
      • Young generation and old generation are reclaimed at the same time.
      • Old generation regions are selected based on their liveness.

    五. 一次Full Gc分析

    
    [Times: user=0.26 sys=0.00, real=0.09 secs] 
    2018-01-18T16:41:33.681+0800: 7924.223: [GC concurrent-mark-end, 8.5070090 secs]// 第一次並行標記結束
    2018-01-18T16:41:33.685+0800: 7924.226: [GC remark 2018-01-18T16:41:33.685+0800: 7924.226: [Finalize Marking, 0.0038099 secs] 2018-01-18T16:41:33.689+0800: 7924.230: [GC ref-proc, 0.0005545 secs] 2018-01-18T16:41:33.689+0800: 7924.231: [Unloading, 0.0338110 secs], 0.0401638 secs]
     [Times: user=0.11 sys=0.01, real=0.04 secs] 
    2018-01-18T16:41:33.727+0800: 7924.268: [GC cleanup 5005M->4341M(6560M), 0.0048745 secs]
     [Times: user=0.01 sys=0.00, real=0.01 secs] 
    2018-01-18T16:41:33.732+0800: 7924.273: [GC concurrent-cleanup-start]
    2018-01-18T16:41:33.732+0800: 7924.274: [GC concurrent-cleanup-end, 0.0004378 secs]
    2018-01-18T16:41:34.158+0800: 7924.700: [GC pause (GCLocker Initiated GC) (young), 0.0815095 secs]
       [Parallel Time: 78.6 ms, GC Workers: 3]
          [GC Worker Start (ms): Min: 7924701.6, Avg: 7924701.6, Max: 7924701.6, Diff: 0.0]
          [Ext Root Scanning (ms): Min: 1.0, Avg: 2.5, Max: 3.3, Diff: 2.2, Sum: 7.5]
          [Update RS (ms): Min: 46.1, Avg: 46.8, Max: 47.2, Diff: 1.1, Sum: 140.5]
             [Processed Buffers: Min: 436, Avg: 444.3, Max: 454, Diff: 18, Sum: 1333]
          [Scan RS (ms): Min: 4.7, Avg: 4.7, Max: 4.8, Diff: 0.1, Sum: 14.2]
          [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [Object Copy (ms): Min: 23.2, Avg: 24.4, Max: 26.6, Diff: 3.4, Sum: 73.1]
          [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
             [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 3]
          [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [GC Worker Total (ms): Min: 78.4, Avg: 78.5, Max: 78.5, Diff: 0.0, Sum: 235.4]
          [GC Worker End (ms): Min: 7924780.0, Avg: 7924780.0, Max: 7924780.0, Diff: 0.0]
       [Code Root Fixup: 0.5 ms]
       [Code Root Purge: 0.0 ms]
       [Clear CT: 0.1 ms]
       [Other: 2.4 ms]
          [Choose CSet: 0.0 ms]
          [Ref Proc: 0.2 ms]
          [Ref Enq: 0.0 ms]
          [Redirty Cards: 0.1 ms]
          [Humongous Register: 0.1 ms]
          [Humongous Reclaim: 0.1 ms]
          [Free CSet: 0.1 ms]
       [Eden: 512.0M(496.0M)->0.0B(240.0M) Survivors: 48.0M->80.0M Heap: 4540.9M(6560.0M)->4033.1M(6560.0M)]
     [Times: user=0.23 sys=0.00, real=0.08 secs] 
    2018-01-18T16:41:34.658+0800: 7925.199: [GC pause (GCLocker Initiated GC) (mixed), 0.0639587 secs]//標記後oldgc進行,同時yonggc進行
       [Parallel Time: 60.5 ms, GC Workers: 3]
          [GC Worker Start (ms): Min: 7925201.0, Avg: 7925201.0, Max: 7925201.0, Diff: 0.0]
          [Ext Root Scanning (ms): Min: 1.7, Avg: 2.7, Max: 4.4, Diff: 2.7, Sum: 8.1]
          [Update RS (ms): Min: 20.2, Avg: 20.2, Max: 20.2, Diff: 0.1, Sum: 60.6]
             [Processed Buffers: Min: 261, Avg: 276.0, Max: 287, Diff: 26, Sum: 828]
          [Scan RS (ms): Min: 10.6, Avg: 10.6, Max: 10.7, Diff: 0.1, Sum: 31.9]
          [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [Object Copy (ms): Min: 25.2, Avg: 26.9, Max: 27.9, Diff: 2.7, Sum: 80.6]
          [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
             [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 3]
          [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [GC Worker Total (ms): Min: 60.4, Avg: 60.4, Max: 60.5, Diff: 0.0, Sum: 181.3]
          [GC Worker End (ms): Min: 7925261.5, Avg: 7925261.5, Max: 7925261.5, Diff: 0.0]
       [Code Root Fixup: 0.4 ms]
       [Code Root Purge: 0.0 ms]
       [Clear CT: 0.4 ms]
       [Other: 2.6 ms]
          [Choose CSet: 0.0 ms]
          [Ref Proc: 0.3 ms]
          [Ref Enq: 0.0 ms]
          [Redirty Cards: 0.1 ms]
          [Humongous Register: 0.1 ms]
          [Humongous Reclaim: 0.1 ms]
          [Free CSet: 0.4 ms]
       [Eden: 256.0M(240.0M)->0.0B(272.0M) Survivors: 80.0M->48.0M Heap: 4431.6M(6560.0M)->3759.1M(6560.0M)]
     [Times: user=0.18 sys=0.00, real=0.07 secs] 
    2018-01-18T16:41:34.791+0800: 7925.332: [GC pause (G1 Evacuation Pause) (mixed), 0.0659238 secs]
       [Parallel Time: 63.0 ms, GC Workers: 3]
          [GC Worker Start (ms): Min: 7925333.5, Avg: 7925333.5, Max: 7925333.6, Diff: 0.0]
          [Ext Root Scanning (ms): Min: 2.0, Avg: 2.7, Max: 3.6, Diff: 1.6, Sum: 8.2]
          [Update RS (ms): Min: 30.4, Avg: 30.6, Max: 30.9, Diff: 0.5, Sum: 91.7]
             [Processed Buffers: Min: 230, Avg: 251.7, Max: 265, Diff: 35, Sum: 755]
          [Scan RS (ms): Min: 5.0, Avg: 5.3, Max: 5.4, Diff: 0.5, Sum: 15.8]
          [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
          [Object Copy (ms): Min: 23.4, Avg: 24.3, Max: 25.0, Diff: 1.6, Sum: 72.9]
          [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
             [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 3]
          [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [GC Worker Total (ms): Min: 62.9, Avg: 62.9, Max: 62.9, Diff: 0.0, Sum: 188.8]
          [GC Worker End (ms): Min: 7925396.5, Avg: 7925396.5, Max: 7925396.5, Diff: 0.0]
       [Code Root Fixup: 0.3 ms]
       [Code Root Purge: 0.0 ms]
       [Clear CT: 0.4 ms]
       [Other: 2.2 ms]
          [Choose CSet: 0.1 ms]
          [Ref Proc: 0.2 ms]
          [Ref Enq: 0.0 ms]
          [Redirty Cards: 0.1 ms]
          [Humongous Register: 0.1 ms]
          [Humongous Reclaim: 0.0 ms]
          [Free CSet: 0.4 ms]
       [Eden: 272.0M(272.0M)->0.0B(272.0M) Survivors: 48.0M->48.0M Heap: 4121.5M(6560.0M)->3517.9M(6560.0M)]
     [Times: user=0.18 sys=0.00, real=0.07 secs] 
    2018-01-18T16:41:35.188+0800: 7925.729: [GC pause (GCLocker Initiated GC) (mixed), 0.0722678 secs]
       [Parallel Time: 68.4 ms, GC Workers: 3]
          [GC Worker Start (ms): Min: 7925731.3, Avg: 7925731.3, Max: 7925731.3, Diff: 0.0]
          [Ext Root Scanning (ms): Min: 1.4, Avg: 2.7, Max: 4.0, Diff: 2.6, Sum: 8.0]
          [Update RS (ms): Min: 18.2, Avg: 18.2, Max: 18.2, Diff: 0.0, Sum: 54.6]
             [Processed Buffers: Min: 187, Avg: 202.0, Max: 214, Diff: 27, Sum: 606]
          [Scan RS (ms): Min: 10.7, Avg: 10.8, Max: 10.8, Diff: 0.0, Sum: 32.3]
          [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [Object Copy (ms): Min: 35.4, Avg: 36.7, Max: 37.9, Diff: 2.5, Sum: 110.0]
          [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
             [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 3]
          [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [GC Worker Total (ms): Min: 68.3, Avg: 68.3, Max: 68.3, Diff: 0.0, Sum: 205.0]
          [GC Worker End (ms): Min: 7925799.6, Avg: 7925799.6, Max: 7925799.6, Diff: 0.0]
       [Code Root Fixup: 0.6 ms]
       [Code Root Purge: 0.0 ms]
       [Clear CT: 0.3 ms]
       [Other: 3.0 ms]
          [Choose CSet: 0.1 ms]
          [Ref Proc: 0.1 ms]
          [Ref Enq: 0.0 ms]
          [Redirty Cards: 0.1 ms]
          [Humongous Register: 0.4 ms]
          [Humongous Reclaim: 0.0 ms]
          [Free CSet: 0.4 ms]
       [Eden: 288.0M(272.0M)->0.0B(272.0M) Survivors: 48.0M->48.0M Heap: 3907.1M(6560.0M)->3267.0M(6560.0M)]
     [Times: user=0.21 sys=0.00, real=0.07 secs] 
    2018-01-18T16:41:35.673+0800: 7926.214: [GC pause (G1 Evacuation Pause) (mixed), 0.0721071 secs] oldGc結束
       [Parallel Time: 69.5 ms, GC Workers: 3]
          [GC Worker Start (ms): Min: 7926215.7, Avg: 7926215.8, Max: 7926215.8, Diff: 0.0]
          [Ext Root Scanning (ms): Min: 1.8, Avg: 3.2, Max: 4.4, Diff: 2.5, Sum: 9.5]
          [Update RS (ms): Min: 34.6, Avg: 34.7, Max: 34.8, Diff: 0.2, Sum: 104.0]
             [Processed Buffers: Min: 246, Avg: 261.0, Max: 273, Diff: 27, Sum: 783]
          [Scan RS (ms): Min: 1.3, Avg: 1.5, Max: 1.6, Diff: 0.3, Sum: 4.5]
          [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [Object Copy (ms): Min: 28.8, Avg: 30.0, Max: 31.3, Diff: 2.5, Sum: 90.0]
          [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
             [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 3]
          [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [GC Worker Total (ms): Min: 69.3, Avg: 69.3, Max: 69.4, Diff: 0.0, Sum: 208.0]
          [GC Worker End (ms): Min: 7926285.1, Avg: 7926285.1, Max: 7926285.1, Diff: 0.0]
       [Code Root Fixup: 0.5 ms]
       [Code Root Purge: 0.0 ms]
       [Clear CT: 0.3 ms]
       [Other: 1.9 ms]
          [Choose CSet: 0.0 ms]
          [Ref Proc: 0.1 ms]
          [Ref Enq: 0.0 ms]
          [Redirty Cards: 0.1 ms]
          [Humongous Register: 0.2 ms]
          [Humongous Reclaim: 0.0 ms]
          [Free CSet: 0.1 ms]
       [Eden: 272.0M(272.0M)->0.0B(1600.0M) Survivors: 48.0M->48.0M Heap: 3632.4M(6560.0M)->3377.3M(6560.0M)]
     [Times: user=0.22 sys=0.00, real=0.07 secs] 
    2018-01-18T16:41:35.756+0800: 7926.297: [GC pause (GCLocker Initiated GC) (young) (initial-mark), 0.0467018 secs] 再一次重新開始oldGc
       [Parallel Time: 45.3 ms, GC Workers: 3]
          [GC Worker Start (ms): Min: 7926297.8, Avg: 7926297.9, Max: 7926297.9, Diff: 0.1]
          [Ext Root Scanning (ms): Min: 1.9, Avg: 3.2, Max: 4.0, Diff: 2.1, Sum: 9.7]
          [Update RS (ms): Min: 24.0, Avg: 24.9, Max: 25.6, Diff: 1.6, Sum: 74.8]
             [Processed Buffers: Min: 45, Avg: 59.7, Max: 76, Diff: 31, Sum: 179]
          [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [Object Copy (ms): Min: 15.6, Avg: 16.9, Max: 18.0, Diff: 2.4, Sum: 50.6]
          [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
             [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 3]
          [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [GC Worker Total (ms): Min: 45.0, Avg: 45.1, Max: 45.1, Diff: 0.1, Sum: 135.2]
          [GC Worker End (ms): Min: 7926342.9, Avg: 7926342.9, Max: 7926342.9, Diff: 0.0]
       [Code Root Fixup: 0.4 ms]
       [Code Root Purge: 0.0 ms]
       [Clear CT: 0.0 ms]
       [Other: 1.0 ms]
          [Choose CSet: 0.0 ms]
          [Ref Proc: 0.2 ms]
          [Ref Enq: 0.0 ms]
          [Redirty Cards: 0.1 ms]
          [Humongous Register: 0.2 ms]
          [Humongous Reclaim: 0.0 ms]
          [Free CSet: 0.0 ms]
       [Eden: 80.0M(1600.0M)->0.0B(512.0M) Survivors: 48.0M->96.0M Heap: 3444.5M(6560.0M)->3408.1M(6560.0M)]
     [Times: user=0.13 sys=0.00, real=0.05 secs] 
    2018-01-18T16:41:35.803+0800: 7926.344: [GC concurrent-root-region-scan-start]
    2018-01-18T16:41:36.157+0800: 7926.698: [GC concurrent-root-region-scan-end, 0.3542041 secs]
    2018-01-18T16:41:36.157+0800: 7926.698: [GC concurrent-mark-start]
    2018-01-18T16:41:36.670+0800: 7927.211: [GC pause (GCLocker Initiated GC) (young), 0.0749439 secs]
       [Parallel Time: 71.8 ms, GC Workers: 3]
          [GC Worker Start (ms): Min: 7927213.3, Avg: 7927213.3, Max: 7927213.3, Diff: 0.0]
          [Ext Root Scanning (ms): Min: 1.3, Avg: 3.0, Max: 5.9, Diff: 4.6, Sum: 9.1]
          [Update RS (ms): Min: 13.5, Avg: 13.8, Max: 13.9, Diff: 0.5, Sum: 41.3]
             [Processed Buffers: Min: 171, Avg: 190.3, Max: 200, Diff: 29, Sum: 571]
          [Scan RS (ms): Min: 4.6, Avg: 4.7, Max: 4.7, Diff: 0.1, Sum: 14.0]
          [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [Object Copy (ms): Min: 47.2, Avg: 50.1, Max: 51.8, Diff: 4.5, Sum: 150.3]
          [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
             [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 3]
          [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [GC Worker Total (ms): Min: 71.7, Avg: 71.7, Max: 71.7, Diff: 0.0, Sum: 215.2]
          [GC Worker End (