垃圾回收器日志解读"/>

最详细G1垃圾回收器日志解读

首先，开启gc日志。-XX:+PrintGCDetails

疏散阶段

疏散阶段，主要是将内存中的数据从一些分区复制到其他分区

0.522: [GC pause (young), 0.15877971 secs] # 这次疏散只涉及年轻代，总耗时 0.15877971.如果是混合gc则可能是 [GC pause (mixed), 0.32714353 secs][Parallel Time: 157.1 ms] # 并行疏散，总耗时 157.1 ms[GC Worker Start (ms):  522.1  522.2  522.2  522.2 # 每个疏散线程的开始时间Avg: 522.2, Min: 522.1, Max: 522.2, Diff:   0.1]  # 最大时间，最小时间[Ext Root Scanning (ms):  1.6  1.5  1.6  1.9  # 每个线程扫描根分区的时间Avg:   1.7, Min:   1.5, Max:   1.9, Diff:   0.4][Update RS (ms):  38.7  38.8  50.6  37.3 #更新RS的耗时，线程会把对当前分区引用的变更记录在buffer里,这里就是处理这些bufferAvg:  41.3, Min:  37.3, Max:  50.6, Diff:  13.3][Processed Buffers : 2 2 3 2 # 处理缓冲区的数量Sum: 9, Avg: 2, Min: 2, Max: 3, Diff: 1][Scan RS (ms):  9.9  9.7  0.0  9.7 # 扫描RSAvg:   7.3, Min:   0.0, Max:   9.9, Diff:   9.9][Object Copy (ms):  106.7  106.8  104.6  107.9  # 每个线程复制到CS的内容其他分区Avg: 106.5, Min: 104.6, Max: 107.9, Diff:   3.3][Termination (ms):  0.0  0.0  0.0  0.0Avg:   0.0, Min:   0.0, Max:   0.0, Diff:   0.0][Termination Attempts : 1 4 4 6Sum: 15, Avg: 3, Min: 1, Max: 6, Diff: 5][GC Worker End (ms):  679.1  679.1  679.1  679.1 # 每个gc线程的结束时间Avg: 679.1, Min: 679.1, Max: 679.1, Diff:   0.1][GC Worker (ms):  156.9  157.0  156.9  156.9 # 每个gc worker的总耗时Avg: 156.9, Min: 156.9, Max: 157.0, Diff:   0.1][GC Worker Other (ms):  0.3  0.3  0.3  0.3 Avg:   0.3, Min:   0.3, Max:   0.3, Diff:   0.0][Clear CT:   0.1 ms] # 清理卡表[Other:   1.5 ms][Choose CSet:   0.0 ms][Ref Proc:   0.3 ms][Ref Enq:   0.0 ms][Free CSet:   0.3 ms][Eden: 12M(12M)->0B(10M) Survivors: 0B->2048K Heap: 13M(64M)->9739K(64M)]  # 各个分代的内存变更。eden的容量从12M到10M,内存占用从12M到0.survivors的内存占用从0 到 2048k.堆内存容量从64M到64M，内存占用从13M到9739K[Times: user=0.59 sys=0.02, real=0.16 secs] # 总耗时0.16秒

标记阶段

1.416: [GC pause (young) (initial-mark), 0.62417980 secs] # 标记周期的第一阶段是初始标记，标记从根直接可访问的对象
2.042: [GC concurrent-root-region-scan-start] # 标志根分区，也就是初始标记的对象所在的区域。可以从初始标记的结果中直接获得
2.067: [GC concurrent-root-region-scan-end, 0.0251507] # 根分区标记的结束及耗时。结束发送在下一次yong gc之前，因为下一次gc会改变初始标记的对象所在的分区
2.068: [GC concurrent-mark-start] # 并发标记，并发创建每个分区的卡表，标记外部分区对当前区域某个卡片的引用。
3.198: [GC concurrent-mark-reset-for-overflow] # 这表明全局标记堆栈已满，并且堆栈溢出。并发标记检测到此溢出，必须重置数据结构以再次开始标记。
4.053: [GC concurrent-mark-end, 1.9849672 sec] # 并发标记的结束，耗时
4.055: [GC remark 4.055: [GC ref-proc, 0.0000254 secs], 0.0030184 secs] # 重新标记。STW,在并发标记阶段产生的变更会被写屏障记录下来。这里就是标记这部分对象，速度很快[Times: user=0.00 sys=0.00, real=0.00 secs] # 标记阶段结束 
4.088: [GC cleanup 117M->106M(138M), 0.0015198 secs][Times: user=0.00 sys=0.00, real=0.00 secs] # 回收资源阶段，将空闲的分区收集好，非空闲的区域按回收代价排序。堆内存 138M, 回收前 117M，回收后106M.
4.090: [GC concurrent-cleanup-start] # 并发清理，主要根据停顿目标选择适当数量的分区收集。
4.091: [GC concurrent-cleanup-end, 0.0002721] # 清理结束，耗时。