G1 GC日志

最新推荐文章于 2024-08-09 19:03:45 发布

、无崖子

最新推荐文章于 2024-08-09 19:03:45 发布

阅读量296

点赞数

分类专栏： JVM 文章标签： java jvm

本文链接：https://blog.csdn.net/nydia_lvhq/article/details/123135167

版权

JVM 专栏收录该内容

1 篇文章 0 订阅

订阅专栏

本文探讨了在JDK8和JDK9中使用G1垃圾收集器时产生的日志的不同格式。在JDK8中，G1 GC日志示例显示了一个年轻代的转移暂停，耗时3.8毫秒。日志还包括了并行时间、GC工作者线程数量等信息。而在JDK9的日志中，提到了类似的内容，但格式有所变化，例如Code Root Fixup的时间记录。

摘要由CSDN通过智能技术生成

G1 GC日志

在jdk8和jdk9中使用G1产生的日志格式是不一样的。

jdk8下面的分析参考 java训练营\第一周\预习材料\Java-GC日志解读与分析-预习资料\17-GC日志解读与分析（实例分析下篇）.pdf 这个文件对G1的日志分析

jdk8

执行

java -verbose:gc -Xms512m -Xmx512m -XX:+UseG1GC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:gc-8.log GCLogAnalysis

日志

ava HotSpot(TM) 64-Bit Server VM (25.171-b11) for windows-amd64 JRE (1.8.0_171-b11), built on Mar 28 2018 16:06:12 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 16683032k(345976k free), swap 31197264k(2029100k free)
CommandLine flags: -XX:InitialHeapSize=536870912 -XX:MaxHeapSize=536870912 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseG1GC -XX:-UseLargePagesIndividualAllocation 
2022-02-25T14:20:30.333+0800: 0.245: [GC pause (G1 Evacuation Pause) (young), 0.0019427 secs]
   [Parallel Time: 1.6 ms, GC Workers: 4]
      [GC Worker Start (ms): Min: 245.2, Avg: 245.2, Max: 245.2, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 0.2, Avg: 0.2, Max: 0.2, Diff: 0.0, Sum: 0.7]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 1.2, Avg: 1.2, Max: 1.3, Diff: 0.0, Sum: 5.0]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
         [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.1]
      [GC Worker Total (ms): Min: 1.5, Avg: 1.5, Max: 1.5, Diff: 0.0, Sum: 6.0]
      [GC Worker End (ms): Min: 246.7, Avg: 246.7, Max: 246.7, Diff: 0.0]
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.3 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.0 ms]
   [Eden: 25.0M(25.0M)->0.0B(21.0M) Survivors: 0.0B->4096.0K Heap: 32.1M(512.0M)->9959.6K(512.0M)]
 [Times: user=0.00 sys=0.00, real=0.00 secs]

我们把上面的日志分成几部分

ava HotSpot(TM) 64-Bit Server VM (25.171-b11) for windows-amd64 JRE (1.8.0_171-b11), built on Mar 28 2018 16:06:12 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 16683032k(345976k free), swap 31197264k(2029100k free)
CommandLine flags: -XX:InitialHeapSize=536870912 -XX:MaxHeapSize=536870912 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseG1GC -XX:-UseLargePagesIndividualAllocation 
2022-02-25T14:20:30.333+0800: 0.245: [GC pause (G1 Evacuation Pause) (young), 0.0019427 secs]
   [Parallel Time: 1.6 ms, GC Workers: 4]
      ...... worker线程的详情，下面单独讲解
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.3 ms]
     ...... 其他琐碎任务，下面单独讲解
   [Eden: 25.0M(25.0M)->0.0B(21.0M) Survivors: 0.0B->4096.0K Heap: 32.1M(512.0M)->9959.6K(512.0M)]
 [Times: user=0.00 sys=0.00, real=0.00 secs]

1、 [GC pause (G1 Evacuation Pause) (young)，0.0038577 secs] – G1转移暂停，纯
年轻代模式; 只清理年轻代空间。这次暂停在JVM启动之后 181 ms 开始，持续的系统时间为
0.0038577秒，也就是 3.8ms 。
2、 [Parallel Time: 3.1 ms，GC Workers: 8] – 表明后面的活动由8个 Worker 线程并行执
行，消耗时间为3.1毫秒(real time); worker 是一种模式，类似于一个老板指挥多个工人干活。
3、 …… – 为阅读方便，省略了部分内容，可以参考前面的日志，下面紧接着也会讲解。
4、 [Code Root Fixup: 0.0 ms] – 释放用于管理并行活动的内部数据，一般都接近于零。这个
过程是串行执行的

jdk9

执行

java -Xms512m -Xmx512m -XX:+UseG1GC -Xlog:gc*=info:file=gc-9.log:time:filecount=0  GCLogAnalysis

日志

[2022-02-25T14:26:09.415+0800] GC(0) Pause Young (G1 Evacuation Pause) 38M->16M(512M) 3.430ms
[2022-02-25T14:26:09.415+0800] GC(0) User=0.00s Sys=0.00s Real=0.00s
[2022-02-25T14:26:09.427+0800] GC(1) Pause Young (G1 Evacuation Pause)
[2022-02-25T14:26:09.427+0800] GC(1) Using 4 workers of 4 for evacuation
[2022-02-25T14:26:09.429+0800] GC(1)   Pre Evacuate Collection Set: 0.0ms
[2022-02-25T14:26:09.429+0800] GC(1)   Evacuate Collection Set: 2.4ms
[2022-02-25T14:26:09.429+0800] GC(1)   Post Evacuate Collection Set: 0.1ms
[2022-02-25T14:26:09.429+0800] GC(1)   Other: 0.1ms
[2022-02-25T14:26:09.429+0800] GC(1) Eden regions: 21->0(21)
[2022-02-25T14:26:09.429+0800] GC(1) Survivor regions: 4->4(4)
[2022-02-25T14:26:09.429+0800] GC(1) Old regions: 6->15
[2022-02-25T14:26:09.429+0800] GC(1) Humongous regions: 20->8
[2022-02-25T14:26:09.429+0800] GC(1) Metaspace: 4354K->4354K(1056768K)