美文网首页
Java GC日志分析

Java GC日志分析

作者: FourtySeven | 来源:发表于2021-03-26 19:57 被阅读0次

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 引用或者被年轻代存活对象所引用的所有对象,标记后示例如下所示:


file

2. 并发标记

在这个阶段 Garbage Collector 会遍历老年代,然后标记所有存活的对象,它会根据上个阶段找到的 GC Roots 遍历查找。并发标记阶段,它会与用户的应用程序并发运行。并不是老年代所有的存活对象都会被标记,因为在标记期间用户的程序可能会改变一些引用,如下图所示:


file

3.并发预清理

Concurrent Preclean:这也是一个并发阶段,与应用的线程并发运行,并不会 stop 应用的线程。在并发运行的过程中,一些对象的引用可能会发生变化,但是这种情况发生时,JVM 会将包含这个对象的区域(Card)标记为 Dirty,这也就是 Card Marking。如下图所示:


file

在pre-clean阶段,那些能够从 Dirty 对象到达的对象也会被标记,这个标记做完之后,dirty card 标记就会被清除了,如下:


file

4.并发可终止预清理

这也是一个并发阶段,但是同样不会影响影响用户的应用线程,这个阶段是为了尽量承担 STW(stop-the-world)中最终标记阶段的工作。这个阶段持续时间依赖于很多的因素,由于这个阶段是在重复做很多相同的工作,直接满足一些条件(比如:重复迭代的次数、完成的工作量或者时钟时间等)

5.重新标记

这是第二个 STW 阶段,也是 CMS 中的最后一个,这个阶段的目标是标记所有老年代所有的存活对象,由于之前的阶段是并发执行的,gc 线程可能跟不上应用程序的变化,为了完成标记老年代所有存活对象的目标,STW 就非常有必要了。 通常 CMS 的 Final Remark 阶段会在年轻代尽可能干净的时候运行,目的是为了减少连续 STW 发生的可能性(年轻代存活对象过多的话,也会导致老年代涉及的存活对象会很多)。这个阶段会比前面的几个阶段更复杂一些

6.并发标记

这里不需要 STW,它是与用户的应用程序并发运行,这个阶段是:清除那些不再使用的对象,回收它们的占用空间为将来使用。如下图所示:


file

7.并发重置

这个阶段也是并发执行的,它会重设 CMS 内部的数据结构,为下次的 GC 做准备

本文由博客群发一文多发等运营工具平台 OpenWrite 发布

相关文章

  • GC日志查看和分析

    GC日志查看和分析 GC日志查看 可以通过在java命令种加入参数来指定对应的gc类型,打印gc日志信息并输出至文...

  • GC 日志分析工具列表

    gc日志分析工具 性能测试排查定位问题,分析调优过程中,会遇到要分析gc日志,人肉分析gc日志有时比较困难,相关图...

  • java-GC分析

    主要关注点: GC日志分析 调优命令 调优工具 GC日志分析 摘录GC日志一部分(前段为年轻代gc回收;后段为fu...

  • Java GC日志分析

    1. 查看GC日志准备 2. 年轻代GC日志 3. CMS GC日志 4. CMS GC 7阶段解析 1.初始标记...

  • 实验:老年代空闲空间放不下minorgc晋升的对象发生fullg

    实验代码 gc日志分析 0.348: [GC (Allocation Failure) 0.348: [ParNe...

  • GC日志

    阅读GC日志是处理Java虚拟机内存问题的基础技能。以下两端典型的GC日志: 33.125:[GC [DefNew...

  • Java GC 日志详解(一图读懂)

    Java GC日志可以通过 +PrintGCDetails开启 以ParallelGC为例 YoungGC日志解释...

  • GC日志的分析

    以下是一段GC日志。 日志分析: 0.244 : 系统启动0.244秒后,发生。 GC (Allocation F...

  • 25-GC日志分析

    一、GC日志参数列表 通过阅读GC日志,可以了解Java虚拟机内存分配与回收策略 -XX:+PrintGC :输...

  • JVM日志查看

    parNew young gc 日志分析 36402.792是gc相对于进程起来的时间,gc后面的Allocati...

网友评论

      本文标题:Java GC日志分析

      本文链接:https://www.haomeiwen.com/subject/szdshltx.html