如何使用“-Xlog:heap=debug”“-Xlog:gc=debug”从 GC 中正确读取日志记录的某些部分

Question

假设我有非常简单的代码：

public class Sandbox { 

    public static void main(String[] args) {

        Map<String, Integer> map = new HashMap<>();

        while (true) {
            map.put(new Random().toString(), new Random().nextInt());
        }
    }
}

它如何 "incorrect" 并不重要，重要的是它的作用。它最终会产生一个 OutOfMemory。我运行它与 :

java -Xms50M -Xmx50M "-Xlog:heap*=debug" "-Xlog:gc*=debug" Sandbox

日志会比较多，我会删掉我最关心的部分（为了方便阅读，我也去掉了一些行的信息）

*****************************     GC(0)    *********************************

[0.115s][debug][gc,heap] GC(0) Heap before GC invocations=0 (full 0)
[0.115s][debug][gc,heap] GC(0) region size 1024K, 23 young, 0 survivors

[0.127s][info ][gc,heap] GC(0) Eden regions: 23->0(15)
[0.128s][info ][gc,heap] GC(0) Survivor regions: 0->3(3)
[0.128s][info ][gc,heap] GC(0) Old regions: 0->4
[0.128s][info ][gc,heap] GC(0) Archive regions: 2->2
[0.128s][info ][gc,heap] GC(0) Humongous regions: 1->1

[0.128s][debug][gc,heap] GC(0) Heap after GC invocations=1 (full 0):
[0.128s][debug][gc,heap] GC(0) region size 1024K, 3 young, 3 survivors


 *****************************     GC(1)    *********************************

[0.159s][debug][gc,heap] GC(1) Heap before GC invocations=1 (full 0)
[0.159s][debug][gc,heap] GC(1) region size 1024K, 18 young, 3 survivors

[0.181s][info ][gc,heap] GC(1) Eden regions: 15->0(1)
[0.181s][info ][gc,heap] GC(1) Survivor regions: 3->3(3)
[0.181s][info ][gc,heap] GC(1) Old regions: 4->10
[0.181s][info ][gc,heap] GC(1) Archive regions: 2->2
[0.181s][info ][gc,heap] GC(1) Humongous regions: 3->3

[0.181s][debug][gc,heap] GC(1) Heap after GC invocations=2 (full 0)
[0.181s][debug][gc,heap] GC(1) region size 1024K, 3 young, 3 survivors

*****************************     GC(2)    *********************************

[0.182s][debug][gc,heap] GC(2) Heap before GC invocations=2 (full 0)
[0.182s][debug][gc,heap] GC(2) region size 1024K, 4 young, 3 survivors 

[0.190s][info ][gc,heap] GC(2) Eden regions: 1->0(9)
[0.190s][info ][gc,heap] GC(2) Survivor regions: 3->1(1)
[0.190s][info ][gc,heap] GC(2) Old regions: 10->13
[0.190s][info ][gc,heap] GC(2) Archive regions: 2->2
[0.190s][info ][gc,heap] GC(2) Humongous regions: 3->3

[0.190s][debug][gc,heap] GC(2) Heap after GC invocations=3 (full 0)
[0.190s][debug][gc,heap] GC(2) region size 1024K, 1 young, 1 survivors

它们究竟是什么意思？

Answer 1

我只在网上找到两个参考文献以某种方式解释了这一点：一个 here and the other here。不幸的是，它们都没有多大意义，所以我不得不查看生成它的源代码以获得理解。

第一行：

[0.115s][debug][gc,heap] GC(0) Heap before GC invocations=0 (full 0)
[0.115s][debug][gc,heap] GC(0) region size 1024K, 23 young, 0 survivors

告诉你在第一次调用 GC (0) 之前，年轻的 space 分配了 23 个区域。它还（间接地）告诉您，在这 23 个中：0 是幸存者区域，这意味着 23 是 Eden 个。

下一行：

[0.127s][info ][gc,heap] GC(0) Eden     regions:     23 -> 0 (15)
[0.128s][info ][gc,heap] GC(0) Survivor regions:     0  -> 3 (3)

告诉你在 GC operation 之前，有 23 个伊甸园区域。全部都被清除了（即0）（毕竟这是young GC存在的原因）。那么就说明在GC之前有0个Survivor region，但是作为这个循环的结果，产生了3 Survivor Regions个。

你必须格外小心这意味着什么。此不会显示有多少区域可用于下一个周期，这仅显示发生的转换。

这个 "transition" 在这些日志中有解释：

[0.128s][debug][gc,heap] GC(0) Heap after GC invocations=1 (full 0):
[0.128s][debug][gc,heap] GC(0) region size 1024K, 3 young, 3 survivors

注意堆如何过渡到 3 young, 3 survivors（因此，0 eden，所有 23 都被清除）。

后面还有一个步骤：调整区域总数。如何？你可以看看source code yourself，一探究竟。

具体来说 (3) 会被计算 here with more details (and very good comments) here，它基本上表示有多少 Survivor Regions 将可用于下一个 GC 周期。在大多数情况下，对于幸存者区域，(3) 将等于 ->3。

这个"adjustment"就是那个(15)和(3)，也就是说，下一个循环会有15 Eden Regions和3 Survivor Regions；也由 下一个 周期的日志表示，在它的最开始。

[0.159s][debug][gc,heap] GC(1) Heap before GC invocations=1 (full 0)
[0.159s][debug][gc,heap] GC(1) region size 1024K, 18 young, 3 survivors

我需要在这里发表一个评论：这些是提示下一个循环中的 GC 应该使用什么，它们可能会被忽略（humongous allocation 会导致这种情况，例如）。

所以我们现在可以画一条线了。这些日志中有两个逻辑部分。

过渡 - 年轻地区如何因这个周期而发生变化
调整过渡后年轻区域的数量。

现在应该很容易消化一些日志，例如：

[0.182s][debug][gc,heap] GC(2) Heap before GC invocations=2 (full 0)
[0.182s][debug][gc,heap] GC(2) region size 1024K, 4 young, 3 survivors

它开始 4 young = 1 Eden + 3 Survivor

[0.190s][info ][gc,heap] GC(2) Eden     regions: 1 -> 0 (9)
[0.190s][info ][gc,heap] GC(2) Survivor regions: 3 -> 1 (1)

它过渡到0 Eden, 1 Survivor

[0.190s][info ][gc,heap] GC(2) Eden     regions: 1 -> 0 (9)
[0.190s][info ][gc,heap] GC(2) Survivor regions: 3 -> 1 (1)

它应用启发式生成 9 Eden, 1 Survivor 到下一个 GC 周期。

如何使用“-Xlog:heap=debug”“-Xlog:gc=debug”从 GC 中正确读取日志记录的某些部分

How to properly read some parts of the logging from GC with "-Xlog:heap=debug" "-Xlog:gc=debug"

java

garbage-collection

jvm

g1gc

java-9

如何使用“-Xlog:heap*=debug”“-Xlog:gc*=debug”从 GC 中正确读取日志记录的某些部分

How to properly read some parts of the logging from GC with "-Xlog:heap*=debug" "-Xlog:gc*=debug"

java

garbage-collection

jvm

g1gc

java-9

如何使用“-Xlog:heap=debug”“-Xlog:gc=debug”从 GC 中正确读取日志记录的某些部分

How to properly read some parts of the logging from GC with "-Xlog:heap=debug" "-Xlog:gc=debug"