手撕 JVM 垃圾收集日志，【MySQL

-XX:+UseConcMarkSweepGC

-XX:CMSInitiatingOccupancyFraction=70

-XX:+ExplicitGCInvokesConcurrentAndUnloadsClasses

-XX:+CMSClassUnloadingEnabled

-XX:+ParallelRefProcEnabled

在重新标记之前对年轻代做一次minor GC

-XX:+CMSScavengeBeforeRemark

使用了-XX:+ExplicitGCInvokesConcurrentAndUnloadsClasses或-XX:+ExplicitGCInvokesConcurrent参数，在进行 Full GC 的时候，比如执行 System.gc() 操作，会触发 CMS GC，以此来提高 GC 效率。

以下是启用 CMS 后摘的一段 GC 日志，由于内容过长，下面我就直接在日志上做注释了。

System.gc() 触发一次 Full GC

-XX:+ExplicitGCInvokesConcurrentAndUnloadsClasses 参数

导致Full GC 以 CMS GC 方式执行

先由 ParNew 收集器回收年轻代

2019-12-03T16:43:03.179-0800: [GC (System.gc()) 2019-12-03T16:43:03.179-0800: [ParNew: 3988K->267K(9216K), 0.0091869 secs] 3988K->919K(19456K), 0.0092257 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]

初始标记阶段，标记那些直接被 GC root 引用或者被年轻代存活对象所引用的所有对象

老年代当前使用 651K

老年代可用大小 10240K=10M

当前堆内存使用量 919K

当前堆可用内存 19456K=19M

“1 CMS-initial-mark” 这里的 1 表示老生代

