java - 了解 G1 垃圾收集器在一个特定 GC 阶段长时间暂停的原因

Question

我正在尝试在服务器端 JVM 中使用 G1 类型的垃圾收集器，虽然一般来说，gc 暂停时间很短，但偶尔它们会突然出现，然后我们就会遇到问题。

我在下面给出了其中一个长暂停的分解，该暂停总共花费了 27.79 秒，其中 23.923 秒用于“[其他:23923.6 毫秒]”中“其他”指示的阶段。

如果有人能告诉我如何进一步理解这个特定 GC 循环阶段的原因，或者如何改善 GC 情况(这似乎在大多数情况下都是如此)，我将非常感激.

[GC pause (G1 Evacuation Pause) (young)
Desired survivor size 524288 bytes, new threshold 0 (max 0)
, 25.0957244 secs]
     [Parallel Time: 1087.3 ms, GC Workers: 4]
   [GC Worker Start (ms): Min: 5050906.2, Avg: 5050906.4, Max: 5050906.5, Diff: 0.2]
   [Ext Root Scanning (ms): Min: 1.0, Avg: 190.7, Max: 415.2, Diff: 414.2, Sum: 762.8]
   [Update RS (ms): Min: 308.9, Avg: 565.0, Max: 650.3, Diff: 341.4, Sum: 2259.8]
      [Processed Buffers: Min: 56, Avg: 69.2, Max: 82, Diff: 26, Sum: 277]
   [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
   [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
   [Object Copy (ms): Min: 0.8, Avg: 310.7, Max: 414.8, Diff: 414.0, Sum: 1242.9]
   [Termination (ms): Min: 0.0, Avg: 15.6, Max: 20.8, Diff: 20.8, Sum: 62.4]
      [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: 1066.9, Avg: 1082.0, Max: 1087.2, Diff: 20.3, Sum: 4328.2]
   [GC Worker End (ms): Min: 5051973.4, Avg: 5051988.4, Max: 5051993.4, Diff: 20.0]
[Code Root Fixup: 0.2 ms]
[Code Root Purge: 0.0 ms]
[String Dedup Fixup: 2.0 ms, GC Workers: 4]
   [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
   [Table Fixup (ms): Min: 0.1, Avg: 0.9, Max: 1.9, Diff: 1.8, Sum: 3.7]
[Clear CT: 82.6 ms]
[Other: 23923.6 ms]
   [Choose CSet: 0.0 ms]
   [Ref Proc: 415.2 ms]
   [Ref Enq: 0.0 ms]
   [Redirty Cards: 0.1 ms]
   [Humongous Register: 0.1 ms]
   [Humongous Reclaim: 0.1 ms]
   [Free CSet: 0.2 ms]
[Eden: 119.0M(119.0M)->0.0B(133.0M) Survivors: 0.0B->0.0B Heap: 572.3M(2391.0M)->456.2M(2666.0M)]
[Times: user=0.00 sys=1.29, real=27.79 secs] 

Answer 1

[Times: user=0.00 sys=1.29, real=27.79 secs]

它几乎不花费任何 CPU 周期来进行垃圾收集，并且所有时间都在内核中，甚至更多的挂起时间，这表明该进程在内核中被阻止执行操作。主要嫌疑人是您的系统交换。

其他潜在原因:

• 系统因其他进程而导致 CPU 资源匮乏
• IO 被必须旋转的空闲硬盘阻止
• 超出配额 - 尤其是在容器化或虚拟机环境中
• THP 压缩 - 尽管这不太可能，因为它通常通过更高的内核负载表现出来

您还可以尝试使用 -XX:G1LogLevel=fine/finer/finest 增加 GC 日志详细程度，看看这是否表明存在任何特殊情况，但症状表明存在系统级问题，但没有任何问题特定于虚拟机。