G1 收集器介绍「建议收藏」

全栈程序员站长

发布于 2022-09-06 18:12:05

1K0

文章被收录于专栏：全栈程序员必看全栈程序员必看

大家好，又见面了，我是你们的朋友全栈君。

G1收集器

一. 名词解释

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（根集合）每个线程栈中，里面的对象引用和引用指向的对象。
对象存活判断

引用计数。无法判断循环引用的对象。
可达性分析。一个对象到GC Roots没有链接时认为是不可达对象。
GCRoots.虚拟机栈引用的对象；方法区中类静态属性实体引用的对象；方法区中常量引用的对象；本地方法栈中JNI引用的对象

Minor GC 年轻代GC
Major GC(Full GC) 发生在老年代的GC
对象提升规则

对象优先分配在Eden区，Eden区满时进行一次Minor GC。
大对象直接进入老年代中，在G1中对于大于Region大小45%的对象认定为大对象。
长期存活的对象进入老年代。对象进行一次MinorGC后进入到Survior区，之后每进行一次MinorGC对象年龄加1。对于大于阈值的对象进入到老年代，Threshold默认值为15。
对象年龄动态判断。Survior区中相同年龄的对象大小的总和大于Survior大小的一半时，大于等于该年龄的对象进入到老年代。
空间分配担保。进行MinorGC时，JVM会计算survior区域移到老年代区域对象的平均大小，如果这个值大于老年代的剩余大小则进行一次FullGC，之后检查HandlePromotionFauilue逻辑，True只进行MinorGC

Full GC 触发条件

老年代空间不足
永久代空间满OOM：PermGen Space（Java8 之前）
CMS GC时出现Promotion Faield和Concurrent Model Failure
统计到升到老年代的对象的大小大大于老年代剩余的空间大小

二. 回收算法介绍

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收集器，作用于老年代的垃圾收集。主要分为初始标记、并发标记、再次标记和并发清除阶段，~~基础仍然是标记-压缩算法~~ 。 CMS是基于标记-清除算法，所以在清除完之后产生无法连续的内存碎片，在新对象分配的时候会采用FreeList空闲列表的方式。（感谢@qq_27976711@qin_lei的指正）

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.

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

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.

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.

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.

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.

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).

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.

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

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.

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.

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 (ms): Min: 7927285.0, Avg: 7927285.0, Max: 7927285.0, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 2.6 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 544.0M(512.0M)->0.0B(448.0M) Survivors: 96.0M->80.0M Heap: 4077.1M(6560.0M)->3597.3M(6560.0M)]
 [Times: user=0.21 sys=0.00, real=0.08 secs] 
2018-01-18T16:41:37.212+0800: 7927.754: [GC pause (GCLocker Initiated GC) (young), 0.0818139 secs]
   [Parallel Time: 78.5 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7927755.7, Avg: 7927755.7, Max: 7927755.8, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.3, Avg: 3.1, Max: 4.3, Diff: 3.0, Sum: 9.2]
      [Update RS (ms): Min: 32.3, Avg: 32.6, Max: 33.0, Diff: 0.8, Sum: 97.8]
         [Processed Buffers: Min: 267, Avg: 293.3, Max: 307, Diff: 40, Sum: 880]
      [Scan RS (ms): Min: 6.2, Avg: 6.2, Max: 6.3, Diff: 0.1, Sum: 18.7]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 34.8, Avg: 36.3, Max: 38.5, Diff: 3.7, Sum: 108.8]
      [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.4, Max: 78.4, Diff: 0.0, Sum: 235.1]
      [GC Worker End (ms): Min: 7927834.1, Avg: 7927834.1, Max: 7927834.1, Diff: 0.0]
   [Code Root Fixup: 0.5 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 2.7 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.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 464.0M(448.0M)->0.0B(336.0M) Survivors: 80.0M->80.0M Heap: 4197.1M(6560.0M)->3691.1M(6560.0M)]
 [Times: user=0.24 sys=0.01, real=0.08 secs] 
2018-01-18T16:41:38.165+0800: 7928.707: [GC pause (GCLocker Initiated GC) (young), 0.0786532 secs]
   [Parallel Time: 76.4 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7928707.7, Avg: 7928707.7, Max: 7928707.7, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.7, Avg: 2.6, Max: 3.2, Diff: 1.5, Sum: 7.8]
      [Update RS (ms): Min: 14.5, Avg: 14.9, Max: 15.1, Diff: 0.6, Sum: 44.7]
         [Processed Buffers: Min: 185, Avg: 195.3, Max: 203, Diff: 18, Sum: 586]
      [Scan RS (ms): Min: 3.6, Avg: 3.6, Max: 3.6, Diff: 0.0, Sum: 10.7]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 54.4, Avg: 55.1, Max: 56.0, Diff: 1.5, Sum: 165.2]
      [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.1]
      [GC Worker Total (ms): Min: 76.3, Avg: 76.3, Max: 76.3, Diff: 0.0, Sum: 229.0]
      [GC Worker End (ms): Min: 7928784.0, Avg: 7928784.0, Max: 7928784.0, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 1.7 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.3 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 352.0M(336.0M)->0.0B(512.0M) Survivors: 80.0M->64.0M Heap: 4118.8M(6560.0M)->3819.7M(6560.0M)]
 [Times: user=0.23 sys=0.01, real=0.08 secs] 
2018-01-18T16:41:39.164+0800: 7929.706: [GC pause (GCLocker Initiated GC) (young), 0.1240224 secs]
   [Parallel Time: 120.3 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7929708.1, Avg: 7929708.1, Max: 7929708.1, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 1.0, Avg: 2.7, Max: 3.8, Diff: 2.8, Sum: 8.0]
      [Update RS (ms): Min: 46.5, Avg: 46.8, Max: 47.3, Diff: 0.8, Sum: 140.4]
         [Processed Buffers: Min: 365, Avg: 379.3, Max: 393, Diff: 28, Sum: 1138]
      [Scan RS (ms): Min: 1.5, Avg: 1.5, Max: 1.5, Diff: 0.1, Sum: 4.6]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 67.7, Avg: 69.1, Max: 71.3, Diff: 3.6, Sum: 207.2]
      [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.1]
      [GC Worker Total (ms): Min: 120.3, Avg: 120.3, Max: 120.3, Diff: 0.0, Sum: 360.9]
      [GC Worker End (ms): Min: 7929828.4, Avg: 7929828.4, Max: 7929828.4, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 3.2 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.3 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.3 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 544.0M(512.0M)->0.0B(480.0M) Survivors: 64.0M->80.0M Heap: 4501.7M(6560.0M)->4088.9M(6560.0M)]
 [Times: user=0.36 sys=0.00, real=0.12 secs] 
