向前迈进！走入GC世界：G1 GC原理深入解析

第零章：名词解释

mutator：应用线程

STW：Stop-The-World，指除了GC线程，其它所有线程全部暂停的一段时间

并发：指代GC线程与mutator在同一时刻执行任务

并行：指代多个GC线程在同一时刻执行任务

Young GC：新生代回收

Mixed GC：混合回收

Full GC：整堆回收

第一章：G1基本概念

这里介绍的主要是一些老生常谈的内容，比较熟悉的同学可以直接跳过本部分内容

G1的目标

G1作为一个增量垃圾回收器，致力于保证高吞吐量与软实时性的最佳平衡，其应用场景最好需要包含以下特性（满足这些特性的话，则可能更适合G1出马，否则可能其他GC更合适）：

• 堆内存大小超过10G，且存活对象占用比例超过50%
• 对象分配和晋升速率可能随时间有显著变化
• 堆中存在大量碎片
• 预测的最大停顿时间不超过几百毫秒

对于其它垃圾回收器来说，由于整堆回收的特性和缺乏启发式调整的机制，导致其无法很好的应付上述场景，而G1由于开创性的停顿预测模型与独特的堆结构，则恰恰相反。

增量GC：通过慢慢GC来缩短mutator最大暂停时间的一种手段

G1的堆结构

 G1 GC 堆分布图

G1中，将堆内存划分为了大小相等的内存块，称之为Heap Region，Heap Region是内存分配和内存回收的最小单位，由于全称过长，后文中可能使用分区、区域或HR代指Heap Region，望知悉。

图中红色区域指代的是新生代（young generation），蓝色区域指代的是老年代（old generation），标注为S的红色区域的为Suvivor Region，标注为H的蓝色区域为Humoungous Region。

从上图中可以看到，在G1收集器中，对象占用的内存和代际的分布都不是连续的，而且对于灰色区域来说，它随时可以为了实现软实时性，成为任何确定的代际区域，这是G1和其他收集器在堆内存结构上的最大差别，也是为什么G1更适合处理「堆中存在大量碎片」场景的原因。

新生代&老年代：通常垃圾收集器会根据对象的特性来选择不同的算法进行垃圾回收，对象会依据特性存储在不同的内存区域中，使用不同的回收算法。新生代&老年代便是依据对象生命周期所划分的内存区域。

停顿预测模型

在G1 GC中，用户通过-XX:MaxGCPauseMills 来设定期望最大停顿时间，而具体则是由G1 GC中的停顿预测模型实现。

卡表

JVM将堆内存划分为了2次幂大小的卡页（Card Page），使用卡表来记录其内存状态。默认情况下，卡页的大小为512B。

卡表（Card Table）是由1B组成的数组，卡表里的元素称为卡片（Card），每个卡片对应堆内存中的一个卡页，卡片数组位置为堆内存地址除卡页大小（向下取整）。

 卡表与卡页映射关系图

堆中的对象所对应的卡片在卡表中的索引值可以通过以下公式快速计算出来。

(对象的地址－堆的头部地址)／512

卡表是一个全局表，其核心是利用了分桶思想，牺牲了一定的索引效率，不过使得JVM仅使用少量内存上即能快速描述内存状态。

记忆集（RSet）

记忆集与卡表密切相关，上一节中介绍了卡表的结构和职责，但是仍不知其具体应用场景有哪些

，接下来我便来介绍其最为重要的一个应用场景：记忆集。

记忆集英文全称为RemerberSet，简称RSet，是一种抽象概念，其核心思想是借由卡表，记录对象在不同代际间的引用关系，加速垃圾回收的速度。

JVM会通过可达性分析算法标记存活对象来帮助进行垃圾回收，不过在分代GC中，新生代和老年代处于不同的回收阶段，如果我仅仅只需要需要回收新生代，却标记了老年代的对象，那么这无疑是不必要的，所以JVM设计了RSet这样的玩意来避免这种现象，使其即便不扫描全部对象，也可以查到待回收对象所在分区被其它分区引用的情况。

记忆集的结构及使用示例

假设有两个分区（Heap Region），其区域内对象的引用关系如下图所示：

每个HR中都会额外开辟一块存储空间，用于存储记忆集，记忆集的结构为一个Hash表，Key为引用本分区的其它分区的地址，Value是卡片（Card）在卡表的索引值，即分区中的哪些卡页引用了本分区。

拿上图两个分区的引用关系举例，对象b引用了对象a，则在HR A中的记忆集，会存储对象b所在卡页对本分区的引用。在这个图中，对象b所在区域为HR B，所在卡页对应卡表索引2048的位置，则HR A的记忆集中会新增一个「B-2048」的引用关系

 记忆集结构图

