最近在钻研一个服务与数据库之间的耗时问题，排查到了服务端GC这块，对于GC的日志进行剖析一波，在此做个记录。
如下只记录了G1的新生代收集的流程 ！！！
{Heap before GC invocations=11035 (full 0): garbage-first heap total 2097152K, used 1878984K [0x0000000640000000, 0x0000000640202000, 0x00000007c0000000) region size 2048K, 594 young (1216512K), 2 survivors (4096K) Metaspace used 96639K, capacity 100818K, committed 101120K, reserved 1138688K class space used 10423K, capacity 11153K, committed 11264K, reserved 1048576K2021-11-21T16:13:30.692+0800: 2055582.832: [GC pause (G1 Evacuation Pause) (young), 0.0107390 secs] [Parallel Time: 7.4 ms, GC Workers: 4] [GC Worker Start (ms): Min: 2055582832.5, Avg: 2055582832.5, Max: 2055582832.6, Diff: 0.1] [Ext Root Scanning (ms): Min: 2.7, Avg: 2.8, Max: 2.8, Diff: 0.2, Sum: 11.0] [Update RS (ms): Min: 2.6, Avg: 2.6, Max: 2.7, Diff: 0.2, Sum: 10.4] [Processed Buffers: Min: 118, Avg: 136.8, Max: 165, Diff: 47, Sum: 547] [Scan RS (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 0.4] [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1] [Object Copy (ms): Min: 1.6, Avg: 1.7, Max: 1.7, Diff: 0.1, Sum: 6.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: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.2] [GC Worker Total (ms): Min: 7.1, Avg: 7.2, Max: 7.3, Diff: 0.2, Sum: 28.8] [GC Worker End (ms): Min: 2055582839.7, Avg: 2055582839.7, Max: 2055582839.8, Diff: 0.1] [Code Root Fixup: 0.2 ms] [Code Root Purge: 0.0 ms] [Clear CT: 0.2 ms] [Other: 2.9 ms] [Choose CSet: 0.0 ms] [Ref Proc: 1.1 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.5 ms] [Eden: 1184.0M(1184.0M)->0.0B(1184.0M) Survivors: 4096.0K->4096.0K Heap: 1834.9M(2048.0M)->652.4M(2048.0M)]Heap after GC invocations=11036 (full 0): garbage-first heap total 2097152K, used 668097K [0x0000000640000000, 0x0000000640202000, 0x00000007c0000000) region size 2048K, 2 young (4096K), 2 survivors (4096K) Metaspace used 96639K, capacity 100818K, committed 101120K, reserved 1138688K class space used 10423K, capacity 11153K, committed 11264K, reserved 1048576K} [Times: user=0.03 sys=0.00, real=0.01 secs]- 开始GC 标记（Heap before GC ）
invocations=11035 代表第11035次回收 - 第一行 概述
2021-11-21T16:13:30.692+0800 - 新生代垃圾收集产生的工夫，通过设置-XX:+PrintGCDateStamps参数能够打印出这个工夫2055582.832 - JVM启动后的绝对工夫GC pause (G1 Evacuation Pause) (young) - 这次收集的类型:新生代收集，只回收了Eden区(代表是一次 yong GC ,起因是: 疏散进展（Evacuation Pause）是将活着的对象从一个区域（young or young + old）拷贝到另一个区域的阶段)- 第二行：具体解析
Parallel Time：并行收集工作在运行过程中引发的STW（Stop The World）工夫，从新生代垃圾收集开始到最初一个工作完结，共破费26.6msGC Workers：有4个线程负责垃圾收集，通过参数-XX:ParallelGCThreads设置，这个参数的值的设置，跟CPU无关，如果物理CPU反对的线程个数小于8，则最多设置为8；如果物理CPU反对的线程个数大于8，则默认值为number * 5/8GC Worker Start：第一个垃圾收集线程开始工作时JVM启动后通过的工夫（min）；最初一个垃圾收集线程开始工作时JVM启动后通过的工夫（max）；diff示意min和max之间的差值。现实状况下，你心愿他们简直是同时开始，即diff趋近于0。Code Root Scanning：扫描代码中的root节点（局部变量）破费的工夫GC Worker Other：垃圾收集线程在实现其余工作的工夫GC Worker Total：展现每个垃圾收集线程的最小、最大、均匀、差值和总共工夫。GC Worker End：min示意最早完结的垃圾收集线程完结时该JVM启动后的工夫；max示意最晚完结的垃圾收集线程完结时该JVM启动后的工夫。现实状况下，diff 有限趋近于 0 Code Root Fixup ：开释用于治理并行垃圾收集流动的数据结构，应该靠近于0，该步骤是线性执行Code Root Purge：清理更多的数据结构，应该很快，耗时靠近于0，也是线性执行Choose CSet：抉择要进行回收的分区放入CSet（G1抉择的规范是垃圾最多的分区优先，也就是存活对象率最低的分区优先）Ref Proc：解决Java中的各种援用 例如soft、weak、final、phantom、JNI等Ref Enq：遍历所有的援用，将不能回收的放入pending列表Humongous Register：JDK8 提供了一个个性，巨型对象能够在新生代收集的时候被回收 能够通过G1ReclaimDeadHumongousObjectsAtYoungGC设置，默认为trueHumongous Reclaim：确保巨型对象能够被回收、开释该巨型对象所占的分区，重置分区类型，并将分区还到free列表，并且更新闲暇空间大小Free CSet：将要开释的分区还回到free列表- GC前后变动
Eden: 1184.0M(1184.0M)->0.0B(1184.0M): （1）以后新生代收集触发的起因是Eden空间满了，调配了 1184.0M ，应用了1184.0M（2）所有的Eden分区都被疏散解决了，在新生代完结后Eden分区的应用大小成为了0.0B Survivors: 4096.0K->4096.0K Eden区回收解决，但survivors并未扭转，阐明很多对象都在Eden区就被回收了Heap: 1834.9M(2048.0M)->652.4M(2048.0M) （1）在本次垃圾收集流动开始的时候，堆空间整体使用量是1834.9M，堆空间的最大值是2048M；（2）在本次垃圾收集完结后，堆空间的使用量是652.4M，最大值放弃不变(注:此处我的启动脚本设置了-xmn和-xmx是一样大的，所以Eden分区放弃不变，如果设置的不是一样的值的话，堆大小会进行自适应调整）- 各阶段耗时
user=0.03: 垃圾收集线程在新生代垃圾收集过程中耗费的CPU工夫，这个工夫跟垃圾收集线程的个数无关sys=0.00: 内核态线程耗费的CPU工夫real=0.01: 本次垃圾收集真正耗费的工夫总结：
基本上GC 下面的日志基本上曾经够用了，如果想更精密一点能够加上 -XX:+PrintAdaptiveSizePolicy 打印内存调节的过程备注：
1、之前珍藏过一个老哥写的博客，对于G1GC的日志剖析能够来这里看看，讲的也挺具体的https://blog.csdn.net/weixin_...
2、呈现GC问题大家除了察看GC日志，也要正当利用工具哦，我个别用的工具是
GcEasy、MAT, dump文件剖析的话个别用的是 heaphero 和 fastthread
哈哈 最初说的有点多了哈，如同和本文主题关系不是太大 ～ ～ ～