2018-01-18T16:41:39.711+0800: 7930.252: [GC pause (G1 Evacuation Pause) (young), 0.5407391 secs]
   [Parallel Time: 538.6 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7930253.1, Avg: 7930253.1, Max: 7930253.1, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 2.0, Avg: 292.5, Max: 438.6, Diff: 436.5, Sum: 877.4]
      [Update RS (ms): Min: 58.1, Avg: 58.5, Max: 58.8, Diff: 0.7, Sum: 175.6]
         [Processed Buffers: Min: 272, Avg: 281.3, Max: 286, Diff: 14, Sum: 844]
      [Scan RS (ms): Min: 4.0, Avg: 4.1, Max: 4.1, Diff: 0.1, Sum: 12.3]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 37.2, Avg: 183.2, Max: 473.6, Diff: 436.5, Sum: 549.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: 538.5, Avg: 538.5, Max: 538.5, Diff: 0.0, Sum: 1615.6]
      [GC Worker End (ms): Min: 7930791.6, Avg: 7930791.6, Max: 7930791.6, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 1.6 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.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 480.0M(480.0M)->0.0B(240.0M) Survivors: 80.0M->80.0M Heap: 4667.0M(6560.0M)->4160.1M(6560.0M)]
 [Times: user=0.31 sys=0.00, real=0.55 secs] 
2018-01-18T16:41:40.300+0800: 7930.842: [GC pause (GCLocker Initiated GC) (young), 0.3669976 secs]
   [Parallel Time: 363.8 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7930843.9, Avg: 7930843.9, Max: 7930843.9, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.0, Avg: 2.6, Max: 4.0, Diff: 3.0, Sum: 7.9]
      [Update RS (ms): Min: 27.3, Avg: 28.7, Max: 29.7, Diff: 2.4, Sum: 86.2]
         [Processed Buffers: Min: 203, Avg: 213.0, Max: 223, Diff: 20, Sum: 639]
      [Scan RS (ms): Min: 6.7, Avg: 6.8, Max: 6.8, Diff: 0.0, Sum: 20.3]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 323.3, Avg: 325.5, Max: 328.7, Diff: 5.4, Sum: 976.4]
      [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: 363.8, Avg: 363.8, Max: 363.8, Diff: 0.0, Sum: 1091.3]
      [GC Worker End (ms): Min: 7931207.7, Avg: 7931207.7, Max: 7931207.7, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 2.7 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 256.0M(240.0M)->0.0B(272.0M) Survivors: 80.0M->48.0M Heap: 4491.7M(6560.0M)->4293.7M(6560.0M)]
 [Times: user=0.23 sys=0.00, real=0.37 secs] 
2018-01-18T16:41:40.732+0800: 7931.273: [GC pause (GCLocker Initiated GC) (young), 0.4720846 secs]
   [Parallel Time: 468.9 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7931275.4, Avg: 7931275.4, Max: 7931275.5, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 0.8, Avg: 2.9, Max: 5.9, Diff: 5.0, Sum: 8.6]
      [Update RS (ms): Min: 440.2, Avg: 440.4, Max: 440.7, Diff: 0.5, Sum: 1321.3]
         [Processed Buffers: Min: 324, Avg: 330.0, Max: 337, Diff: 13, Sum: 990]
      [Scan RS (ms): Min: 4.6, Avg: 4.6, Max: 4.7, Diff: 0.0, Sum: 13.9]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 17.6, Avg: 20.7, Max: 22.9, Diff: 5.3, Sum: 62.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: 468.8, Avg: 468.8, Max: 468.8, Diff: 0.0, Sum: 1406.5]
      [GC Worker End (ms): Min: 7931744.3, Avg: 7931744.3, Max: 7931744.3, Diff: 0.0]
   [Code Root Fixup: 0.3 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 2.8 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.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 288.0M(272.0M)->0.0B(272.0M) Survivors: 48.0M->48.0M Heap: 4710.5M(6560.0M)->4448.4M(6560.0M)]
 [Times: user=0.27 sys=0.01, real=0.47 secs] 
2018-01-18T16:41:41.264+0800: 7931.806: [GC pause (GCLocker Initiated GC) (young), 0.0494748 secs]
   [Parallel Time: 46.5 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7931807.5, Avg: 7931807.6, Max: 7931807.6, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.7, Avg: 2.7, Max: 4.4, Diff: 3.7, Sum: 8.0]
      [Update RS (ms): Min: 14.3, Avg: 14.5, Max: 14.8, Diff: 0.5, Sum: 43.6]
         [Processed Buffers: Min: 147, Avg: 158.3, Max: 169, Diff: 22, Sum: 475]
      [Scan RS (ms): Min: 5.5, Avg: 5.5, Max: 5.6, Diff: 0.1, Sum: 16.6]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 21.7, Avg: 23.4, Max: 25.4, Diff: 3.7, Sum: 70.2]
      [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.2]
         [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.1]
      [GC Worker Total (ms): Min: 46.4, Avg: 46.4, Max: 46.4, Diff: 0.1, Sum: 139.2]
      [GC Worker End (ms): Min: 7931854.0, Avg: 7931854.0, Max: 7931854.0, Diff: 0.0]
   [Code Root Fixup: 0.3 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 2.6 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.3 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 288.0M(272.0M)->0.0B(272.0M) Survivors: 48.0M->48.0M Heap: 4845.3M(6560.0M)->4540.8M(6560.0M)]
 [Times: user=0.14 sys=0.00, real=0.05 secs] 
2018-01-18T16:41:41.689+0800: 7932.230: [GC pause (GCLocker Initiated GC) (young), 0.0523246 secs]
   [Parallel Time: 50.0 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7932231.6, Avg: 7932231.6, Max: 7932231.6, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.7, Avg: 3.0, Max: 5.0, Diff: 3.3, Sum: 9.1]
      [Update RS (ms): Min: 12.0, Avg: 12.3, Max: 12.4, Diff: 0.4, Sum: 36.9]
         [Processed Buffers: Min: 125, Avg: 133.3, Max: 143, Diff: 18, Sum: 400]
      [Scan RS (ms): Min: 6.7, Avg: 6.8, Max: 7.0, Diff: 0.2, Sum: 20.5]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 25.8, Avg: 27.7, Max: 29.1, Diff: 3.3, Sum: 83.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: 49.9, Avg: 50.0, Max: 50.0, Diff: 0.0, Sum: 149.9]
      [GC Worker End (ms): Min: 7932281.6, Avg: 7932281.6, Max: 7932281.6, Diff: 0.0]
   [Code Root Fixup: 0.3 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 1.9 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.3 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 288.0M(272.0M)->0.0B(272.0M) Survivors: 48.0M->48.0M Heap: 4920.7M(6560.0M)->4675.9M(6560.0M)]
 [Times: user=0.15 sys=0.00, real=0.05 secs] 