记忆集如何筛选记录引用关系

上边介绍了记忆集的结构及其如何记录引用关系的示例，但是堆对象引用那么多，如果全部一一记录的话，我们的内存就爆炸了，所以我们需要明确哪些引用关系我们需要记录，哪些我们不需要记录。

在G1中提供了3种收集算法。新生代回收、混合回收和FullGC。新生代回收总是收集所有新生代分区，混合回收会收集所有的新生代分区以及部分老生代分区，而FullGC则是对所有的分区处理。简单了解这些后，我们对所有引用关系分类分析：

• 分区内部间的引用：无需记录引用关系，前文所说，Heap Region是内存分配和回收的最小单位，要么都回收，要么都不回收
• 新生代分区到新生代分区的引用：无需记录引用关系，无论哪种类型的回收，新生代都会全量回收
• 新生代分区到老年代分区的引用：无需记录引用关系，
• 老年代分区到新生代分区的引用：需要记录引用关系，新生代回收时，有两种根，一种是栈空间/全局变量的引用，另一种便是老年代到新生代的引用
• 老年代分区到老年代分区的引用：需要记录引用关系，混合回收时可能只回收部分Region，需要记录引用关系，快速找到活跃对象

这里说的引用关系，指的是分区间的引用关系，不要认为不记录分区间的引用关系，那么对象间也就没有引用关系了

记忆集记录的引用关系具体什么时候会使用

参考「第三章：垃圾回收过程」的「转移（垃圾回收）」小节

记忆集写屏障

记忆集其作用是HR间的引用关系，为保证其正确性，那么当引用关系变化时，我们需要及时更新记忆集，而记忆集写屏障则能帮我们完成这个工作。其工作的伪代码如下所示：

def evacuation_write_barrier(obj,field,newobj):
	check=obj^newobj # 异或
	check=check>>LOG_OF_HEAP_REGION_SIZE # 判断高位
	if newobj==Null:
		check=0
	if check==0:
		return
    
	if not is_dirty_card(obj):
		to_dirty(obj) # 标记为dirty card
		enqueue($current_thread.rs_log,obj)
    
	*field=newobj

obj为引用对象的地址，newobj为被引用对象的地址，field为obj的成员变量，上边这段代码的背景是obj的filed字段重新修改引用为newObj，所以obj新增了一个对其它分区的引用关系，需要通过写屏障记录。

解释一下这段代码干了什么事情，2～7行用于过滤同个HR间的引用，通过两个对象间的地址的异或（XOR），最终使异或结果左移LOG_OF_HEAP_REGION_SIZE，从而通过判断高位是否一致，来判断被引用对象和引用对象是否在同一个分区，如果是一个分区则不需要记录引用关系的变化了。

LOG_OF_HEAP_REGION_SIZE：Heap Region大小以2为底的对数

在9～11行，用来将对象对应卡片，加入dirty_card_queue，简称DCQ，DCQ由线程持有，当DCQ慢了之后，会放入一个全局的DCQS队列，最终会由Refine线程遍历其中的DCQ，更新Rset的索引关系，其过程如下所示

Refine线程：专门用于处理RSet更新的线程，Refine线程会和Mutator线程并发执行，由于G1在真正执行转移（垃圾回收）阶段时，会强制更新一次Rset，所以Refine线程的主要作用是提前处理RSet的更新，避免转移（垃圾回收）时停顿时间过长

第二章：对象分配过程

快速分配

快速分配指的是基于线程本地分配缓冲区（Thread Local Allocation Buffer）的分配。

通常来说，JVM堆是所有线程的共享区域，因此，从JVM堆空间分配对象时，必须锁定整个堆，以免被其它线程中断影响，而为了避免资源竞争降低对象分配效率，TLAB通过给每个线程分配一个缓冲区，来使其进行快速无锁分配。

 对象分配流程图

当一个对象快速分配失败时（通常是TLAB剩余空间不足以分配该对象），线程会视TLAB使用情况决定是否要将这个TLAB归还到堆空间中去，并再申请一个TLAB，如果判断需要这么做时，则会在TLAB分配成功后，再次尝试快速分配，否则则进入慢速分配。

那么什么情况，JVM会判断该线程需要再申请一个TLAB呢？实际上虚拟机会维护一个refill_waste的值，当对象在TLAB分配对象失败时，如果对象大小大于refill_waste，则让其直接进行在堆分配，如果对象大小小于refill_waste，则为其重新分配一个TLAB，将对象分配在新TLAB上。refill_waste的值可用通过TLABRefillWasteFraction，默认值是64，也就是说默认refill_waste=TLABSize/64

