上一篇文章中,我们详细介绍了 CMS 的配置参数以及 gc log 的解读:
但事实上,g1 由于他的诸多优势已经越来越多的受到 java 程序员的青睐,尤其在机器内存日益增大的今天,巨大的内存分区无疑会让 CMS 回收时间过长,而这已经成为程序员们无法忍受 CMS 最重要的一个原因。
此前,我们已经深入介绍了 g1 垃圾回收的机制以及相应的配置:
本文,我们就来详细介绍一下 g1 的 gc log,让你能够通过 g1 的 gc log 分析出性能问题出在哪里。
当然,上文介绍的两个实用的 gc log 分析工具:GCeasy 与 GC Viewer,都可以直接用于分析 g1 的 gc log,本文就不再赘述了。
上一篇文章中介绍的 gc 日志打印的相关参数在 g1 垃圾回收器中仍然是可用的:
-Xloggc:<path> # gc log 的输出路径 -XX:+PrintGC # 输出 gc log -XX:+PrintGCDetails # 输出 gc 详细信息 -XX:+PrintGCDateStamps # 在 gc log 中记录 gc 启动时的系统时间 -XX:+PrintGCTimeStamps # 在 gc log 中记录 gc 启动时相对于 jvm 启动的相对时间
-XX:+UnlockDiagnosticVMOptions # 解锁诊断参数 -XX:+G1SummarizeConcMark # jvm 退出时汇总并发标记 -XX:+G1PrintHeapRegions # 打印垃圾收集的 region 信息 -XX:G1PrintRegionLivenessInfo # 打印在并发标记周期的清理阶段每个区的活跃数据信息 -XX:+G1SummarizeRSetStats # 打印 RSet 回收情况 -XX:G1SummarizeRSetStatsPeriod=period # 打印 RSet 回收报告周期(每 period 次 GC 打印一次报告)
-XX:+UnlockExperimentalVMOptions # 解锁实验参数 -XX:G1LogLevel=fine, finer, finest # GC 日志级别 -XX:+G1TraceEagerReclaimHumongousObjects # 跟踪并输出超大对象回收相关信息 -XX:+G1ConcRegionFreeingVerbose # Debug JVM
对于线上持续运行的 java 程序来说,gc 日志不断地输出,会导致单个 GC 日志文件过大,这十分不利于我们去获取和分析,以一定的规则自动切割 gc 日志文件无疑对我们来说更为方便。
下面我们就来介绍两种常见的日志自动分割方式的配置。
-Xloggc:/data/var/gclog/gc.log -XX:+UseGCLogFileRotation # 开启循环分割 -XX:NumberOfGCLogFiles=5 # gc log 文件数 -XX:GCLogFileSize=20M # 单个 gc log 文件最大容量
通过这个配置,JVM的一个日志文件达到了20M以后,就会写入另一个新的文件,最多会有5个日志文件,他们的名字分别是:gc.log.0、gc.log.1、gc.log.2、gc.log.3、gc.log.4。
当 gc.log.4 文件达到 20M 以后,JVM 就会删除并重新创建 gc.log.0,并向其中写入新的 gc log。
这个方式是非常不推荐使用的。因为他存在以下问题:
显而易见,当 gc.log.4 日志达到配置中的 20M 大小,我们就会丢失 gc.log.0 中的内容,这可能造成一些问题我们无法定位和排查。
尽管日志是循环覆盖的,但每当重启 jvm,gc 日志都会从 gc.log.0 开始写起,这就会造成你无法知道到底哪个 gc 日志是新的,哪个是旧的,他们掺杂在一起。
如果你想要使用日志分析工具,那么你就需要提前合并上传多个文件。
-Xloggc:/data/var/gclog/gc-%t.log
这种方式是更为推荐的,%t 会给文件名添加时间戳后缀,格式是YYYY-MM-DD_HH-MM-SS。
这样,每次 JVM 重启以后,会生成新的日志文件,新的日志也不会覆盖老的日志。
如图所示,相较于 CMS 的 GC 日志,G1 的 GC 日志信息更为详细。
主要包含了以下六部分内容:
如图所示,并发标记主要分为六个步骤:
GC pause (G1 Evacuation Pause) (young) (initial-mark)
初始标记是 Young GC 的一部分,他的主要工作是寻找所有可达的存活对象。
初始标记阶段会设置两种 TAMS 变量来区分现存的对象和并行标记时才分配的对象。
GC concurrent-root-region-scan-start / GC concurrent-root-region-scan-end
与上一阶段不同,这个阶段 GC 的线程可以和应用线程并发运行,他的主要工作是进行根分区扫描,扫描初始标记的对象和 survivor 分区中引用的对象。
GC concurrent-mark-start / GC concurrent-mark-end
这一阶段就是 -XX:ConcGCThreads 参数指定并发线程数的并发标记阶段。
这一阶段会并发标记所有非完全空闲的分区的存活对象,使用 SATB 算法标记各个分区。
GC remark [ Finalize Marking / GC ref-proc / Unloading]
这一阶段的主要工作是处理 SATB 缓冲,标记上一阶段没有标记的新生存活对象。
GC cleanup
GC concurrent-cleanup-start / GC concurrent-cleanup-end
一旦并发标记完成,紧接着就会进行一次 mixed gc。
如上图所示,mixed gc 与 young gc 在日志中表现基本上是相同的,这里就不再赘述了。
mixed gc 的日志与 young gc 的日志仅存在两点区别:
在 G1 中,full gc 是我们要极力避免的,他是整个堆内存的完整收集,因此,G1 中的 full gc 通常意味着一个漫长的 stw 暂停。
full gc 的日志中包含有三部分信息:
通过 -XX:+PrintGCApplicationStoppedTime 参数和 -XX:+PrintGCApplicationConcurrentTime 参数可以产生汇总信息日志:
他包含三部分信息:
如果你想了解到整个 GC 过程中更加详细的内容,你可以设置下面三个参数:
-XX:+PrintAdaptiveSizePolicy # 每次 GC 后根据本次 GC 的时间、吞吐量、内存占用量重新计算 Eden、From 和 To 区的大小并打印 -XX:+PrintTenuringDistribution # 打印 Survivor 对象年龄分布 -XX:+PrintReferenceGC # 打印各种引用的处理时间