2018-01-18T16:41:42.191+0800: 7932.733: [GC pause (GCLocker Initiated GC) (young), 0.0412888 secs]
   [Parallel Time: 38.6 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7932734.3, Avg: 7932734.3, Max: 7932734.3, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.1, Avg: 2.7, Max: 4.8, Diff: 3.7, Sum: 8.1]
      [Update RS (ms): Min: 8.3, Avg: 8.6, Max: 8.8, Diff: 0.4, Sum: 25.7]
         [Processed Buffers: Min: 89, Avg: 110.3, Max: 122, Diff: 33, Sum: 331]
      [Scan RS (ms): Min: 4.2, Avg: 4.2, Max: 4.2, Diff: 0.0, Sum: 12.7]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 20.7, Avg: 22.9, Max: 24.6, Diff: 3.9, Sum: 68.7]
      [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: 38.5, Avg: 38.5, Max: 38.5, Diff: 0.0, Sum: 115.6]
      [GC Worker End (ms): Min: 7932772.8, Avg: 7932772.8, Max: 7932772.8, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 2.1 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.3 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.4 ms]
      [Humongous Reclaim: 0.3 ms]
      [Free CSet: 0.1 ms]
   [Eden: 288.0M(272.0M)->0.0B(272.0M) Survivors: 48.0M->48.0M Heap: 5065.1M(6560.0M)->4803.0M(6560.0M)]
 [Times: user=0.12 sys=0.00, real=0.04 secs] 
2018-01-18T16:41:42.667+0800: 7933.209: [GC pause (GCLocker Initiated GC) (young), 0.0564448 secs]
   [Parallel Time: 53.4 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7933210.9, Avg: 7933210.9, Max: 7933210.9, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.1, Avg: 2.8, Max: 4.4, Diff: 3.3, Sum: 8.5]
      [Update RS (ms): Min: 25.4, Avg: 26.2, Max: 26.8, Diff: 1.4, Sum: 78.7]
         [Processed Buffers: Min: 255, Avg: 274.3, Max: 286, Diff: 31, Sum: 823]
      [Scan RS (ms): Min: 2.3, Avg: 2.4, Max: 2.4, Diff: 0.1, Sum: 7.1]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 19.5, Avg: 21.5, Max: 24.2, Diff: 4.6, Sum: 64.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.1]
      [GC Worker Total (ms): Min: 53.1, Avg: 53.2, Max: 53.2, Diff: 0.0, Sum: 159.5]
      [GC Worker End (ms): Min: 7933264.1, Avg: 7933264.1, Max: 7933264.1, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 2.5 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.3 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 288.0M(272.0M)->0.0B(272.0M) Survivors: 48.0M->48.0M Heap: 5179.9M(6560.0M)->4928.3M(6560.0M)]
 [Times: user=0.16 sys=0.00, real=0.06 secs] 
2018-01-18T16:41:43.161+0800: 7933.703: [GC pause (GCLocker Initiated GC) (young), 0.0439796 secs]
   [Parallel Time: 40.9 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7933704.9, Avg: 7933704.9, Max: 7933705.0, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 1.1, Avg: 2.8, Max: 4.3, Diff: 3.2, Sum: 8.4]
      [Update RS (ms): Min: 14.2, Avg: 15.0, Max: 15.6, Diff: 1.4, Sum: 45.1]
         [Processed Buffers: Min: 186, Avg: 194.3, Max: 201, Diff: 15, Sum: 583]
      [Scan RS (ms): Min: 2.5, Avg: 2.6, Max: 2.8, Diff: 0.3, Sum: 7.8]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 18.4, Avg: 20.2, Max: 22.9, Diff: 4.5, Sum: 60.7]
      [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: 40.8, Avg: 40.8, Max: 40.8, Diff: 0.1, Sum: 122.5]
      [GC Worker End (ms): Min: 7933745.8, Avg: 7933745.8, Max: 7933745.8, 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.3 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.3 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 288.0M(272.0M)->0.0B(272.0M) Survivors: 48.0M->48.0M Heap: 5305.2M(6560.0M)->5044.4M(6560.0M)]
 [Times: user=0.13 sys=0.00, real=0.04 secs] 
2018-01-18T16:41:43.231+0800: 7933.773: [GC concurrent-mark-end, 7.0744752 secs]//并行标记结束
2018-01-18T16:41:43.235+0800: 7933.777: [GC remark 2018-01-18T16:41:43.235+0800: 7933.777: [Finalize Marking, 0.0027798 secs] 2018-01-18T16:41:43.238+0800: 7933.780: [GC ref-proc, 0.0005481 secs] 2018-01-18T16:41:43.239+0800: 7933.781: [Unloading, 0.0253989 secs], 0.0309346 secs]
 [Times: user=0.08 sys=0.00, real=0.03 secs] 
2018-01-18T16:41:43.273+0800: 7933.815: [GC cleanup 5279M->3888M(6560M), 0.0037050 secs]
 [Times: user=0.01 sys=0.00, real=0.00 secs] 
2018-01-18T16:41:43.277+0800: 7933.819: [GC concurrent-cleanup-start]//并发清除
2018-01-18T16:41:43.278+0800: 7933.820: [GC concurrent-cleanup-end, 0.0010701 secs]
2018-01-18T16:41:43.659+0800: 7934.200: [GC pause (GCLocker Initiated GC) (young),   0.0574015 secs]——标记结束，后面进行mixedGC
   [Parallel Time: 55.2 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7934201.6, Avg: 7934201.6, Max: 7934201.7, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 2.3, Avg: 2.8, Max: 3.4, Diff: 1.1, Sum: 8.4]
      [Update RS (ms): Min: 28.3, Avg: 28.7, Max: 29.3, Diff: 1.0, Sum: 86.0]
         [Processed Buffers: Min: 243, Avg: 265.3, Max: 278, Diff: 35, Sum: 796]
      [Scan RS (ms): Min: 1.7, Avg: 2.4, Max: 2.7, Diff: 1.0, Sum: 7.1]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 20.7, Avg: 21.3, Max: 21.7, Diff: 1.1, Sum: 63.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: 55.1, Avg: 55.1, Max: 55.1, Diff: 0.1, Sum: 165.4]
      [GC Worker End (ms): Min: 7934256.8, Avg: 7934256.8, Max: 7934256.8, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 1.7 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: 288.0M(272.0M)->0.0B(272.0M) Survivors: 48.0M->48.0M Heap: 4033.8M(6560.0M)->3754.6M(6560.0M)]
 [Times: user=0.16 sys=0.00, real=0.06 secs] 
