延迟问题哪些 G1GC

garbage-collection java g1gc latency

2022-09-03 06:19:44

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

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

服务延迟的增加与垃圾收集指标的增加相匹配。

服务规范

我正在M4-2X大型EC2盒子上运行Java应用程序（JDK-8），每个盒子有50个活动线程。服务在 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，并将ConccGThreads = 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

全环会原因

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

答案 1

第一点是

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

但是G1GC中可以有一个参数，您可以对其进行分析：

巨大的物体

在这一点上，G1GC的大部分功能和架构都被清除了，除了最大的弱点/复杂性，Humongous对象。如前所述，G1HeapRegionSize/2 ≥的任何单个数据分配都被视为一个巨大的对象，该对象从可用空间的连续区域中分配出来，然后添加到 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 事件。如果可用空间的分配失败触发了 GC，则 GC 事件将是完整 GC，这在大多数情况下是非常不希望的。为了避免在具有大量巨型对象的应用程序中发生 Full GC 事件，必须确保可用空间池与 Eden 相比足够大，以便 Eden 始终首先填满。人们通常最终会过于谨慎，应用程序最终会处于Free ram池非常大且从未充分利用的状态，根据定义，这是浪费RAM。

在 MPCMC 结束时释放巨型对象

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

因此，您可以尝试更新最新的java。

仅在 MPCMC 结束时可收集的大量对象将增加对预留可用空间的要求，或者更有可能触发完整 GC。

查找多少巨大的物体：

步骤 1.：在 gc 上运行以下命令.log

命令 1 ：

grep "source: concurrent humongous allocation" /tmp/gc.log | sed 's/.*allocation request: $[0-9]*$ bytes.*/\1/' > humoungous_humongoud_size.txt

命令 2 ：

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

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

但最后，如果您的应用程序有内存泄漏，则必须解决此问题。

答案 2

这是一个年轻的收藏，几乎所有东西都在年轻地死去，所以与上面的评论相反，这似乎不是老一辈人填饱肚子的问题。

[Ext Root Scanning (ms): Min: 0.0, Avg: 140.9, Max: 2478.3, Diff: 2478.3, Sum: 2818.8]

它基本上花费了大部分时间扫描GC根，然后其他阶段被搁置，等待这个阶段完成。

你有很多线程（你只提到活跃的线程）吗？或者您的应用程序是否泄漏类或动态生成越来越多的字节码？

该应用程序为每个服务调用动态生成大量类，并且考虑到调用量，我怀疑这些类可能是一个问题，但不确定如何解决它。

首先，您必须确定在旧一代集合期间是否收集了这些生成的类。如果没有，您有泄漏，需要修复您的应用程序。如果它们堆积起来但最终被收集，你只需要更频繁地收集老一代，例如，通过减少年轻一代的规模（这给老一代带来更大的压力）或通过减少IHOP。