慢速分配

快速分配失败则进入慢速分配

大对象分配

大对象分配也是慢速分配的一种，步骤如下

• 尝试垃圾回收，同时启动并发标记。
• 尝试开始分配对象，对于大对象分为两类，一类是大于HeapRegionSize的一半，但是小于HeapRegionSize，即一个完整的堆分区可以保存，则直接从空闲列表直接拿一个堆分区，或者分配一个新的堆分区。另一类则是不仅大于HeapRegionSize的一半，还大于HeapRegionSize，即连续对象，需要多个堆分区，思路同上，但是处理的时候需要加锁。
• 如果失败再次尝试垃圾回收，之后再分配。
• 最终成功分配或者失败达到一定次数，则分配失败

第三章：垃圾回收过程

Garbage Collection Cycle

前文我们说过G1的GC有三种：新生代GC、混合GC、Full GC。不过按阶段来的话，G1的回收只有两个阶段，Young-Only和Space Relcaimation阶段。

在Young Only阶段，G1只会回收新生代内存，即新生代回收，在Space Reclamation阶段，G1除了会全量回收新生代内存，还会回收老年代区域，即混合回收。Full GC是一种特殊的兜底回收逻辑，此处不考虑进来。

所以G1的垃圾回收其实不是我们所想的Young GC和Mixed GC穿插进行，而是Young GC 持续一段时间，Mixed GC 再持续一段时间。

Garbage Collection Cycle概览图

那么G1如何判断什么时候进入Space Reclamation阶段呢？参照上图，当老年代堆内存占比超过一定阈值时，G1会开始并发标记，当并发标记的最后一个阶段Clean Up阶段完成后，G1则会进入Space Reclamation阶段，进行Mixed GC。

并发标记

并发标记的时机是在YGC后，只有达到InitiatingHeapOccupancyPercent阈值后，才会触发并发标记。InitiatingHeapOccupancyPercent默认值是45。

并发标记阶段分为4个子阶段

1、初始标记阶段（Initial Mark）

负责标记所有直接可达的根对象（栈对象、全局对象、JNI对象等），初始标记伴随一次YGC，因此初始标记需要将Mutator线程暂停，也就是需要一个STW的时间。

2、并发标记子阶段（Concurrent Start）

根据新生代的Survivor分区以及老生代的RSet开始并发标记存活对象。

3、再标记子阶段（Remark）

再标记（Remark）是最后一个标记阶段。由于并发标记子阶段时，Mutator线程仍在不断修改对象引用关系，因此在该阶段中，G1需要一个STW，找出所有未被访问的存活对象。

4、清理子阶段（Clean Mark）

再标记阶段之后进入清理子阶段，也是需要STW的。清理子阶段主要执行以下操作：

• 统计存活对象，统计的结果将会用来排序分区，以用于下一次的CSet的选择；根据SATB算法，需要把新分配的对象，即不在本次并发标记范围内的新分配对象，都视为活跃对象。
• 交换标记位图，为下次并发标记准备。
• 重置RSet，此时老生代分区已经标记完成，如果标记后的分区没有引用对象，这说明引用已经改变，这个时候可以删除原来的RSet里面的引用关系。
• 把空闲分区放到空闲分区列表中；这里的空闲指的是全都是垃圾对象的分区；如果分区还有任何分区活跃对象都不会释放，真正释放是在混合GC中。

 并发标记流程图

并发标记阶段完成后，即能够获得所有候选的回收集，G1会根据其回收价值进行排序，在MixedGC时，在满足期望最大停顿时间的前提下，筛选最具有回收价值的回收集

转移（垃圾回收）

转移是Young GC和Mixed GC都会执行的过程，是我们常说的垃圾回收。

在并发标记完成后，G1能筛选出所有候选的回收集，并根据用户定义的期望最大停顿时间，筛选本次转移真正的回收集（CSet），标记回收集中的存活对象，将这些对象转移，完成垃圾回收。

Young GC 的回收只包含全量新生代区域，意味着Young GC 不需要耗费时间来筛选回收集，整个新时代都是回收集，Mixed GC 由于除了回收全量新生代区域，还会回收部分老年代区域，所以需要耗费时间来筛选回收集

既然需要标记存活对象，那么就需要从根引用进行可达性分析，来进行标记。

在转移过程中，除了会使用栈空间、全局变量等根，还会将CSet中的记忆集作为根，进行扫描。

 转移（垃圾回收）流程图