2018-01-18T16:41:44.164+0800: 7934.705: [GC pause (GCLocker Initiated GC) (mixed), 0.0612253 secs]
   [Parallel Time: 57.6 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7934707.2, Avg: 7934707.3, Max: 7934707.3, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.1, Avg: 2.9, Max: 5.0, Diff: 3.9, Sum: 8.6]
      [Update RS (ms): Min: 22.8, Avg: 23.5, Max: 23.8, Diff: 1.0, Sum: 70.5]
         [Processed Buffers: Min: 198, Avg: 228.0, Max: 245, Diff: 47, Sum: 684]
      [Scan RS (ms): Min: 7.1, Avg: 7.1, Max: 7.1, Diff: 0.1, Sum: 21.3]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 21.6, Avg: 24.0, Max: 26.5, Diff: 4.9, Sum: 72.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: 57.5, Avg: 57.5, Max: 57.5, Diff: 0.0, Sum: 172.5]
      [GC Worker End (ms): Min: 7934764.8, Avg: 7934764.8, Max: 7934764.8, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.5 ms]
   [Other: 2.8 ms]
      [Choose CSet: 0.1 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.5 ms]
   [Eden: 288.0M(272.0M)->0.0B(272.0M) Survivors: 48.0M->48.0M Heap: 4143.7M(6560.0M)->3257.6M(6560.0M)]
 [Times: user=0.17 sys=0.00, real=0.06 secs] 
2018-01-18T16:41:44.662+0800: 7935.204: [GC pause (G1 Evacuation Pause) (mixed), 0.0601968 secs] //Mixed Gc 清除堆
   [Parallel Time: 56.6 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7935205.3, Avg: 7935205.3, Max: 7935205.3, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.1, Avg: 2.9, Max: 4.7, Diff: 3.6, Sum: 8.7]
      [Update RS (ms): Min: 26.9, Avg: 27.3, Max: 27.7, Diff: 0.8, Sum: 82.0]
         [Processed Buffers: Min: 182, Avg: 213.7, Max: 243, Diff: 61, Sum: 641]
      [Scan RS (ms): Min: 4.5, Avg: 4.7, Max: 4.8, Diff: 0.3, Sum: 14.1]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [Object Copy (ms): Min: 19.6, Avg: 21.6, Max: 23.7, Diff: 4.1, Sum: 64.8]
      [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: 56.5, Avg: 56.5, Max: 56.5, Diff: 0.0, Sum: 169.6]
      [GC Worker End (ms): Min: 7935261.8, Avg: 7935261.8, Max: 7935261.8, Diff: 0.0]
   [Code Root Fixup: 0.5 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.5 ms]
   [Other: 2.6 ms]
      [Choose CSet: 0.1 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.4 ms]
   [Eden: 272.0M(272.0M)->0.0B(1296.0M) Survivors: 48.0M->48.0M Heap: 3587.9M(6560.0M)->3001.5M(6560.0M)]
 [Times: user=0.18 sys=0.00, real=0.06 secs] 
2018-01-18T16:41:44.726+0800: 7935.268: [GC pause (G1 Humongous Allocation) (young) (initial-mark), 0.0316910 secs]。由于大对象分配 重新开始初始化标记开始 old GC
   [Parallel Time: 30.5 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7935268.6, Avg: 7935268.6, Max: 7935268.7, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 3.2, Avg: 3.9, Max: 4.3, Diff: 1.1, Sum: 11.7]
      [Update RS (ms): Min: 20.3, Avg: 20.3, Max: 20.3, Diff: 0.0, Sum: 60.9]
         [Processed Buffers: Min: 35, Avg: 43.0, Max: 55, Diff: 20, Sum: 129]
      [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: 5.6, Avg: 6.0, Max: 6.8, Diff: 1.1, Sum: 18.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.1]
      [GC Worker Total (ms): Min: 30.2, Avg: 30.3, Max: 30.3, Diff: 0.1, Sum: 90.8]
      [GC Worker End (ms): Min: 7935298.9, Avg: 7935298.9, Max: 7935298.9, Diff: 0.0]
   [Code Root Fixup: 0.5 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.0 ms]
   [Other: 0.6 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.0 ms]
   [Eden: 16.0M(1296.0M)->0.0B(800.0M) Survivors: 48.0M->64.0M Heap: 3017.5M(6560.0M)->2996.6M(6560.0M)]
 [Times: user=0.09 sys=0.00, real=0.03 secs] 
 2018-01-18T16:41:44.758+0800: 7935.300: [GC concurrent-root-region-scan-start]// 并行标记RS
2018-01-18T16:41:44.772+0800: 7935.314: [GC concurrent-root-region-scan-end, 0.0141398 secs]  //并行标记RSEnd
2018-01-18T16:41:44.772+0800: 7935.314: [GC concurrent-mark-start] //并行标记开始
2018-01-18T16:41:45.697+0800: 7936.239: [GC pause (G1 Evacuation Pause) (young), 0.0887764 secs]
   [Parallel Time: 85.4 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7936241.1, Avg: 7936241.2, Max: 7936241.2, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.9, Avg: 2.8, Max: 4.2, Diff: 2.4, Sum: 8.4]
      [Update RS (ms): Min: 11.5, Avg: 11.8, Max: 12.0, Diff: 0.5, Sum: 35.4]
         [Processed Buffers: Min: 120, Avg: 143.7, Max: 163, Diff: 43, Sum: 431]
      [Scan RS (ms): Min: 12.0, Avg: 12.0, Max: 12.1, Diff: 0.0, Sum: 36.1]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 57.0, Avg: 58.4, Max: 59.4, Diff: 2.3, Sum: 175.2]
      [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: 85.3, Avg: 85.3, Max: 85.3, Diff: 0.0, Sum: 255.9]
      [GC Worker End (ms): Min: 7936326.4, Avg: 7936326.4, Max: 7936326.4, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 2.8 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 800.0M(800.0M)->0.0B(224.0M) Survivors: 64.0M->112.0M Heap: 3963.7M(6560.0M)->3181.8M(6560.0M)]
 [Times: user=0.26 sys=0.00, real=0.09 secs] 
2018-01-18T16:41:46.193+0800: 7936.735: [GC pause (GCLocker Initiated GC) (young), 0.0939753 secs]
   [Parallel Time: 90.5 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7936737.2, Avg: 7936737.2, Max: 7936737.2, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.1, Avg: 2.5, Max: 3.8, Diff: 2.7, Sum: 7.6]
      [Update RS (ms): Min: 34.0, Avg: 34.3, Max: 34.7, Diff: 0.7, Sum: 103.0]
         [Processed Buffers: Min: 255, Avg: 280.0, Max: 297, Diff: 42, Sum: 840]
      [Scan RS (ms): Min: 6.8, Avg: 6.8, Max: 6.9, Diff: 0.1, Sum: 20.5]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 45.1, Avg: 46.6, Max: 48.5, Diff: 3.4, Sum: 139.7]
      [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: 90.4, Avg: 90.5, Max: 90.5, Diff: 0.0, Sum: 271.4]
      [GC Worker End (ms): Min: 7936827.7, Avg: 7936827.7, Max: 7936827.7, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 2.9 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 256.0M(224.0M)->0.0B(432.0M) Survivors: 112.0M->48.0M Heap: 3537.5M(6560.0M)->3299.3M(6560.0M)]
 [Times: user=0.27 sys=0.00, real=0.09 secs] 
