java - G1GC 的延迟问题

Question

我面临着使用 G1GC 算法时 GC 暂停持续增加的问题。随着时间的推移，服务延迟持续增长。一旦发生这种情况，我重新启动我的服务，延迟恢复正常。启动后，延迟再次随时间增加。

在启动时，服务延迟约为 200 毫秒，但在 24 小时内，它们上升到 350 毫秒，并继续以线性方式增加。

服务延迟的增加与 GarbageCollection 指标的增加相匹配。

服务规范

我在 M4-2X 大型 EC2 机器上运行一个 Java 应用程序 (JDK-8)，每个机器有 50 个 Activity 线程。服务在 12GB 堆上运行。请求的平均延迟约为 250 毫秒，传入请求的速率约为每箱每秒 20 个。

G1G1 配置

        <jvmarg line="-Xms12288M"/>
        <jvmarg line="-Xmx12288M"/>

        <jvmarg line="-verbose:gc" />
        <jvmarg line="-XX:+UseG1GC"/>
        <jvmarg line="-XX:+PrintGCDetails" />
        <jvmarg line="-XX:+PrintGCTimeStamps" />
        <jvmarg line="-XX:+PrintTenuringDistribution" />
        <jvmarg line="-XX:+PrintGCApplicationStoppedTime" />
        <jvmarg line="-XX:MaxGCPauseMillis=250"/>
        <jvmarg line="-XX:ParallelGCThreads=20" />
        <jvmarg line="-XX:ConcGCThreads=5" />
        <jvmarg line="-XX:-UseGCLogFileRotation"/>

GC 日志

79488.355: Total time for which application threads were stopped: 0.0005309 seconds, Stopping threads took: 0.0000593 seconds
79494.559: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 369098752 bytes, new threshold 15 (max 15)
- age   1:   64725432 bytes,   64725432 total
- age   2:    8867888 bytes,   73593320 total
- age   3:    2503592 bytes,   76096912 total
- age   4:     134344 bytes,   76231256 total
- age   5:    3729424 bytes,   79960680 total
- age   6:     212000 bytes,   80172680 total
- age   7:     172568 bytes,   80345248 total
- age   8:     175312 bytes,   80520560 total
- age   9:     282480 bytes,   80803040 total
- age  10:     160952 bytes,   80963992 total
- age  11:     140856 bytes,   81104848 total
- age  12:     153384 bytes,   81258232 total
- age  13:     123648 bytes,   81381880 total
- age  14:      76360 bytes,   81458240 total
- age  15:      63888 bytes,   81522128 total
, 2.5241014 secs]
   [Parallel Time: 2482.2 ms, GC Workers: 20]
      [GC Worker Start (ms): Min: 79494558.9, Avg: 79494567.4, Max: 79494602.1, Diff: 43.2]
      [Ext Root Scanning (ms): Min: 0.0, Avg: 140.9, Max: 2478.3, Diff: 2478.3, Sum: 2818.8]
      [Update RS (ms): Min: 0.0, Avg: 5.3, Max: 41.9, Diff: 41.9, Sum: 106.9]
         [Processed Buffers: Min: 0, Avg: 23.2, Max: 80, Diff: 80, Sum: 465]
      [Scan RS (ms): Min: 0.1, Avg: 0.2, Max: 0.4, Diff: 0.3, Sum: 4.1]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.4]
      [Object Copy (ms): Min: 0.0, Avg: 41.9, Max: 68.7, Diff: 68.7, Sum: 837.9]
      [Termination (ms): Min: 0.0, Avg: 2282.3, Max: 2415.8, Diff: 2415.8, Sum: 45645.3]
         [Termination Attempts: Min: 1, Avg: 21.5, Max: 68, Diff: 67, Sum: 430]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.2, Diff: 0.1, Sum: 1.0]
      [GC Worker Total (ms): Min: 2435.8, Avg: 2470.7, Max: 2482.0, Diff: 46.2, Sum: 49414.5]
      [GC Worker End (ms): Min: 79497037.9, Avg: 79497038.1, Max: 79497041.0, Diff: 3.1]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.9 ms]
   [Other: 40.9 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 37.7 ms]
      [Ref Enq: 0.8 ms]
      [Redirty Cards: 0.4 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 1.3 ms]
   [Eden: 5512.0M(5512.0M)->0.0B(4444.0M) Survivors: 112.0M->128.0M Heap: 8222.2M(12.0G)->2707.5M(12.0G)]
 [Times: user=19.63 sys=0.18, real=2.53 secs]
79497.083: Total time for which application threads were stopped: 2.5252654 seconds, Stopping threads took: 0.0000914 seconds

