1. 查看GC日志准备
-XX:+PrintGC 输出GC日志
-XX:+PrintGCDetails 输出GC的详细日志
-XX:+PrintGCTimeStamps 输出GC的时间戳(以基准时间的形式)
-XX:+PrintGCDateStamps 输出GC的时间戳(以日期的形式,如 2013-05-04T21:53:59.234+0800)
-XX:+PrintHeapAtGC 在进行GC的前后打印出堆的信息
-Xloggc:../logs/gc.log 日志文件的输出路径
2. 年轻代GC日志
2019-09-17T23:12:05.334+0800: 6950.220: [GC2019-09-17T23:12:05.334+0800: 6950.220: [ParNew: 1713371K->30726K(1887488K), 0.0325240 secs] 1910235K->227695K(6081792K), 0.0329710 secs] [Times: user=0.12 sys=0.01, real=0.04 secs
3. CMS GC日志
2019-09-17T21:19:48.213+0800: 213.099: [GC [1 CMS-initial-mark: 2136781K(4194304K)] 2378922K(6081792K), 0.0269660 secs] [Times: user=0.02 sys=0.00, real=0.03 secs]
2019-09-17T21:19:48.240+0800: 213.126: [CMS-concurrent-mark-start]
2019-09-17T21:19:48.499+0800: 213.385: [CMS-concurrent-mark: 0.259/0.259 secs] [Times: user=0.98 sys=0.08, real=0.26 secs]
2019-09-17T21:19:48.499+0800: 213.385: [CMS-concurrent-preclean-start]
2019-09-17T21:19:48.508+0800: 213.394: [CMS-concurrent-preclean: 0.009/0.009 secs] [Times: user=0.01 sys=0.01, real=0.01 secs]
2019-09-17T21:19:48.509+0800: 213.395: [CMS-concurrent-abortable-preclean-start]
2019-09-17T21:19:50.125+0800: 215.011: [CMS-concurrent-abortable-preclean: 1.612/1.616 secs] [Times: user=3.28 sys=0.08, real=1.62 secs]
2019-09-17T21:19:50.125+0800: 215.011: [GC[YG occupancy: 1065145 K (1887488 K)]2019-09-17T21:19:50.125+0800: 215.011: [Rescan (parallel) , 0.1963400 secs]2019-09-17T21:19:50.321+0800: 215.207: [weak refs processing, 0.0003260 secs]2019-09-17T21:19:50.322+0800: 215.208: [class unloading, 0.0267880 secs]2019-09-17T21:19:50.349+0800: 215.235: [scrub symbol table, 0.0894820 secs]2019-09-17T21:19:50.438+0800: 215.324: [scrub string table, 0.0028500 secs] [1 CMS-remark: 2136781K(4194304K)] 3201926K(6081792K), 0.3199900 secs] [Times: user=0.87 sys=0.03, real=0.32 secs]
2019-09-17T21:19:50.445+0800: 215.331: [CMS-concurrent-sweep-start]
2019-09-17T21:19:51.334+0800: 216.220: [CMS-concurrent-sweep: 0.888/0.889 secs] [Times: user=1.81 sys=0.20, real=0.89 secs]
2019-09-17T21:19:51.334+0800: 216.220: [CMS-concurrent-reset-start]
2019-09-17T21:19:51.378+0800: 216.264: [CMS-concurrent-reset: 0.044/0.044 secs] [Times: user=0.09 sys=0.04, real=0.04 secs]
4. CMS GC 7阶段解析
1.初始标记
这个是 CMS 两次 stop-the-wolrd 事件的其中一次,这个阶段的目标是:标记那些直接被 GC root 引用或者被年轻代存活对象所引用的所有对象,标记后示例如下所示:
2. 并发标记
在这个阶段 Garbage Collector 会遍历老年代,然后标记所有存活的对象,它会根据上个阶段找到的 GC Roots 遍历查找。并发标记阶段,它会与用户的应用程序并发运行。并不是老年代所有的存活对象都会被标记,因为在标记期间用户的程序可能会改变一些引用,如下图所示:
3.并发预清理
Concurrent Preclean:这也是一个并发阶段,与应用的线程并发运行,并不会 stop 应用的线程。在并发运行的过程中,一些对象的引用可能会发生变化,但是这种情况发生时,JVM 会将包含这个对象的区域(Card)标记为 Dirty,这也就是 Card Marking。如下图所示: 在pre-clean阶段,那些能够从 Dirty 对象到达的对象也会被标记,这个标记做完之后,dirty card 标记就会被清除了,如下:
4.并发可终止预清理
这也是一个并发阶段,但是同样不会影响影响用户的应用线程,这个阶段是为了尽量承担 STW(stop-the-world)中最终标记阶段的工作。这个阶段持续时间依赖于很多的因素,由于这个阶段是在重复做很多相同的工作,直接满足一些条件(比如:重复迭代的次数、完成的工作量或者时钟时间等)
5.重新标记
这是第二个 STW 阶段,也是 CMS 中的最后一个,这个阶段的目标是标记所有老年代所有的存活对象,由于之前的阶段是并发执行的,gc 线程可能跟不上应用程序的变化,为了完成标记老年代所有存活对象的目标,STW 就非常有必要了。 通常 CMS 的 Final Remark 阶段会在年轻代尽可能干净的时候运行,目的是为了减少连续 STW 发生的可能性(年轻代存活对象过多的话,也会导致老年代涉及的存活对象会很多)。这个阶段会比前面的几个阶段更复杂一些
6.并发标记
这里不需要 STW,它是与用户的应用程序并发运行,这个阶段是:清除那些不再使用的对象,回收它们的占用空间为将来使用。如下图所示:
7.并发重置
这个阶段也是并发执行的,它会重设 CMS 内部的数据结构,为下次的 GC 做准备
本文由博客群发一文多发等运营工具平台 OpenWrite 发布