2018-01-18T16:41:47.178+0800: 7937.720: [GC pause (GCLocker Initiated GC) (young), 0.0995459 secs]
   [Parallel Time: 96.5 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7937721.3, Avg: 7937721.4, Max: 7937721.4, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 1.8, Avg: 3.7, Max: 5.3, Diff: 3.6, Sum: 11.2]
      [Update RS (ms): Min: 44.2, Avg: 44.9, Max: 45.3, Diff: 1.1, Sum: 134.8]
         [Processed Buffers: Min: 174, Avg: 221.3, Max: 246, Diff: 72, Sum: 664]
      [Scan RS (ms): Min: 2.3, Avg: 2.6, Max: 3.0, Diff: 0.7, Sum: 7.7]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 43.5, Avg: 44.9, Max: 46.4, Diff: 2.9, Sum: 134.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: 96.4, Avg: 96.5, Max: 96.5, Diff: 0.1, Sum: 289.4]
      [GC Worker End (ms): Min: 7937817.8, Avg: 7937817.8, Max: 7937817.8, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 2.6 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 448.0M(432.0M)->0.0B(480.0M) Survivors: 48.0M->64.0M Heap: 3848.4M(6560.0M)->3456.0M(6560.0M)]
 [Times: user=0.29 sys=0.01, real=0.10 secs] 
2018-01-18T16:41:48.164+0800: 7938.705: [GC pause (GCLocker Initiated GC) (young), 0.0903180 secs]
   [Parallel Time: 86.6 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7938707.6, Avg: 7938707.6, Max: 7938707.6, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 1.3, Avg: 3.3, Max: 5.2, Diff: 3.9, Sum: 10.0]
      [Update RS (ms): Min: 37.1, Avg: 37.7, Max: 38.4, Diff: 1.3, Sum: 113.2]
         [Processed Buffers: Min: 198, Avg: 217.7, Max: 231, Diff: 33, Sum: 653]
      [Scan RS (ms): Min: 3.4, Avg: 3.4, Max: 3.5, Diff: 0.1, Sum: 10.2]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 39.5, Avg: 41.7, Max: 44.6, Diff: 5.1, Sum: 125.2]
      [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.2]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 3]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.0, Sum: 0.2]
      [GC Worker Total (ms): Min: 86.5, Avg: 86.5, Max: 86.6, Diff: 0.1, Sum: 259.6]
      [GC Worker End (ms): Min: 7938794.1, Avg: 7938794.1, Max: 7938794.1, Diff: 0.0]
   [Code Root Fixup: 0.5 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 3.0 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.3 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 512.0M(480.0M)->0.0B(528.0M) Survivors: 64.0M->80.0M Heap: 4083.6M(6560.0M)->3597.6M(6560.0M)]
 [Times: user=0.26 sys=0.00, real=0.09 secs] 
2018-01-18T16:41:48.700+0800: 7939.241: [GC pause (G1 Evacuation Pause) (young), 0.0856401 secs]
   [Parallel Time: 80.6 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7939245.1, Avg: 7939245.1, Max: 7939245.2, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 1.1, Avg: 2.6, Max: 4.3, Diff: 3.2, Sum: 7.8]
      [Update RS (ms): Min: 25.0, Avg: 25.3, Max: 25.6, Diff: 0.6, Sum: 76.0]
         [Processed Buffers: Min: 259, Avg: 265.3, Max: 269, Diff: 10, Sum: 796]
      [Scan RS (ms): Min: 7.4, Avg: 7.5, Max: 7.5, Diff: 0.1, Sum: 22.4]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 43.2, Avg: 44.9, Max: 46.4, Diff: 3.1, Sum: 134.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.1]
      [GC Worker Total (ms): Min: 80.5, Avg: 80.5, Max: 80.5, Diff: 0.1, Sum: 241.5]
      [GC Worker End (ms): Min: 7939325.6, Avg: 7939325.6, Max: 7939325.6, Diff: 0.0]
   [Code Root Fixup: 0.5 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 4.4 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.9 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.2 ms]
   [Eden: 528.0M(528.0M)->0.0B(608.0M) Survivors: 80.0M->80.0M Heap: 4295.7M(6560.0M)->3783.3M(6560.0M)]
 [Times: user=0.24 sys=0.00, real=0.09 secs] 
2018-01-18T16:41:49.683+0800: 7940.225: [GC pause (GCLocker Initiated GC) (young), 0.0858164 secs]
   [Parallel Time: 83.3 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7940225.8, Avg: 7940225.8, Max: 7940225.8, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.8, Avg: 2.7, Max: 3.3, Diff: 1.5, Sum: 8.2]
      [Update RS (ms): Min: 30.1, Avg: 30.5, Max: 30.6, Diff: 0.5, Sum: 91.4]
         [Processed Buffers: Min: 230, Avg: 249.0, Max: 264, Diff: 34, Sum: 747]
      [Scan RS (ms): Min: 5.9, Avg: 5.9, Max: 6.0, Diff: 0.1, Sum: 17.7]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 43.4, Avg: 43.9, Max: 44.8, Diff: 1.4, Sum: 131.7]
      [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.1]
      [GC Worker Total (ms): Min: 83.2, Avg: 83.2, Max: 83.2, Diff: 0.0, Sum: 249.6]
      [GC Worker End (ms): Min: 7940309.0, Avg: 7940309.0, Max: 7940309.0, Diff: 0.0]
   [Code Root Fixup: 0.5 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 1.9 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.3 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 624.0M(608.0M)->0.0B(704.0M) Survivors: 80.0M->96.0M Heap: 4528.3M(6560.0M)->3945.1M(6560.0M)]
 [Times: user=0.25 sys=0.00, real=0.08 secs] 
2018-01-18T16:41:50.689+0800: 7941.231: [GC pause (GCLocker Initiated GC) (young), 0.1015273 secs]
   [Parallel Time: 98.9 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7941231.7, Avg: 7941231.8, Max: 7941231.8, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 1.2, Avg: 2.6, Max: 3.9, Diff: 2.7, Sum: 7.8]
      [Update RS (ms): Min: 32.8, Avg: 34.4, Max: 35.5, Diff: 2.7, Sum: 103.3]
         [Processed Buffers: Min: 225, Avg: 241.0, Max: 256, Diff: 31, Sum: 723]
      [Scan RS (ms): Min: 9.3, Avg: 9.6, Max: 9.9, Diff: 0.6, Sum: 28.7]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 49.8, Avg: 51.8, Max: 54.6, Diff: 4.8, Sum: 155.4]
      [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: 98.6, Avg: 98.6, Max: 98.6, Diff: 0.1, Sum: 295.8]
      [GC Worker End (ms): Min: 7941330.3, Avg: 7941330.3, Max: 7941330.3, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 2.0 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.2 ms]
      [Free CSet: 0.2 ms]
   [Eden: 736.0M(704.0M)->0.0B(592.0M) Survivors: 96.0M->112.0M Heap: 4867.5M(6560.0M)->4104.3M(6560.0M)]
 [Times: user=0.30 sys=0.01, real=0.10 secs] 
