时间戳

首页 > 解决方案 > 这个 Java G1 GC 日志消息是什么意思？

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

问题描述

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

[info ][gc,marking     ] GC(132605) Concurrent Mark (728435.456s, 728445.080s) 9624.269ms
  1. 并发标记在G1中真的是并发（remarking时间除外）？这意味着这里测量的时间不是暂停时间。
  2. 这个时间代表什么？这是 CPU 时间吗？挂钟时间？

我已经做了一些谷歌搜索，看看这可能是什么，但我从来没有找到这个特定消息的含义。

标签： javagarbage-collection

解决方案

  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));

推荐阅读