如果此刻G1处于Space Reclamation阶段，则一定不需要进行并发标记，因为进入Space Reclamation阶段，意味着已完成并发标记，Space Reclamation阶段在回收到一定阈值才会停下，再次进入Young-Only阶段

转移其核心逻辑此处使用伪代码进行表示（以下伪代码摘抄自《深入Java虚拟机：JVM G1GC的算法与实现》，本人主要负责解释说明）：

def evacuate_roots():
	for r in $roots: # 遍历root集合，
		if is_into_collection_set(*r):
			*r=evacuate_obj(r) # 转移根对象到空闲区域
	force_update_rs() # 强制更新RSet
    for regionin $collection_set: # 遍历回收集
    	for card in region.rs_cards: # 遍历Region记忆集中的卡页
    		scan_card(card)
    
    def scan_card(card):
    	for obj in objects_in_card(card): # 遍历卡页中的对象
    		if is_marked(obj): # 如果该对象已经标记了，就是说该对象是存活的
    			for child in children(obj): # 遍历其引用
    				if is_into_collection_set(*child): # 如果引用的对象在回收集中
    					*child=evacuate_obj(child) #转移对象到空闲区域
    
    def evacuate_obj(ref):
    	from=*ref 
    	if not is_marked(from): # 如果待转移对象非存活对象，返回
    		return from
    	if from.forwarded: # 如果待转移对象已经转移，重定向地址为转移后地址，并返回转移后地址
    		add_reference(ref,from.forwarded)
    	  return from.forwarding
    	to=allocate($free_region,from.size) # 分配内存空间，用于转移待转移对象
    	copy_data(new,from,from.size) # 转移数据
    	
        from.forwarding=to # 重定向引用
      	from.forwarded=True # 标记对象已转移
      
      	for child in children(to): # 扫描待转移对象的引用关系，加入到队列中，待后续扫描标记
        	if is_into_collection_set(*child):
      			enqueue($evacuate_queue,child)
      	  else:
      			add_reference(child,*child)
      	
        add_reference(ref,to)
        return to
        

第四章：GC日志解读

这里以截取的一段GC日志为例，帮助各位理解GC日志