2018-01-18T16:41:51.701+0800: 7942.242: [GC pause (GCLocker Initiated GC) (young), 0.0843856 secs]
   [Parallel Time: 81.0 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7942244.2, Avg: 7942244.2, Max: 7942244.2, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.2, Avg: 2.8, Max: 5.7, Diff: 4.6, Sum: 8.4]
      [Update RS (ms): Min: 14.1, Avg: 14.7, Max: 15.3, Diff: 1.2, Sum: 44.0]
         [Processed Buffers: Min: 165, Avg: 181.7, Max: 193, Diff: 28, Sum: 545]
      [Scan RS (ms): Min: 10.5, Avg: 10.6, Max: 10.6, Diff: 0.1, Sum: 31.7]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 49.3, Avg: 52.7, Max: 55.1, Diff: 5.8, Sum: 158.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: 80.9, Avg: 80.9, Max: 80.9, Diff: 0.0, Sum: 242.7]
      [GC Worker End (ms): Min: 7942325.0, Avg: 7942325.0, Max: 7942325.1, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 2.9 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.3 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 640.0M(592.0M)->0.0B(512.0M) Survivors: 112.0M->96.0M Heap: 4934.4M(6560.0M)->4300.7M(6560.0M)]
 [Times: user=0.24 sys=0.00, real=0.09 secs] 
2018-01-18T16:41:52.672+0800: 7943.214: [GC pause (GCLocker Initiated GC) (young), 0.1060453 secs]
   [Parallel Time: 102.6 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7943215.8, Avg: 7943215.8, Max: 7943215.8, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.4, Avg: 2.8, Max: 4.8, Diff: 3.5, Sum: 8.4]
      [Update RS (ms): Min: 44.4, Avg: 44.7, Max: 44.9, Diff: 0.5, Sum: 134.2]
         [Processed Buffers: Min: 261, Avg: 276.7, Max: 285, Diff: 24, Sum: 830]
      [Scan RS (ms): Min: 6.6, Avg: 6.6, Max: 6.7, Diff: 0.1, Sum: 19.9]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 46.2, Avg: 48.2, Max: 49.6, Diff: 3.4, Sum: 144.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: 102.5, Avg: 102.5, Max: 102.6, Diff: 0.0, Sum: 307.6]
      [GC Worker End (ms): Min: 7943318.4, Avg: 7943318.4, Max: 7943318.4, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 2.9 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.3 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.8 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 544.0M(512.0M)->0.0B(320.0M) Survivors: 96.0M->80.0M Heap: 4976.5M(6560.0M)->4467.7M(6560.0M)]
 [Times: user=0.31 sys=0.00, real=0.10 secs] 
2018-01-18T16:41:53.171+0800: 7943.713: [GC pause (GCLocker Initiated GC) (young), 0.0834187 secs]
   [Parallel Time: 80.9 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7943714.3, Avg: 7943714.3, Max: 7943714.3, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 1.3, Avg: 3.0, Max: 5.0, Diff: 3.7, Sum: 8.9]
      [Update RS (ms): Min: 40.8, Avg: 41.3, Max: 42.0, Diff: 1.2, Sum: 124.0]
         [Processed Buffers: Min: 159, Avg: 188.0, Max: 204, Diff: 45, Sum: 564]
      [Scan RS (ms): Min: 3.5, Avg: 3.7, Max: 3.8, Diff: 0.3, Sum: 11.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 30.4, Avg: 32.7, Max: 35.0, Diff: 4.6, Sum: 98.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.1]
      [GC Worker Total (ms): Min: 80.8, Avg: 80.8, Max: 80.9, Diff: 0.1, Sum: 242.5]
      [GC Worker End (ms): Min: 7943795.1, Avg: 7943795.1, Max: 7943795.1, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 2.0 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 352.0M(320.0M)->0.0B(256.0M) Survivors: 80.0M->64.0M Heap: 4907.1M(6560.0M)->4555.8M(6560.0M)]
 [Times: user=0.24 sys=0.00, real=0.08 secs] 
2018-01-18T16:41:53.666+0800: 7944.208: [GC pause (GCLocker Initiated GC) (young), 0.0506961 secs]
   [Parallel Time: 48.8 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7944208.8, Avg: 7944208.8, Max: 7944208.9, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 1.4, Avg: 2.7, Max: 3.6, Diff: 2.2, Sum: 8.1]
      [Update RS (ms): Min: 16.7, Avg: 17.0, Max: 17.1, Diff: 0.4, Sum: 50.9]
         [Processed Buffers: Min: 86, Avg: 100.7, Max: 109, Diff: 23, Sum: 302]
      [Scan RS (ms): Min: 3.7, Avg: 3.7, Max: 3.7, Diff: 0.0, Sum: 11.1]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 24.4, Avg: 25.2, Max: 26.4, Diff: 2.0, Sum: 75.5]
      [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: 48.7, Avg: 48.7, Max: 48.7, Diff: 0.1, Sum: 146.1]
      [GC Worker End (ms): Min: 7944257.5, Avg: 7944257.5, Max: 7944257.5, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 1.3 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.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 272.0M(256.0M)->0.0B(272.0M) Survivors: 64.0M->48.0M Heap: 4869.2M(6560.0M)->4626.8M(6560.0M)]
 [Times: user=0.15 sys=0.00, real=0.05 secs] 
2018-01-18T16:41:54.185+0800: 7944.726: [GC pause (G1 Evacuation Pause) (young), 0.0643077 secs]
   [Parallel Time: 61.7 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7944727.9, Avg: 7944727.9, Max: 7944727.9, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.1, Avg: 2.7, Max: 4.1, Diff: 3.0, Sum: 8.1]
      [Update RS (ms): Min: 25.5, Avg: 25.9, Max: 26.4, Diff: 0.9, Sum: 77.6]
         [Processed Buffers: Min: 212, Avg: 215.0, Max: 218, Diff: 6, Sum: 645]
      [Scan RS (ms): Min: 2.3, Avg: 2.3, Max: 2.3, Diff: 0.0, Sum: 6.9]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 28.9, Avg: 30.6, Max: 32.8, Diff: 3.9, Sum: 91.8]
      [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: 61.6, Avg: 61.6, Max: 61.6, Diff: 0.0, Sum: 184.9]
      [GC Worker End (ms): Min: 7944789.5, Avg: 7944789.5, Max: 7944789.5, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 2.1 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.3 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 272.0M(272.0M)->0.0B(272.0M) Survivors: 48.0M->48.0M Heap: 4998.4M(6560.0M)->4778.8M(6560.0M)]
 [Times: user=0.19 sys=0.00, real=0.06 secs] 
