Rapid Young G1 疏散集合

Question

我正在使用一个最近升级的应用程序，我看到了我无法解释的新行为。收集模式看起来不错，但随后将在几秒钟内连续执行超过 10 个 G1 疏散收集（年轻）。他们似乎正在清理伊甸园的记忆，但我不明白为什么它会这么快填满。

这是一个复杂的问题还是我做错了什么？ （如果我发布的细节太多，我可以编辑并删除它。

-XX:+UseG1GC -Xms10240m -Xmx10240m -XX:NewRatio=2 -XX:NewSize=1792m -XX:G1ReservePercent=30 -XX:+AggressiveOpts

GCViewer 如果您查看此屏幕截图，您会看到近乎实线的蓝线，其中年轻一代收集快速连续发生。

2017-03-02T12：27：08.527-0800：48187.087：[GC 暂停（G1 疏散暂停）（年轻） 所需的幸存者大小 299892736 字节，新阈值 15（最大 15） - 年龄 1：6684488 字节，总共 6684488 - 年龄 2：15234432 字节，总共 21918920 - 年龄 3：5530024 字节，总共 27448944 - 年龄 4：5502152 字节，总共 32951096 - 5 岁：4490976 字节，总共 37442072 - 6 岁：1736456 字节，总共 39178528 - 7 岁：2849184 字节，总共 42027712 - 8 岁：2600504 字节，总共 44628216 - 9 岁：1793032 字节，总共 46421248 - 10 岁：1996752 字节，总共 48418000 - 11 岁：876104 字节，总共 49294104 - 12 岁：2233720 字节，总共 51527824 - 13 岁：1218392 字节，总共 52746216 - 14 岁：903760 字节，总共 53649976 - 15 岁：1774480 字节，总共 55424456 , 0.0369978 秒] [并行时间：32.2 ms，GC Workers：8] [GC Worker Start (ms): Min: 48187087.1, Avg: 48187087.2, Max: 48187087.3, Diff: 0.2] [Ext Root Scanning (ms): Min: 4.4, Avg: 6.5, Max: 12.0, Diff: 7.7, Sum: 51.9] [更新 RS（毫秒）：最小值：4.0，平均值：8.5，最大值：9.6，差异：5.6，总和：68.3] [已处理的缓冲区：最小值：8，平均值：13.4，最大值：19，差异：11，总和：107] [扫描 RS (ms)：Min：0.1，Avg：0.2，Max：0.3，Diff：0.2，Sum：1.9] [代码根扫描（毫秒）：Min：0.0，Avg：0.0，Max：0.0，Diff：0.0，Sum：0.1] [对象复制（毫秒）：Min：15.4，Avg：16.6，Max：17.8，Diff：2.4，Sum：132.5] [终止（毫秒）：Min：0.0，Avg：0.0，Max：0.0，Diff：0.0，Sum：0.0] [终止尝试：Min：1，Avg：1.0，Max：1，Diff：0，Sum：8] [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 0.8] [GC Worker Total (ms): Min: 31.9, Avg: 31.9, Max: 32.0, Diff: 0.2, Sum: 255.6] [GC Worker End (ms): Min: 48187119.1, Avg: 48187119.2, Max: 48187119.3, Diff: 0.1] [代码根修复：0.4 毫秒] [代码根清除：0.0 ms] [清除 CT：0.7 毫秒] [其他：3.7 毫秒] [选择 CSet：0.0 毫秒] [参考过程：0.8 毫秒] [参考 Enq：0.0 毫秒] [Redirty 卡：0.2 毫秒] [巨大的寄存器：0.2毫秒] [巨大的回收：0.1毫秒] [免费 CSet：1.8 毫秒] [伊甸园：4508.0M(4508.0M)->0.0B(4516.0M) 幸存者：68.0M->64.0M 堆：7036.0M(10.0G)->2524.1M(10.0G)] [时间：用户=0.26 系统=0.00，真实=0.04 秒] 2017-03-02T12：27：09.078-0800：48187.638：[GC 暂停（G1 疏散暂停）（年轻） 所需的幸存者大小 301989888 字节，新阈值 15（最大 15） - 年龄 1：31144 字节，总共 31144 - 年龄 2：6631192 字节，总共 6662336 - 年龄 3：15225176 字节，总共 21887512 - 年龄 4：5530024 字节，总共 27417536 - 5 岁：5501976 字节，总共 32919512 - 6 岁：4490976 字节，总共 37410488 - 7 岁：1736456 字节，总共 39146944 - 8 岁：2849184 字节，总共 41996128 - 9 岁：2600504 字节，总共 44596632 - 10 岁：1793032 字节，总共 46389664 - 11 岁：1996752 字节，总共 48386416 - 12 岁：876104 字节，总共 49262520 - 13 岁：2233720 字节，总共 51496240 - 14 岁：1218392 字节，总共 52714632 - 15 岁：903760 字节，总共 53618392 , 0.0320568 秒] [并行时间：28.0 ms，GC Workers：8] [GC Worker Start (ms): Min: 48187638.4, Avg: 48187638.5, Max: 48187638.6, Diff: 0.2] [Ext Root Scanning (ms): Min: 3.8, Avg: 5.4, Max: 11.2, Diff: 7.4, Sum: 43.4] [更新 RS（毫秒）：最小值：2.4，平均值：7.4，最大值：8.7，差异：6.3，总和：59.2] [已处理的缓冲区：最小值：7，平均值：11.6，最大值：15，差异：8，总和：93] [扫描 RS (ms)：Min：0.2，Avg：0.2，Max：0.3，Diff：0.1，Sum：1.9] [代码根扫描（毫秒）：Min：0.0，Avg：0.0，Max：0.0，Diff：0.0，Sum：0.1] [对象复制（毫秒）：Min：13.6，Avg：14.6，Max：15.0，Diff：1.3，Sum：116.5] [终止（毫秒）：Min：0.0，Avg：0.0，Max：0.0，Diff：0.0，Sum：0.0] [终止尝试：最小：1，平均：1.9，最大：3，差异：2，总和：15] [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 0.8] [GC Worker Total (ms): Min: 27.6, Avg: 27.7, Max: 27.8, Diff: 0.3, Sum: 221.9] [GC Worker End (ms): Min: 48187666.2, Avg: 48187666.3, Max: 48187666.3, Diff: 0.1] [代码根修复：0.3 毫秒] [代码根清除：0.0 ms] [清除 CT：0.7 毫秒] [其他：3.0 毫秒] [选择 CSet：0.0 毫秒] [参考过程：0.5 毫秒] [参考 Enq：0.0 毫秒] [Redirty 卡：0.2 毫秒] [巨大的寄存器：0.2毫秒] [巨大的回收：0.1毫秒] [免费 CSet：1.6 毫秒] [伊甸园：4516.0M(4516.0M)->0.0B(4520.0M) 幸存者：64.0M->60.0M 堆：7040.1M(10.0G)->2521.7M(10.0G)] [时间：用户=0.23 系统=0.00，真实=0.03 秒] 2017-03-02T12：27：09.618-0800：48188.179：[GC 暂停（G1 疏散暂停）（年轻） 所需的幸存者大小 301989888 字节，新阈值 15（最大 15） - 年龄 1：47960 字节，总共 47960 - 年龄 2：26736 字节，总共 74696 - 年龄 3：6628208 字节，总共 6702904 - 年龄 4：15151304 字节，总共 21854208 - 5 岁：5530024 字节，总共 27384232 - 6 岁：5501976 字节，总共 32886208 - 7 岁：4490976 字节，总共 37377184 - 8 岁：1736456 字节，总共 39113640 - 9 岁：2849184 字节，总共 41962824 - 10 岁：2600504 字节，总共 44563328 - 11 岁：1792992 字节，总共 46356320 - 12 岁：1996752 字节，总共 48353072 - 13 岁：876104 字节，总共 49229176 - 14 岁：2233720 字节，总共 51462896 - 15 岁：1218392 字节，总共 52681288 , 0.0347669 秒] [并行时间：30.5 ms，GC Workers：8] [GC Worker Start (ms): Min: 48188179.0, Avg: 48188179.0, Max: 48188179.1, Diff: 0.1] [Ext Root Scanning (ms): Min: 4.0, Avg: 6.2, Max: 14.5, Diff: 10.5, Sum: 49.9] [更新 RS（毫秒）：最小值：0.7，平均值：8.2，最大值：10.1，差异：9.4，总和：65.9] [已处理的缓冲区：最小值：6，平均值：12.5，最大值：22，差异：16，总和：100] [扫描 RS (ms)：Min：0.1，Avg：0.2，Max：0.3，Diff：0.2，Sum：1.9] [代码根扫描（毫秒）：Min：0.0，Avg：0.0，Max：0.0，Diff：0.0，Sum：0.1] [对象复制（毫秒）：Min：14.4，Avg：15.4，Max：15.8，Diff：1.4，Sum：123.1] [终止（毫秒）：Min：0.0，Avg：0.0，Max：0.0，Diff：0.0，Sum：0.0] [终止尝试：最小：1，平均：1.6，最大：3，差异：2，总和：13] [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.9] [GC Worker Total (ms): Min: 30.2, Avg: 30.2, Max: 30.3, Diff: 0.1, Sum: 241.8] [GC Worker End (ms): Min: 48188209.2, Avg: 48188209.3, Max: 48188209.3, Diff: 0.2] [代码根修复：0.3 毫秒] [代码根清除：0.0 ms] [清除 CT：0.7 毫秒] [其他：3.3 毫秒] [选择 CSet：0.0 毫秒] [参考过程：0.6 毫秒] [参考 Enq：0.0 毫秒] [Redirty 卡：0.4 毫秒] [巨大的寄存器：0.2毫秒] [巨大的回收：0.1毫秒] [免费 CSet：1.5 毫秒] [伊甸园：4520.0M(4520.0M)->0.0B(4520.0M) 幸存者：60.0M->60.0M 堆：7041.7M(10.0G)->2525.3M(10.0G)] [时间：用户=0.24 系统=0.00，真实=0.03 秒] 2017-03-02T12：27：10.264-0800：48188.825：[GC 暂停（G1 疏散暂停）（年轻） 所需的幸存者大小 301989888 字节，新阈值 15（最大 15） - 年龄 1：48824 字节，总共 48824 - 年龄 2：18672 字节，总共 67496 - 年龄 3：17312 字节，总共 84808 - 年龄 4：6627608 字节，总共 6712416 - 5 岁：15149168 字节，总共 21861584 - 6 岁：5530024 字节，总共 27391608 - 7 岁：5501976 字节，总共 32893584 - 8 岁：4490848 字节，总共 37384432 - 9 岁：1736456 字节，总共 39120888 - 10 岁：2849184 字节，总共 41970072 - 11 岁：2600504 字节，总共 44570576 - 12 岁：1792992 字节，总共 46363568 - 13 岁：1996752 字节，总共 48360320 - 14 岁：876104 字节，总共 49236424 - 15 岁：2233720 字节，总共 51470144 , 0.0343310 秒] [并行时间：28.8 ms，GC Workers：8] [GC Worker Start (ms): Min: 48188825.2, Avg: 48188825.3, Max: 48188825.5, Diff: 0.3] [Ext Root Scanning (ms): Min: 3.9, Avg: 5.9, Max: 12.0, Diff: 8.1, Sum: 47.5] [更新 RS（毫秒）：最小值：2.9，平均值：8.0，最大值：9.3，差异：6.3，总和：63.6] [处理的缓冲区：最小值：8，平均值：11.8，最大值：21，差异：13，总和：94] [扫描 RS (ms)：Min：0.1，Avg：0.3，Max：0.4，Diff：0.3，Sum：2.3] [代码根扫描（毫秒）：Min：0.0，Avg：0.0，Max：0.1，Diff：0.0，Sum：0.1] [对象复制（毫秒）：Min：13.0，Avg：14.2，Max：14.9，Diff：1.9，Sum：113.3] [终止（毫秒）：Min：0.0，Avg：0.0，Max：0.0，Diff：0.0，Sum：0.0] [终止尝试：最小：1，平均：1.5，最大：2，差异：1，总和：12] [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 0.7] [GC Worker Total (ms): Min: 28.3, Avg: 28.4, Max: 28.6, Diff: 0.4, Sum: 227.5] [GC Worker End (ms): Min: 48188853.7, Avg: 48188853.8, Max: 48188853.8, Diff: 0.1] [代码根修复：0.4 毫秒] [代码根清除：0.0 ms] [清除 CT：0.6 毫秒] [其他：4.5 毫秒] [选择 CSet：0.0 毫秒] [参考过程：1.7 毫秒] [参考 Enq：0.1 毫秒] [Redirty 卡：0.3 毫秒] [巨大的寄存器：0.3毫秒] [巨大的回收：0.1毫秒] [免费 CSet：1.7 毫秒] [伊甸园：4520.0M(4520.0M)->0.0B(4524.0M) 幸存者：60.0M->56.0M 堆：7045.3M(10.0G)->2522.1M(10.0G)] [时间：用户=0.23 系统=0.00，真实=0.03 秒] 2017-03-02T12：27：10.866-0800：48189.426：[GC 暂停（G1 疏散暂停）（年轻） 所需的幸存者大小 301989888 字节，新阈值 15（最大 15） - 年龄 1：579088 字节，总共 579088 - 年龄 2：9904 字节，总共 588992 - 年龄 3：18376 字节，总共 607368 - 年龄 4：14720 字节，总共 622088 - 5 岁：6624344 字节，总共 7246432 - 6 岁：11726288 字节，总共 18972720 - 7 岁：5529984 字节，总共 24502704 - 8 岁：5492072 字节，总共 29994776 - 9 岁：4482976 字节，总共 34477752 - 10 岁：1736360 字节，总共 36214112 - 11 岁：2848368 字节，总计 39062480 - 12 岁：2600504 字节，总共 41662984 - 13 岁：1792992 字节，总共 43455976 - 14 岁：1996752 字节，总共 45452728 - 15 岁：876104 字节，总共 46328832 , 0.0350574 秒] [并行时间：29.2 ms，GC Workers：8] [GC Worker Start (ms): Min: 48189427.4, Avg: 48189427.5, Max: 48189427.6, Diff: 0.2] [Ext Root Scanning (ms): Min: 4.0, Avg: 5.8, Max: 11.5, Diff: 7.5, Sum: 46.0] [更新 RS (ms): Min: 3.3, Avg: 8.2, Max: 9.6, Diff: 6.3, Sum: 65.8] [处理的缓冲区：最小值：7，平均值：13.0，最大值：22，差异：15，总和：104] [扫描 RS (ms)：Min：0.1，Avg：0.2，Max：0.3，Diff：0.2，Sum：1.9] [代码根扫描（毫秒）：Min：0.0，Avg：0.0，Max：0.1，Diff：0.1，Sum：0.1] [对象复制（毫秒）：Min：13.2，Avg：14.4，Max：14.9，Diff：1.7，Sum：114.8] [终止（毫秒）：Min：0.0，Avg：0.3，Max：0.3，Diff：0.3，Sum：2.1] [终止尝试：最小：1，平均：3.8，最大：7，差异：6，总和：30] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.4] [GC Worker Total (ms): Min: 28.8, Avg: 28.9, Max: 29.0, Diff: 0.2, Sum: 231.1] [GC Worker End (ms): Min: 48189456.4, Avg: 48189456.4, Max: 48189456.4, Diff: 0.1] [代码根修复：0.3 毫秒] [代码根清除：0.0 ms] [清除 CT：0.7 毫秒] [其他：4.8 毫秒] [选择 CSet：0.0 毫秒] [参考过程：1.4 毫秒] [参考 Enq：0.2 毫秒] [Redirty 卡：0.3 毫秒] [巨大的寄存器：0.9毫秒] [巨大的回收：0.1毫秒] [免费 CSet：1.5 毫秒] [伊甸园：4524.0M(4524.0M)->0.0B(4524.0M) 幸存者：56.0M->56.0M 堆：7046.1M(10.0G)->2525.3M(10.0G)] [时间：用户=0.24 系统=0.00，真实=0.03 秒] 2017-03-02T12：27：11.515-0800：48190.075：[GC 暂停（G1 疏散暂停）（年轻） 所需的幸存者大小 301989888 字节，新阈值 15（最大 15） - 年龄 1：827320 字节，总共 827320 - 年龄 2：16496 字节，总共 843816 - 年龄 3：2352 字节，总共 846168 - 年龄 4：18176 字节，总共 864344 - 5 岁：14528 字节，总共 878872 - 6 岁：6577816 字节，总共 7456688 - 7 岁：11698856 字节，总共 19155544 - 8 岁：5520560 字节，总共 24676104 - 9 岁：5492032 字节，总共 30168136 - 10 岁：4482976 字节，总共 34651112 - 11 岁：1736360 字节，总共 36387472 - 12 岁：2848368 字节，总共 39235840 - 13 岁：2600504 字节，总共 41836344 - 14 岁：1792992 字节，总共 43629336 - 15 岁：1996752 字节，总共 45626088 , 0.0353327 秒] [并行时间：28.5 ms，GC Workers：8] [GC Worker Start (ms): Min: 48190075.8, Avg: 48190075.9, Max: 48190076.1, Diff: 0.3] [Ext Root Scanning (ms): Min: 3.3, Avg: 6.0, Max: 11.7, Diff: 8.4, Sum: 47.7] [更新 RS（毫秒）：最小值：3.1，平均值：7.5，最大值：8.7，差异：5.6，总和：60.4] [处理的缓冲区：最小值：6，平均值：13.0，最大值：23，差异：17，总和：104] [扫描 RS (ms)：Min：0.1，Avg：0.2，Max：0.3，Diff：0.2，Sum：1.9] [代码根扫描（毫秒）：Min：0.0，Avg：0.0，Max：0.0，Diff：0.0，Sum：0.1] [对象复制（毫秒）：Min：12.8，Avg：14.0，Max：14.7，Diff：1.9，Sum：111.8] [终止（毫秒）：Min：0.0，Avg：0.0，Max：0.0，Diff：0.0，Sum：0.0] [终止尝试：最小：1，平均：1.4，最大：2，差异：1，总和：11] [GC Worker Other (ms): Min: 0.0, Avg: 0.4, Max: 2.1, Diff: 2.1, Sum: 2.9] [GC Worker Total (ms): Min: 28.0, Avg: 28.1, Max: 28.2, Diff: 0.3, Sum: 224.8] [GC Worker End (ms): Min: 48190103.9, Avg: 48190104.0, Max: 48190104.1, Diff: 0.2] [代码根修复：0.4 毫秒] [代码根清除：0.0 ms] [清除 CT：0.7 毫秒] [其他：5.7 毫秒] [选择 CSet：0.0 毫秒] [参考过程：2.6 毫秒] [参考 Enq：0.0 毫秒] [Redirty 卡：0.3 毫秒] [巨大的寄存器：0.2毫秒] [巨大的回收：0.1毫秒] [免费 CSet：1.9 毫秒] [伊甸园：4524.0M(4524.0M)->0.0B(4512.0M) 幸存者：56.0M->60.0M 堆：7049.3M(10.0G)->2529.7M(10.0G)] [时间：用户=0.23 系统=0.00，真实=0.04 秒]

Answer 1

他们似乎正在清理伊甸园的记忆，但我不明白为什么它会这么快填满。

您已经确定了从您提供的日志中可以识别的所有内容。由于您的应用程序分配了对象，因此一代被填满。哪些对象？您必须使用分配分析器来识别它。

收集模式看起来不错，但随后将在几秒钟内连续执行超过 10 次 G1 疏散收集（年轻）。

但似乎并没有特别过分。它每秒在 GC 上花费 30-80 毫秒来清理千兆字节的内存。这仍然是 92% 的最低 mutator 利用率。

也许您的应用程序只是突发性的？