我正在寻求有关 GC 配置的帮助。根据我的阅读，我打算将并行线程数增加到32，将G1HeapRegionSize设置为16M，并设置ConcGCThreads = 8。

    Mixed   Concurrent Mark Remark  Cleanup initial-mark    Young GC    Total
Count   14  4   4   4   4   263 293
Total GC Time   4 sec 120 ms    0   1 sec 100 ms    70 ms   980 ms  1 min 8 sec 10 ms   1 min 14 sec 280 ms
Avg GC Time     294 ms  0   275 ms  17 ms   245 ms  259 ms  254 ms
Avg Time std dev    127 ms  0   73 ms   4 ms    73 ms   63 ms   79 ms
Min/Max Time    0 / 560 ms  0 / 0   0 / 400 ms  0 / 20 ms   0 / 340 ms  0 / 620 ms  0 / 620 ms
Avg Interval Time   2 min 55 sec 119 ms 12 min 32 sec 443 ms    12 min 32 sec 443 ms    12 min 32 sec 449 ms    12 min 32 sec 423 ms    13 sec 686 ms   51 sec 887 ms

GC 原因

Cause   Count   Avg Time    Max Time    Total Time  Time %
G1 Evacuation Pause     263 259 ms  560 ms  1 min 8 sec 50 ms   91.61%
GCLocker Initiated GC   15  272 ms  400 ms  4 sec 80 ms 5.49%
Others  12  n/a n/a 1 sec 250 ms    1.68%
G1 Humongous Allocation     3   300 ms  340 ms  900 ms  1.21%
Total   293 n/a n/a 1 min 14 sec 280 ms 99.99%

任期总结

Desired Survivor Size: 448.0 mb,

Max Threshold: 15

Age Survival Count  Average size (kb)   Average Total 'To' size (kb)
age 1   281 54856.84    54856.84
age 2   273 32935.6 89227.65
age 3   258 29812.41    122175.68
age 4   235 28499.48    158266.46
age 5   214 27909.13    196528.23
age 6   192 26896.33    237892.45
age 7   180 25759.58    272516.81
age 8   174 23565.21    299092.37
age 9   166 21745.62    320927.73
age 10  149 19323.6 340228.24
age 11  125 17400.14    357569.6
age 12  96  13995.26    372030.12
age 13  55  10909.19    378053.14
age 14  38  10197.95    389146.13
age 15  22  5996.65 395657.37

Answer 1

第一点是

您需要检查您的应用程序中是否存在任何连接泄漏。

但是G1GC中可以有一个参数，你可以分析一下:

巨大的物体

此时，G1GC 的大部分功能和架构都已清除，除了最大的弱点/复杂性，即 Humongous 对象。如前所述，任何大于等于 G1HeapRegionSize/2 的单个数据分配都被认为是 Humongous 对象，它是从连续的可用空间区域中分配出来的，然后将其添加到 Tenured 中。让我们来看看一些基本特征以及它们如何影响正常的 GC 生命周期。以下关于 Humongous 对象的讨论将深入了解 Humongous 对象的缺点，例如:

Increase the risk of running out of Free space and triggering a Full GC
Increase overall time spent in STW

巨大的对象被分配到可用空间之外。分配失败触发 GC 事件。如果 Free space 的分配失败触发了 GC，那么 GC 事件将是 Full GC，这在大多数情况下是非常不可取的。为了避免在具有大量 Humongous 对象的应用程序中发生 Full GC 事件，必须确保空闲空间池与 Eden 相比足够大，Eden 总是首先填满。人们通常会过度谨慎，应用程序最终会处于空闲 ram 池非常大且从未被充分利用的状态，根据定义，这就是在浪费 RAM。

巨大的对象在 MPCMC 结束时被释放

直到大约 Oracle JDK 8u45，Humongous 对象确实只在 MPCMC 运行结束时才被收集。 Oracle 8u45-8u65 版本的发行说明有一些提交表明一些(但不是全部)Humongous 对象在次要事件期间被收集。

所以，你可以尝试更新最新的java。

仅在 MPCMC 结束时才可收集的巨大对象将增加对保留可用空间的要求或更有可能触发 Full GC。

找出有多少巨大的物体:

第 1 步:在您的 gc.log 上运行以下命令

命令 1:

grep "source: concurrent humongous allocation"/tmp/gc.log | sed 's/.*分配请求:\([0-9]*\) bytes.*/\1/' > humoungous_humongoud_size.txt

命令 2:

awk -F',' '{sum+=$1} END{print sum;}' humoungous_humongoud_size.txt

它将为您提供在我的应用程序中生成的巨大对象的大小。

但最后，如果您的应用程序存在内存泄漏，您必须解决它。