2018-01-18T16:41:54.664+0800: 7945.206: [GC pause (GCLocker Initiated GC) (young), 0.0656294 secs]
   [Parallel Time: 61.9 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7945208.4, Avg: 7945208.4, Max: 7945208.4, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 1.2, Avg: 2.7, Max: 4.8, Diff: 3.6, Sum: 8.2]
      [Update RS (ms): Min: 38.0, Avg: 38.3, Max: 38.4, Diff: 0.4, Sum: 114.9]
         [Processed Buffers: Min: 213, Avg: 224.7, Max: 242, Diff: 29, Sum: 674]
      [Scan RS (ms): Min: 0.8, Avg: 0.8, Max: 0.8, Diff: 0.1, Sum: 2.4]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 17.8, Avg: 19.9, Max: 21.4, Diff: 3.6, Sum: 59.7]
      [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: 61.9, Avg: 61.9, Max: 61.9, Diff: 0.0, Sum: 185.6]
      [GC Worker End (ms): Min: 7945270.3, Avg: 7945270.3, Max: 7945270.3, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 3.1 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.9 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 288.0M(272.0M)->0.0B(272.0M) Survivors: 48.0M->48.0M Heap: 5134.3M(6560.0M)->4865.4M(6560.0M)]
 [Times: user=0.19 sys=0.00, real=0.06 secs] 
2018-01-18T16:41:55.162+0800: 7945.704: [GC pause (G1 Evacuation Pause) (young), 0.0492854 secs]
   [Parallel Time: 46.5 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7945705.6, Avg: 7945705.6, Max: 7945705.6, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.7, Avg: 2.7, Max: 4.0, Diff: 2.4, Sum: 8.1]
      [Update RS (ms): Min: 18.6, Avg: 18.9, Max: 19.1, Diff: 0.5, Sum: 56.7]
         [Processed Buffers: Min: 179, Avg: 200.0, Max: 217, Diff: 38, Sum: 600]
      [Scan RS (ms): Min: 2.1, Avg: 2.5, Max: 3.1, Diff: 1.0, Sum: 7.4]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 20.3, Avg: 22.3, Max: 23.6, Diff: 3.3, Sum: 66.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: 46.5, Avg: 46.5, Max: 46.5, Diff: 0.0, Sum: 139.5]
      [GC Worker End (ms): Min: 7945752.1, Avg: 7945752.1, Max: 7945752.1, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 2.2 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.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 288.0M(272.0M)->0.0B(272.0M) Survivors: 48.0M->48.0M Heap: 5225.4M(6560.0M)->4948.6M(6560.0M)]
 [Times: user=0.15 sys=0.00, real=0.05 secs] 
2018-01-18T16:41:55.659+0800: 7946.201: [GC pause (GCLocker Initiated GC) (young) (to-space exhausted), 0.1416608 secs]
   [Parallel Time: 53.4 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7946202.7, Avg: 7946202.7, Max: 7946202.7, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 2.3, Avg: 2.8, Max: 3.2, Diff: 0.9, Sum: 8.3]
      [Update RS (ms): Min: 18.7, Avg: 18.8, Max: 18.9, Diff: 0.2, Sum: 56.3]
         [Processed Buffers: Min: 192, Avg: 224.7, Max: 249, Diff: 57, Sum: 674]
      [Scan RS (ms): Min: 2.6, Avg: 3.0, Max: 3.2, Diff: 0.7, Sum: 9.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 28.2, Avg: 28.6, Max: 29.1, Diff: 0.9, Sum: 85.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: 53.3, Avg: 53.4, Max: 53.4, Diff: 0.0, Sum: 160.1]
      [GC Worker End (ms): Min: 7946256.1, Avg: 7946256.1, Max: 7946256.1, Diff: 0.0]
   [Code Root Fixup: 0.5 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 87.6 ms]
      [Evacuation Failure: 84.9 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.3 ms]
      [Humongous Register: 0.3 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.0 ms]
   [Eden: 288.0M(272.0M)->0.0B(272.0M) Survivors: 48.0M->48.0M Heap: 5317.8M(6560.0M)->5346.2M(6560.0M)]
 [Times: user=0.40 sys=0.00, real=0.14 secs] 
2018-01-18T16:41:55.816+0800: 7946.358: [GC pause (GCLocker Initiated GC) (young) (to-space exhausted), 0.1649153 secs]
   [Parallel Time: 131.2 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7946358.4, Avg: 7946358.4, Max: 7946358.4, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.8, Avg: 2.6, Max: 3.7, Diff: 1.9, Sum: 7.7]
      [Update RS (ms): Min: 27.4, Avg: 27.6, Max: 27.7, Diff: 0.4, Sum: 82.8]
         [Processed Buffers: Min: 102, Avg: 111.7, Max: 118, Diff: 16, Sum: 335]
      [Scan RS (ms): Min: 1.6, Avg: 1.7, Max: 1.9, Diff: 0.2, Sum: 5.2]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 97.9, Avg: 99.2, Max: 100.0, Diff: 2.1, Sum: 297.5]
      [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: 131.2, Avg: 131.2, Max: 131.2, Diff: 0.0, Sum: 393.6]
      [GC Worker End (ms): Min: 7946489.6, Avg: 7946489.6, Max: 7946489.6, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 33.2 ms]
      [Evacuation Failure: 31.9 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.0 ms]
   [Eden: 80.0M(272.0M)->0.0B(320.0M) Survivors: 48.0M->0.0B Heap: 5436.9M(6560.0M)->5418.5M(6560.0M)]
 [Times: user=0.27 sys=0.00, real=0.16 secs] 
2018-01-18T16:41:55.985+0800: 7946.526: [GC pause (G1 Evacuation Pause) (young) (to-space exhausted), 0.0400241 secs]// Promotion Failure 提升失败
   [Parallel Time: 23.0 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7946526.7, Avg: 7946526.8, Max: 7946526.8, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 2.3, Avg: 3.1, Max: 4.3, Diff: 2.0, Sum: 9.2]
      [Update RS (ms): Min: 9.6, Avg: 9.8, Max: 9.9, Diff: 0.3, Sum: 29.4]
         [Processed Buffers: Min: 46, Avg: 50.7, Max: 55, Diff: 9, Sum: 152]
      [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: 8.8, Avg: 10.0, Max: 10.7, Diff: 2.0, Sum: 29.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: 22.9, Avg: 22.9, Max: 23.0, Diff: 0.0, Sum: 68.8]
      [GC Worker End (ms): Min: 7946549.7, Avg: 7946549.7, Max: 7946549.7, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.0 ms]
   [Other: 16.6 ms]
      [Evacuation Failure: 15.8 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.0 ms]
   [Eden: 16.0M(320.0M)->0.0B(320.0M) Survivors: 0.0B->0.0B Heap: 5443.7M(6560.0M)->5443.7M(6560.0M)]
 [Times: user=0.06 sys=0.01, real=0.04 secs] 