2019-12-03T16:43:03.189-0800: [GC (CMS Initial Mark) [1 CMS-initial-mark: 651K(10240K)] 919K(19456K), 0.0002156 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

并发标记开始

标记所有存活的对象，它会根据上个阶段找到的 GC Roots 遍历查找

2019-12-03T16:43:03.189-0800: [CMS-concurrent-mark-start]

并发标记阶段耗时统计

2019-12-03T16:43:03.190-0800: [CMS-concurrent-mark: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]

并发预清理阶段开始

在上述并发标记过程中，一些对象的引用可能会发生变化，JVM 会将包含这个对象的区域（Card）标记为 Dirty

在此阶段，能够从 Dirty 对象到达的对象也会被标记，这个标记做完之后，dirty card 标记就会被清除了

2019-12-03T16:43:03.190-0800: [CMS-concurrent-preclean-start]

并发预清理耗时统计

2019-12-03T16:43:03.190-0800: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

重新标记阶段，目的是完成老年代中所有存活对象的标记

上一阶段是并发执行的，在执行过程中对象的引用关系还会发生变化，所以再次标记

因为配置了 -XX:+CMSScavengeBeforeRemark 参数，所以会在标记发生一次 Minor GC

进行一次Minor GC,完成后年轻代可用空间 267K，年轻代总大小9216K

2019-12-03T16:43:03.190-0800: [GC (CMS Final Remark) [YG occupancy: 267 K (9216 K)]

更详细的年轻代收集情况

2019-12-03T16:43:03.190-0800: [GC (CMS Final Remark) 2019-12-03T16:43:03.190-0800: [ParNew: 267K->103K(9216K), 0.0021800 secs] 919K->755K(19456K), 0.0022127 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

在程序暂停时重新进行扫描(Rescan),以完成存活对象的标记

2019-12-03T16:43:03.192-0800: [Rescan (parallel) , 0.0002866 secs]

第一子阶段：处理弱引用

2019-12-03T16:43:03.193-0800: [weak refs processing, 0.0015605 secs]

第二子阶段：卸载不适用的类

2019-12-03T16:43:03.194-0800: [class unloading, 0.0010847 secs]

第三子阶段:清理持有class级别 metadata 的符号表(symbol tables),以及内部化字符串对应的 string tables

完成后老年代使用量为651K(老年代总大小10240K=10M)

整个堆使用量 755K(总堆大小19456K=19M)

2019-12-03T16:43:03.195-0800: [scrub symbol table, 0.0015690 secs]

2019-12-03T16:43:03.197-0800: [scrub string table, 0.0003786 secs][1 CMS-remark: 651K(10240K)] 755K(19456K), 0.0075058 secs] [Times: user=0.01 sys=0.01, real=0.00 secs]

#开始并发清理 清除未被标记、不再使用的对象以释放内存空间

2019-12-03T16:43:03.198-0800: [CMS-concurrent-sweep-start]

#并发清理阶段耗时

2019-12-03T16:43:03.198-0800: [CMS-concurrent-sweep: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

开始并发重置，重置CMS算法相关的内部数据, 为下一次GC循环做准备

2019-12-03T16:43:03.198-0800: [CMS-concurrent-reset-start]

重置耗时

2019-12-03T16:43:03.199-0800: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

下面是执行 jmap -histo:live 命令触发的 Full GC

GC 类型是 Full GC

触发原因是 Heap Inspection Initiated GC

CMS收集老年代：从清理前的650K变为清理后的617K，总的老年代10M,耗时0.0048490秒

总堆使用大小由 1245K变为617K，总堆19M

metaspace: 3912K变为3912K，

metaspace 总大小显示为 CompressedClassSpaceSize +(2*InitialBootClassLoaderMetaspaceSize)

2019-12-03T16:43:20.115-0800: [Full GC (Heap Inspection Initiated GC) 2019-12-03T16:43:20.115-0800: [CMS: 650K->617K(10240K), 0.0048490 secs] 1245K->617K(19456K), [Metaspace: 3912K->3912K(1056768K)], 0.0049050 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]

以上就是对 CMS 垃圾收集器产生日志的分析，因为过程复杂，所以产生的日志内容也比较多。

G1 收集器

G1 收集器是在 JDK 7 版本中就已经正式推出，并且作为 JDK 9 默认的垃圾收集器。

Parallel Scavenge：我追求高吞吐量，现在社会什么最重要，效率呀，有没有。

CMS：效率固然重要，极致的用户体验才是王道啊，不能让用户等啊，不能等啊，低停顿、即时响应是我毕生追求。

G1（一脸不屑）：有句话不只当讲不当讲，首先声明没有恶意，我想说，在座的各位都是垃圾。上面两位说的，我全都有，是的，全都有。 (ps：结果被打)

以上纯属开个玩笑，只是为了说明 G1 在满足了低停顿的同时也保证了高吞吐量，适用于多核处理器、大内存容量的服务端系统。

G1 是 CMS 的替代版本，具有如下特点：

• 横跨年轻代和老年代，不需要其他收集器配合；

• 并发收集器，可以与用户线程并发执行；

• 会压缩内存碎片；

• 可预测的停顿时间与高吞吐量；

与其他的垃圾收集器不同，G1 对堆内存做了不一样的规划，虽然还是使用分代策略，分为老年代、年轻代，年轻代又分为 Eden、Survivior 区，但是只是逻辑划分，物理上并不连续。它是将堆内存分为一系列大小在1M-32M 不等的 Region 区，通过下方的图可以直观的看出效果。

image

G1 垃圾收集包括年轻代收集和老年代收集两部分。

年轻代比较简单，收集器如果检测到存活区对象存活时间达到阈值，就会将这些存活对象转移到新的 Survivor 区或老年代，此过程会导致 stop the world。

老年代的收集就比较复杂了，包括如下几个阶段：

• 初始标记阶段(Initial Marking Phase)，会导致 stop the wrold;

• 根区域扫描（Root Region Scan），与应用程序并发执行；

• 根区域扫描（Root Region Scan），与应用程序并发执行；

• 并发标记（Concurrent Marking），与应用程序并发执行；

• 最终标记（Remark），会导致 stop the wrold;

• 复制/清除（Copying/Cleanup），会导致 stop the wrold;

开启 G1 收集器的参数如下：

-XX:+UseG1GC

-XX:MaxGCPauseMillis=100

使用 G1 收集器时，一般不设置年轻代的大小。

以下是一次 G1 收集的日志，简单的分析直接写到下面的日志内了。

进行了一次年轻代 GC,耗时0.0008029S

[GC pause (G1 Humongous Allocation) (young), 0.0008029 secs]

4个GC线程并行执行

[Parallel Time: 0.5 ms, GC Workers: 4]

GC 线程耗时统计，反应收集的稳定性和效率

[GC Worker Start (ms): Min: 90438.1, Avg: 90438.2, Max: 90438.4, Diff: 0.3]

扫描堆外内存耗时统计

[Ext Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.2, Diff: 0.2, Sum: 0.6]

更新和扫描RSets 耗时统计

[Update RS (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.2]

[Processed Buffers: Min: 0, Avg: 0.2, Max: 1, Diff: 1, Sum: 1]

[Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]

#扫描堆中的 root 对象耗时统计

[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]

拷贝存活对象耗时统计

[Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]

GC 线程确保自身安全停止耗时统计

[Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.5]

[Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4]

[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]

GC的worker 线程的工作时间总计

[GC Worker Total (ms): Min: 0.1, Avg: 0.4, Max: 0.5, Diff: 0.3, Sum: 1.5]

GC的worker 线程完成作业的时间统计

[GC Worker End (ms): Min: 90438.6, Avg: 90438.6, Max: 90438.6, Diff: 0.0]

修复GC期间code root指针改变的耗时

[Code Root Fixup: 0.0 ms]

清除code root耗时

[Code Root Purge: 0.0 ms]

清除card tables 中的dirty card的耗时

[Clear CT: 0.0 ms]

其他方面比如选择CSet、处理已用对象、引用入ReferenceQueues、释放CSet中的region等的耗时

[Other: 0.3 ms]

[Choose CSet: 0.0 ms]

[Ref Proc: 0.1 ms]

[Ref Enq: 0.0 ms]

[Redirty Cards: 0.0 ms]

[Humongous Register: 0.0 ms]

[Humongous Reclaim: 0.0 ms]

[Free CSet: 0.0 ms]

收集前 Eden区使用量 1024K(总容量9216K),收集后容量0B(总容量9216K)

Survivors 区收集前后的大小

堆空间收集前使用量13.4M(总量20M),收集后650.2K

[Eden: 1024.0K(9216.0K)->0.0B(9216.0K) Survivors: 1024.0K->1024.0K Heap: 13.4M(20.0M)->650.2K(20.0M)]

[Times: user=0.00 sys=0.00, real=0.00 secs]

初始标记阶段，耗时0.0031800s

2019-12-03T16:48:25.456-0800: [GC pause (G1 Humongous Allocation) (young) (initial-mark), 0.0031800 secs][Parallel Time: 2.5 ms, GC Workers: 4]

[GC Worker Start (ms): Min: 4115.2, Avg: 4115.4, Max: 4115.8, Diff: 0.6]

…

[Eden: 3072.0K(10.0M)->0.0B(9216.0K) Survivors: 0.0B->1024.0K Heap: 9216.0K(20.0M)->744.0K(20.0M)]

[Times: user=0.01 sys=0.00, real=0.00 secs]

Root区扫描

2019-12-03T16:48:25.460-0800: [GC concurrent-root-region-scan-start]

2019-12-03T16:48:25.462-0800: [GC concurrent-root-region-scan-end, 0.0024198 secs]

并发标记

2019-12-03T16:48:25.462-0800: [GC concurrent-mark-start]

小编13年上海交大毕业，曾经在小公司待过，也去过华为、OPPO等大厂，18年进入阿里一直到现在。

深知大多数初中级Java工程师，想要提升技能，往往是自己摸索成长，但自己不成体系的自学效果低效又漫长，而且极易碰到天花板技术停滞不前！

因此收集整理了一份《2024年最新Java开发全套学习资料》送给大家，初衷也很简单，就是希望能够帮助到想自学提升又不知道该从何学起的朋友，同时减轻大家的负担。

由于文件比较大，这里只是将部分目录截图出来，每个节点里面都包含大厂面经、学习笔记、源码讲义、实战项目、讲解视频

如果你觉得这些内容对你有帮助，可以添加下面V无偿领取！（备注Java）

最后

很多程序员，整天沉浸在业务代码的 CRUD 中，业务中没有大量数据做并发，缺少实战经验，对并发仅仅停留在了解，做不到精通，所以总是与大厂擦肩而过。

我把私藏的这套并发体系的笔记和思维脑图分享出来，理论知识与项目实战的结合，我觉得只要你肯花时间用心学完这些，一定可以快速掌握并发编程。

不管是查缺补漏还是深度学习都能有非常不错的成效，需要的话记得帮忙点个赞支持一下

整理不易，觉得有帮助的朋友可以帮忙点赞分享支持一下小编~

mg-sFWzceuB-1710423184052)]

由于文件比较大，这里只是将部分目录截图出来，每个节点里面都包含大厂面经、学习笔记、源码讲义、实战项目、讲解视频

如果你觉得这些内容对你有帮助，可以添加下面V无偿领取！（备注Java）
[外链图片转存中…(img-C5PHHRkA-1710423184053)]

最后

很多程序员，整天沉浸在业务代码的 CRUD 中，业务中没有大量数据做并发，缺少实战经验，对并发仅仅停留在了解，做不到精通，所以总是与大厂擦肩而过。

我把私藏的这套并发体系的笔记和思维脑图分享出来，理论知识与项目实战的结合，我觉得只要你肯花时间用心学完这些，一定可以快速掌握并发编程。

不管是查缺补漏还是深度学习都能有非常不错的成效，需要的话记得帮忙点个赞支持一下

整理不易，觉得有帮助的朋友可以帮忙点赞分享支持一下小编~

本文已被CODING开源项目：【一线大厂Java面试题解析+核心总结学习笔记+最新讲解视频+实战项目源码】收录