这个 Java G1 GC 日志消息是什么意思？

Question

这是来自在 JDK 11 的某些开源变体上运行的 Java 进程，该进程使用 24G 堆 G1GC 运行。

[info ][gc,marking     ] GC(132605) Concurrent Mark (728435.456s, 728445.080s) 9624.269ms

1. 并发标记在G1中真的是并发吗（除了重标记时间）？这意味着这里测量的时间不是暂停时间。
2. 这个时间代表什么？这是CPU时间吗？挂钟时间？

我已经用谷歌搜索了一下这可能是什么，但我从未找到这个特定消息的含义。

Answer 1

1. 是的，这不是暂停时间。
   您还可以添加安全点记录器以查看任何其他暂停。
   但除此之外，我认为所有实际的暂停都以清晰的方式记录，说明哪部分是暂停。例如Pause Young (Mixed) (G1 Evacuation Pause)

2. 它应该是GC(number of GC) Concurrent Mark(clock start time, clock end time) time
   其中点击时间是应用程序启动后的相对时间。最后的时间就是花了多长时间，也是真正的墙上时间。您可以在源代码中直接验证这一点：https://github.com/openjdk/jdk/blob/7ccf4358256a0fef895e4081f90b04f71d21bf9d/src/hotspot/share/gc/g1/g1ConcurrentMarkThread.cpp#L184-L220

        log_info(gc, marking)("Concurrent Mark (%.3fs, %.3fs) %.3fms",
                              TimeHelper::counter_to_seconds(mark_start),
                              TimeHelper::counter_to_seconds(mark_end),
                              TimeHelper::counter_to_millis(mark_end - mark_start));

如果您启用了足够的日志记录，您应该会在上面看到一行：
[info ][gc,marking ] GC(132605) Concurrent Mark 728435.456s 或
[728435.456s][info ][gc,marking ] GC(132605) Concurrent Mark 728435.456s
Somehwere，标记并发标记的开始。（这里开始的时间是 gc 记录器的正常运行时间装饰器）

由上述来源中的第一行之一打印：

      log_info(gc, marking)("Concurrent Mark (%.3fs)",
                            TimeHelper::counter_to_seconds(mark_start));