2018-01-18T16:41:56.027+0800: 7946.568: [GC pause (G1 Evacuation Pause) (young), 0.0063659 secs]
   [Parallel Time: 5.4 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7946568.6, Avg: 7946568.6, Max: 7946568.6, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 2.8, Avg: 2.8, Max: 2.9, Diff: 0.2, Sum: 8.5]
      [Update RS (ms): Min: 2.1, Avg: 2.2, Max: 2.2, Diff: 0.1, Sum: 6.5]
         [Processed Buffers: Min: 7, Avg: 9.3, Max: 13, Diff: 6, Sum: 28]
      [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: 0.1, Avg: 0.2, Max: 0.2, Diff: 0.2, Sum: 0.5]
      [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.2]
         [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: 5.3, Avg: 5.3, Max: 5.3, Diff: 0.0, Sum: 16.0]
      [GC Worker End (ms): Min: 7946573.9, Avg: 7946573.9, Max: 7946573.9, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.0 ms]
   [Other: 0.6 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.2 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.0 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.0 ms]
   [Eden: 0.0B(320.0M)->0.0B(320.0M) Survivors: 0.0B->0.0B Heap: 5443.7M(6560.0M)->5443.7M(6560.0M)]
 [Times: user=0.01 sys=0.00, real=0.01 secs] 
2018-01-18T16:41:56.034+0800: 7946.576: [GC pause (G1 Evacuation Pause) (young), 0.0042370 secs]
   [Parallel Time: 3.2 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7946576.1, Avg: 7946576.1, Max: 7946576.1, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 2.3, Avg: 2.4, Max: 2.5, Diff: 0.2, Sum: 7.1]
      [Update RS (ms): Min: 0.0, Avg: 0.2, Max: 0.5, Diff: 0.5, Sum: 0.5]
         [Processed Buffers: Min: 0, Avg: 0.7, Max: 1, Diff: 1, Sum: 2]
      [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: 0.1, Avg: 0.2, Max: 0.2, Diff: 0.2, Sum: 0.5]
      [Termination (ms): Min: 0.0, Avg: 0.3, Max: 0.6, Diff: 0.6, Sum: 1.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: 3.1, Avg: 3.1, Max: 3.1, Diff: 0.0, Sum: 9.3]
      [GC Worker End (ms): Min: 7946579.2, Avg: 7946579.2, Max: 7946579.2, Diff: 0.0]
   [Code Root Fixup: 0.5 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.5 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.0 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.0 ms]
   [Eden: 0.0B(320.0M)->0.0B(320.0M) Survivors: 0.0B->0.0B Heap: 5443.7M(6560.0M)->5443.7M(6560.0M)]
 [Times: user=0.01 sys=0.00, real=0.00 secs] 
2018-01-18T16:41:56.039+0800: 7946.581: [GC pause (G1 Evacuation Pause) (young), 0.0032436 secs]
   [Parallel Time: 2.5 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7946581.0, Avg: 7946581.0, Max: 7946581.0, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.8, Avg: 1.8, Max: 1.9, Diff: 0.1, Sum: 5.5]
      [Update RS (ms): Min: 0.0, Avg: 0.2, Max: 0.5, Diff: 0.5, Sum: 0.5]
         [Processed Buffers: Min: 0, Avg: 0.7, Max: 1, Diff: 1, Sum: 2]
      [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: 0.1, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 0.4]
      [Termination (ms): Min: 0.0, Avg: 0.3, Max: 0.5, Diff: 0.5, Sum: 0.8]
         [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: 2.4, Avg: 2.4, Max: 2.4, Diff: 0.0, Sum: 7.3]
      [GC Worker End (ms): Min: 7946583.4, Avg: 7946583.4, Max: 7946583.4, Diff: 0.0]
   [Code Root Fixup: 0.4 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.0 ms]
   [Other: 0.4 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.0 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.0 ms]
   [Eden: 0.0B(320.0M)->0.0B(320.0M) Survivors: 0.0B->0.0B Heap: 5443.7M(6560.0M)->5443.7M(6560.0M)]
 [Times: user=0.00 sys=0.00, real=0.01 secs] 
2018-01-18T16:41:56.043+0800: 7946.585: [GC pause (G1 Evacuation Pause) (young), 0.0033300 secs]
   [Parallel Time: 2.6 ms, GC Workers: 3]
      [GC Worker Start (ms): Min: 7946585.1, Avg: 7946585.1, Max: 7946585.1, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 1.8, Avg: 1.9, Max: 1.9, Diff: 0.1, Sum: 5.6]
      [Update RS (ms): Min: 0.0, Avg: 0.2, Max: 0.5, Diff: 0.5, Sum: 0.5]
         [Processed Buffers: Min: 0, Avg: 1.3, Max: 3, Diff: 3, Sum: 4]
      [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: 0.1, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 0.4]
      [Termination (ms): Min: 0.0, Avg: 0.3, Max: 0.5, Diff: 0.5, Sum: 0.9]
         [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: 2.4, Avg: 2.5, Max: 2.5, Diff: 0.0, Sum: 7.4]
      [GC Worker End (ms): Min: 7946587.5, Avg: 7946587.6, Max: 7946587.6, Diff: 0.0]
   [Code Root Fixup: 0.3 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.0 ms]
   [Other: 0.4 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.0 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.0 ms]
   [Eden: 0.0B(320.0M)->0.0B(320.0M) Survivors: 0.0B->0.0B Heap: 5443.7M(6560.0M)->5443.7M(6560.0M)]
 [Times: user=0.00 sys=0.00, real=0.00 secs] 
2018-01-18T16:41:56.047+0800: 7946.589: [Full GC (Allocation Failure)  5443M->791M(6560M), 1.1463336 secs]。//此时 由于大对象分配的 标记过程还在进行，没有oldgc，但堆已经满了，进行fullgc

发布者：全栈程序员栈长，转载请注明出处：https://javaforall.cn/134212.html原文链接：https://javaforall.cn

本文参与腾讯云自媒体同步曝光计划，分享自作者个人站点/博客。

原始发表：2022年6月7，如有侵权请联系 cloudcommunity@tencent.com 删除

编程算法