# 触发并发标记，原因：大对象分配，老年代占比超过IHOP阈值
# occupancy指老年代占有内存大小，allocation request指本次对象分配所需申请内存
# threshold指阈值
[gc,ergo,ihop      ] Request concurrent cycle initiation (occupancy higher than threshold) occupancy: 18790481920B allocation request: 16777248B threshold: 18790481920B (50.00) source: concurrent humongous allocation
[safepoint         ] Application time: 0.1052313 seconds
# 看名字也能看得出来，collect for allocation
[safepoint         ] Entering safepoint region: G1CollectForAllocation
[gc,ergo           ] Request concurrent cycle initiation (requested by GC cause). GC cause: G1 Humongous Allocation
[gc,heap           ] GC(19615) Heap before GC invocations=19615 (full 0): garbage-first heap   total 36700160K, used 29863278K [0x00007f98dd000000, 0x00007fa19d00000)
[gc,heap           ] GC(19615)   region size 16384K, 705 young (11550720K), 34 survivors (557056K)
[gc,heap           ] GC(19615)  Metaspace       used 580660K, capacity 592798K, committed 598784K, reserved 600064K
# 启动并发标记
[gc,ergo           ] GC(19615) Initiate concurrent cycle (concurrent cycle initiation requested)
# 伴随一次YoungGC
[gc,start          ] GC(19615) Pause Young (Concurrent Start) (G1 Humongous Allocation)
[gc,task           ] GC(19615) Using 24 workers of 24 for evacuation
# TLAB日志信息
# thrds：线程数 
# refills：refill的总次数 这里是91694，max表示一个周期内的最大值
# slow allocs: 发生慢速分配的次数
# waste：由三个部分组成，gc、slow、fast
# gc：发生GC时还没有使用的TLAB空间
# slow：暂时不清楚什么意思
# fast：暂时不清楚什么意思
[gc,tlab           ] GC(19615) TLAB totals: thrds: 2870  refills: 91694 max: 1434 slow allocs: 11949 max 964 waste:  1.9% gc: 154439632B max: 4864808B slow: 60164832B max: 903784B fast: 0B max: 0B
[gc,alloc,region   ] GC(3308) Mutator Allocation stats, regions: 1139, wasted size: 1789K ( 0.0%)
# 期望的survivor区占有空间，new threshold 15 表示当前对象晋升年龄为15，max threshold 15 表示最大对象晋升年龄为15
[gc,age            ] GC(3308) Desired survivor size 1249902592 bytes, new threshold 15 (max threshold 15)
# Choose CSet，由于这是一次young gc，所以Cset全是年轻代，耗时为0
[gc,ergo,cset      ] GC(3308) Finish choosing CSet. old: 0 regions, predicted old region time: 0.00ms, time remainin: 104.69
[gc,refine         ] Activated worker 0, on threshold: 666, current: 709
# GC结束阶段信息统计，通常不用关注，打出这一行日志说明本次GC已经接近尾声
[gc,task,stats     ] GC(3308) GC Termination Stats
[gc,task,stats     ] GC(3308)      elapsed  --strong roots-- -------termination------- ------waste (KiB)------
[gc,task,stats     ] GC(3308) thr     ms        ms      %        ms      %    attempts  total   alloc    undo
[gc,task,stats     ] GC(3308) --- --------- --------- ------ --------- ------ -------- ------- ------- -------
[gc,task,start     ] G1 Service Thread (Periodic GC Task) (run)
[gc,task           ] G1 Service Thread (Periodic GC Task) (run) 0.074ms (cpu: 0.035ms)
[gc,task,stats     ] GC(3308)   8    110.28     82.40  74.72      0.01   0.01        1       0       0       0
[gc,task,stats     ] GC(3308)   5    110.36     82.41  74.67      0.02   0.02        1       0       0       0
[gc,task,stats     ] GC(3308)   2    110.42     82.45  74.67      0.02   0.02        1       0       0       0
[gc,task,stats     ] GC(3308)  18    110.37     82.75  74.98      0.02   0.02        1       0       0       0
[gc,task,stats     ] GC(3308)   6    110.45     82.41  74.62      0.01   0.01        1       0       0       0
[gc,task,stats     ] GC(3308)  15    110.43     82.42  74.64      0.01   0.01        1       1       1       0
[gc,task,stats     ] GC(3308)   0    110.54     82.46  74.60      0.01   0.01        1       0       0       0
[gc,task,stats     ] GC(3308)   3    110.54     82.41  74.55      0.02   0.02        1      49      49       0
[gc,task,stats     ] GC(3308)   1    110.58     82.46  74.57      0.02   0.01        1       0       0       0
[gc,task,stats     ] GC(3308)  19    110.52     82.36  74.52      0.01   0.01        1       6       6       0
[gc,task,stats     ] GC(3308)  12    110.58     82.40  74.51      0.02   0.02        1       0       0       0
[gc,task,stats     ] GC(3308)  22    110.41     84.69  76.70      0.01   0.01        1     150     150       0
[gc,task,stats     ] GC(3308)   9    110.63     82.55  74.62      0.01   0.01        1     313     313       0
[gc,task,stats     ] GC(3308)  14    110.64     84.66  76.52      0.02   0.02        1       2       2       0
[gc,task,stats     ] GC(3308)   4    110.72     82.41  74.43      0.02   0.02        1       0       0       0
[gc,task,stats     ] GC(3308)  16    110.68     82.29  74.35      0.01   0.01        1      14      14       0
[gc,task,stats     ] GC(3308)  20    110.68     84.77  76.58      0.01   0.01        1       0       0       0
[gc,task,stats     ] GC(3308)  10    110.78     88.72  80.09      0.02   0.01        1       0       0       0
[gc,task,stats     ] GC(3308)   7    110.83     82.40  74.35      0.02   0.02        1       7       7       0
[gc,task,stats     ] GC(3308)  13    110.84     82.38  74.33      0.02   0.01        1       2       2       0
[gc,task,stats     ] GC(3308)  21    110.82     82.70  74.63      0.01   0.01        1       0       0       0
[gc,task,stats     ] GC(3308)  23    110.47     82.01  74.24      0.01   0.01        1       0       0       0
[gc,task,stats     ] GC(3308)  11    110.92     82.38  74.27      0.01   0.01        1       5       5       0
[gc,task,stats     ] GC(3308)  17    110.92     85.26  76.86      0.01   0.01        1       1       1       0
# 启用Redirty任务，保证引用关系无误
[gc,ergo           ] GC(3308) Running G1 Clear Card Table Task using 24 workers for 55 units of work for 1755 regions.
[gc,ref            ] GC(3308) Skipped phase1 of Reference Processing due to unavailable references
# 释放CSet
[gc,ergo           ] GC(3308) Running G1 Free Collection Set using 24 workers for collection set length 1188
# 大对象分配信息，这里解释一下下边这一行日志：
# 312号HR分区为大对象分区，大小为16M，起始地址为0x00007f5321000000，Rset更新过1次，代码块长度为0，is marked 0表示被标记，不能被回收，且是数组类型
[gc,humongous      ] GC(3308) Live humongous region 312 object size 16777248 start 0x00007f5321000000  with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 1
[gc,humongous      ] GC(3308) Live humongous region 378 object size 8388632 start 0x00007f5363000000  with remset 0 code roots 0 is marked 0 reclaim candidate 0 type array 0
[gc,humongous      ] GC(3308) Live humongous region 410 object size 16777240 start 0x00007f5383000000  with remset 0 code roots 0 is marked 0 reclaim candidate 0 type array 0
[gc,humongous      ] GC(3308) Live humongous region 459 object size 16777240 start 0x00007f53b4000000  with remset 0 code roots 0 is marked 0 reclaim candidate 0 type array 0
[gc,humongous      ] GC(3308) Live humongous region 461 object size 16777248 start 0x00007f53b6000000  with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 1
[gc,humongous      ] GC(3308) Live humongous region 572 object size 8388632 start 0x00007f5425000000  with remset 0 code roots 0 is marked 0 reclaim candidate 0 type array 0
[gc,humongous      ] GC(3308) Live humongous region 579 object size 134217752 start 0x00007f542c000000  with remset 2 code roots 0 is marked 0 reclaim candidate 0 type array 0
[gc,humongous      ] GC(3308) Live humongous region 669 object size 16777240 start 0x00007f5486000000  with remset 0 code roots 0 is marked 0 reclaim candidate 0 type array 0
[gc,humongous      ] GC(3308) Live humongous region 677 object size 8388632 start 0x00007f548e000000  with remset 0 code roots 0 is marked 0 reclaim candidate 0 type array 0
[gc,humongous      ] GC(3308) Live humongous region 678 object size 16777240 start 0x00007f548f000000  with remset 0 code roots 0 is marked 0 reclaim candidate 0 type array 0
[gc,humongous      ] GC(3308) Live humongous region 685 object size 8388632 start 0x00007f5496000000  with remset 0 code roots 0 is marked 0 reclaim candidate 0 type array 0
[gc,humongous      ] GC(3308) Live humongous region 689 object size 16777240 start 0x00007f549a000000  with remset 0 code roots 0 is marked 0 reclaim candidate 0 type array 0
[gc,humongous      ] GC(3308) Live humongous region 691 object size 16777248 start 0x00007f549c000000  with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 1
[gc,humongous      ] GC(3308) Live humongous region 741 object size 8388632 start 0x00007f54ce000000  with remset 0 code roots 0 is marked 0 reclaim candidate 0 type array 0
[gc,humongous      ] GC(3308) Live humongous region 742 object size 16777240 start 0x00007f54cf000000  with remset 0 code roots 0 is marked 0 reclaim candidate 0 type array 0
[gc,humongous      ] GC(3308) Dead humongous region 747 object size 16762032 start 0x00007f54d4000000 with remset 0 code roots 0 is marked 0 reclaim candidate 1 type array 1
[gc,humongous      ] GC(3308) Live humongous region 753 object size 8388632 start 0x00007f54da000000  with remset 0 code roots 0 is marked 0 reclaim candidate 0 type array 0
[gc,humongous      ] GC(3308) Live humongous region 754 object size 16777240 start 0x00007f54db000000  with remset 0 code roots 0 is marked 0 reclaim candidate 0 type array 0
[gc,humongous      ] GC(3308) Live humongous region 766 object size 12707280 start 0x00007f54e7000000  with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 1
[gc,humongous      ] GC(3308) Live humongous region 770 object size 9692992 start 0x00007f54eb000000  with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 1
[gc,humongous      ] GC(3308) Live humongous region 771 object size 8388632 start 0x00007f54ec000000  with remset 0 code roots 0 is marked 0 reclaim candidate 0 type array 0
[gc,ergo,refine    ] GC(3308) Updated Refinement Zones: green: 719, yellow: 2157, red: 3595
# 下边信息为本次GC各阶段的耗时信息
# PS：不是这个时候才执行下边这些阶段，而是执行完了，统计耗时信息
# 预回收阶段统计信息
[gc,phases         ] GC(3308)   Pre Evacuate Collection Set: 0.1ms
[gc,phases         ] GC(3308)     Prepare TLABs: 1.5ms
[gc,phases         ] GC(3308)     Choose Collection Set: 0.0ms
[gc,phases         ] GC(3308)     Humongous Register: 0.1ms
# evacuation阶段
[gc,phases         ] GC(3308)   Evacuate Collection Set: 111.1ms
// 根结点扫描的耗时信息，其中Min表示24个线程中耗时最短的线程耗时情况，Avg、Max等参数以此类推
[gc,phases         ] GC(3308)     Ext Root Scanning (ms):   Min:  3.5, Avg:  5.1, Max:  5.5, Diff:  2.0, Sum: 123.3, Workers: 24
# 记忆集（RSet）更新
[gc,phases         ] GC(3308)     Update RS (ms):           Min:  7.8, Avg: 19.2, Max: 29.9, Diff: 22.2, Sum: 460.8, Workers: 24
[gc,phases         ] GC(3308)       Processed Buffers:        Min: 13, Avg: 107.6, Max: 221, Diff: 208, Sum: 2583, Workers: 24
# Scan Cards
# 这一阶段会从DCQ中找出卡片，遍历其区域中所有对象，用于更新Rset 
[gc,phases         ] GC(3308)       Scanned Cards:            Min: 3316, Avg: 8767.1, Max: 14417, Diff: 11101, Sum: 210411, Workers: 24
[gc,phases         ] GC(3308)       Skipped Cards:            Min: 0, Avg: 10.3, Max: 23, Diff: 23, Sum: 247, Workers: 24
# 扫码Rset
# 这一阶段会将Rset中对象作为根，扫描活跃对象
[gc,phases         ] GC(3308)     Scan RS (ms):             Min:  0.0, Avg:  9.0, Max: 16.2, Diff: 16.2, Sum: 217.0, Workers: 24
[gc,phases         ] GC(3308)       Scanned Cards:            Min: 0, Avg: 4385.7, Max: 8922, Diff: 8922, Sum: 105257, Workers: 24
[gc,phases         ] GC(3308)       Claimed Cards:            Min: 0, Avg: 4892.9, Max: 9695, Diff: 9695, Sum: 117429, Workers: 24
[gc,phases         ] GC(3308)       Skipped Cards:            Min: 0, Avg: 53531.8, Max: 84703, Diff: 84703, Sum: 1284762, Workers: 24
[gc,phases         ] GC(3308)     Code Root Scanning (ms):  Min:  0.0, Avg:  0.0, Max:  0.0, Diff:  0.0, Sum:  0.1, Workers: 24
[gc,phases         ] GC(3308)     AOT Root Scanning (ms):   skipped
# 对像拷贝
[gc,phases         ] GC(3308)     Object Copy (ms):         Min: 62.5, Avg: 76.7, Max: 98.7, Diff: 36.2, Sum: 1839.7, Workers: 24
[gc,phases         ] GC(3308)     Termination (ms):         Min:  0.0, Avg:  0.0, Max:  0.0, Diff:  0.0, Sum:  0.4, Workers: 24
[gc,phases         ] GC(3308)       Termination Attempts:     Min: 1, Avg:  1.0, Max: 1, Diff: 0, Sum: 24, Workers: 24
[gc,phases         ] GC(3308)     GC Worker Other (ms):     Min:  0.1, Avg:  0.5, Max:  0.8, Diff:  0.7, Sum: 11.2, Workers: 24
[gc,phases         ] GC(3308)     GC Worker Total (msG):     Min: 110.3, Avg: 110.6, Max: 110.9, Diff:  0.6, Sum: 2655.0, Workers: 24
#  善后工作
[gc,phases         ] GC(3308)   Post Evacuate Collection Set: 3.7ms
[gc,phases         ] GC(3308)     Code Roots Fixup: 0.0ms
[gc,phases         ] GC(3308)     Clear Card Table: 2.1ms
[gc,phases         ] GC(3308)     Reference Processing: 0.3ms
[gc,phases,ref     ] GC(3308)       Reconsider SoftReferences: 0.0ms
[gc,phases,ref     ] GC(3308)         SoftRef (ms):             skipped
[gc,phases,ref     ] GC(3308)       Notify Soft/WeakReferences: 0.1ms
[gc,phases,ref     ] GC(3308)         SoftRef (ms):             Min:  0.0, Avg:  0.0, Max:  0.0, Diff:  0.0, Sum:  0.0, Workers: 1
[gc,phases,ref     ] GC(3308)         WeakRef (ms):             Min:  0.0, Avg:  0.0, Max:  0.0, Diff:  0.0, Sum:  0.0, Workers: 1
[gc,phases,ref     ] GC(3308)         FinalRef (ms):            Min:  0.0, Avg:  0.0, Max:  0.0, Diff:  0.0, Sum:  0.0, Workers: 1
[gc,phases,ref     ] GC(3308)         Total (ms):               Min:  0.0, Avg:  0.0, Max:  0.0, Diff:  0.0, Sum:  0.0, Workers: 1
[gc,phases,ref     ] GC(3308)       Notify and keep alive finalizable: 0.1ms
[gc,phases,ref     ] GC(3308)         Balance queues: 0.0ms
[gc,phases,ref     ] GC(3308)         FinalRef (ms):            Min:  0.0, Avg:  0.1, Max:  0.1, Diff:  0.1, Sum:  1.5, Workers: 24
[gc,phases,ref     ] GC(3308)       Notify PhantomReferences: 0.1ms
[gc,phases,ref     ] GC(3308)         PhantomRef (ms):          Min:  0.1, Avg:  0.1, Max:  0.1, Diff:  0.0, Sum:  0.1, Workers: 1
[gc,phases,ref     ] GC(3308)       SoftReference:
[gc,phases,ref     ] GC(3308)         Discovered: 0
[gc,phases,ref     ] GC(3308)         Cleared: 0
[gc,phases,ref     ] GC(3308)       WeakReference:
[gc,phases,ref     ] GC(3308)         Discovered: 194
[gc,phases,ref     ] GC(3308)         Cleared: 536
[gc,phases         ] GC(3308)     Weak Processing: 0.1ms
[gc,phases         ] GC(3308)       JVMTI weak processing: 0.0ms
[gc,phases         ] GC(3308)       JFR weak processing: 0.0ms
[gc,phases         ] GC(3308)       JNI weak processing       Min:  0.0, Avg:  0.0, Max:  0.0, Diff:  0.0, Sum:  0.1, Workers: 24
[gc,phases         ] GC(3308)       VM weak processing        Min:  0.0, Avg:  0.0, Max:  0.0, Diff:  0.0, Sum:  0.9, Workers: 24
[gc,phases         ] GC(3308)     Merge Per-Thread State: 0.1ms
[gc,phases         ] GC(3308)     Code Roots Purge: 0.0ms
[gc,phases         ] GC(3308)     Redirty Cards: 0.4ms
[gc,phases         ] GC(3308)     DerivedPointerTable Update: 0.7ms
[gc,phases         ] GC(3308)     Free Collection Set: 0.5ms
[gc,phases         ] GC(3308)     Humongous Reclaim: 0.2ms
[gc,phases         ] GC(3308)     Start New Collection Set: 0.0ms
[gc,phases         ] GC(3308)     Resize TLABs: 0.3ms
[gc,phases         ] GC(3308)     Resize Heap After Collection: 0.0ms
[gc,phases         ] GC(3308)   Other: 4.3ms
# 各区域变化情况
[gc,heap           ] GC(3308) Eden regions: 1139->0(1136)
[gc,heap           ] GC(3308) Survivor regions: 49->50(149)
[gc,heap           ] GC(3308) Old regions: 784->785
[gc,heap           ] GC(3308) Humongous regions: 53->51
[gc,metaspace      ] GC(3308) Metaspace: 534929K->534929K(561152K)
[gc,heap           ] GC(3308) Heap after GC invocations=3309 (full 0): garbage-first heap   total 36700160K, used 14501693K [0x00007f51e9000000, 0x00007f5aa9000000)
[gc,heap           ] GC(3308)   region size 16384K, 50 young (819200K), 50 survivors (819200K)
[gc,heap           ] GC(3308)  Metaspace       used 534929K, capacity 545739K, committed 559360K, reserved 561152K
# 本次GC总耗时信息
[gc                ] GC(3308) Pause Young (Concurrent Start) (G1 Humongous Allocation) 32394M->14161M(35840M) 119.004ms
[gc,cpu            ] GC(3308) User=2.45s Sys=0.11s Real=0.11s
[safepoint         ] Leaving safepoint region

感言

在本篇文章中，主要向各位介绍来G1的机制原理，篇幅与时间有限，无法在此详述G1调优相关内容，如果大家对此比较感兴趣，后续可能会另写一篇文章，专门介绍G1调优相关的内容，比如说如何设置进入Space Reclamation的阈值，如何控制选择Cset，如何控制TLAB重新申请的时机，GC某个阶段耗时过长如何尝试调优等

参考资料

HotSpot Virtual Machine Garbage Collection Tuning Guide

《JVM G1源码分析和调优》

《深入Java虚拟机：JVM G1GC的算法与实现》

《实战Java虚拟机：JVM故障诊断与性能优化》