为什么在达到 InitiatingHeapOccupancyPercent 时 G1 不开始标记周期？
Why doesn't G1 start a marking cycle when the InitiatingHeapOccupancyPercent is achieved?
根据 documentation、XX:InitiatingHeapOccupancyPercent
Sets the Java heap occupancy threshold that triggers a marking cycle.
The default occupancy is 45 percent of the entire Java heap.
在我当前的环境中，不会发生这种情况。
我的G1垃圾回收配置如下
-Xms25000m
-Xmx25000m
-XX:+UseG1GC
-XX:MaxGCPauseMillis=1000
-XX:GCTimeRatio=99
-XX:InitiatingHeapOccupancyPercent=70
-XX:MaxTenuringThreshold=8
-XX:+UnlockExperimentalVMOptions
-XX:G1MixedGCCountTarget=16
-XX:G1OldCSetRegionThresholdPercent=3
-XX:G1NewSizePercent=30
-XX:G1RSetUpdatingPauseTimePercent=5
对于 25g 堆和 70% 的 XX:InitiatingHeapOccupancyPercent，您会期望标记周期在 18g 被占用时开始。我正在跟踪垃圾收集日志，但这并没有发生。
摘录如下：
{Heap before GC invocations=592 (full 0):
garbage-first heap total 25600000K, used 22802164K [0x00000001a5800000, 0x00000001a60061a8, 0x00000007c0000000)
region size 8192K, 1526 young (12500992K), 25 survivors (204800K)
Metaspace used 37386K, capacity 37948K, committed 38144K, reserved 1083392K
class space used 3948K, capacity 4080K, committed 4096K, reserved 1048576K
2016-04-20T22:06:38.272+0000: 4213.406: [GC pause (GCLocker Initiated GC) (young)
Desired survivor size 801112064 bytes, new threshold 8 (max 8)
- age 1: 98537800 bytes, 98537800 total
- age 2: 7053912 bytes, 105591712 total
- age 3: 6556320 bytes, 112148032 total
- age 4: 8836064 bytes, 120984096 total
- age 5: 5725448 bytes, 126709544 total
- age 6: 6702728 bytes, 133412272 total
- age 7: 3831920 bytes, 137244192 total
- age 8: 4166336 bytes, 141410528 total
4213.406: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 184844, predicted base time: 44.67 ms, remaining time: 955.33 ms, target pause time: 1000.00 ms]
4213.406: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 1501 regions, survivors: 25 regions, predicted young region time: 21.21 ms]
4213.406: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 1501 regions, survivors: 25 regions, old: 0 regions, predicted pause time: 65.88 ms, target pause time: 1000.00 ms]
4213.475: [G1Ergonomics (Heap Sizing) attempt heap expansion, reason: recent GC overhead higher than threshold after GC, recent GC overhead: 1.40 %, threshold: 1.00 %, uncommitted: 0 bytes, calculated expansion amount: 0 bytes (20.00 %)]
, 0.0687163 secs]
[Parallel Time: 61.7 ms, GC Workers: 28]
[GC Worker Start (ms): Min: 4213406.9, Avg: 4213407.1, Max: 4213407.3, Diff: 0.4]
[Ext Root Scanning (ms): Min: 6.0, Avg: 6.2, Max: 6.4, Diff: 0.4, Sum: 173.1]
[Update RS (ms): Min: 33.5, Avg: 34.0, Max: 34.6, Diff: 1.1, Sum: 951.9]
[Processed Buffers: Min: 27, Avg: 36.6, Max: 48, Diff: 21, Sum: 1024]
[Scan RS (ms): Min: 0.1, Avg: 0.2, Max: 0.5, Diff: 0.4, Sum: 6.3]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
[Object Copy (ms): Min: 20.1, Avg: 20.6, Max: 20.8, Diff: 0.7, Sum: 577.5]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.7]
[Termination Attempts: Min: 1, Avg: 13.2, Max: 19, Diff: 18, Sum: 371]
[GC Worker Other (ms): Min: 0.0, Avg: 0.2, Max: 0.4, Diff: 0.3, Sum: 4.7]
[GC Worker Total (ms): Min: 60.9, Avg: 61.2, Max: 61.6, Diff: 0.6, Sum: 1714.2]
[GC Worker End (ms): Min: 4213468.2, Avg: 4213468.3, Max: 4213468.5, Diff: 0.3]
[Code Root Fixup: 0.4 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 1.2 ms]
[Other: 5.4 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.5 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.8 ms]
[Humongous Register: 0.2 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 2.4 ms]
[Eden: 11.7G(11.7G)->0.0B(11.7G) Survivors: 200.0M->200.0M Heap: 21.7G(24.4G)->10.0G(24.4G)]
Heap after GC invocations=593 (full 0):
garbage-first heap total 25600000K, used 10516798K [0x00000001a5800000, 0x00000001a60061a8, 0x00000007c0000000)
region size 8192K, 25 young (204800K), 25 survivors (204800K)
Metaspace used 37386K, capacity 37948K, committed 38144K, reserved 1083392K
class space used 3948K, capacity 4080K, committed 4096K, reserved 1048576K
}
[Times: user=1.70 sys=0.01, real=0.07 secs]
2016-04-20T22:06:38.342+0000: 4213.475: Total time for which application threads were stopped: 0.0701353 seconds, Stopping threads took: 0.0001600 seconds
我会提请你注意
{Heap before GC invocations=592 (full 0):
garbage-first heap total 25600000K, used 22802164K [0x00000001a5800000, 0x00000001a60061a8, 0x00000007c0000000)
[...]
[Eden: 11.7G(11.7G)->0.0B(11.7G) Survivors: 200.0M->200.0M Heap: 21.7G(24.4G)->10.0G(24.4G)]
在此回收之前，超过 70% 的堆已被占用。为什么那没有触发标记周期？
应用程序继续进行新生代收集，填满旧区域，最终导致分配失败和冗长的 Full GC。
将 InitiatingHeapOccupancyPercent 减少到 55 没有明显的效果。
在 20 岁时，它确实开始进行混合收集，但只有在 ~80% 的堆被占用时才开始。
JDK-6976060 表明标记周期的需要是在新生代GC结束时计算的。根据它是在年轻 GC 之前还是之后使用占用率统计信息，这可能意味着也可能不意味着出于 IHOP 计算的目的，eden space 始终被视为 0% 占用。 45% 的伊甸园大小意味着永远无法达到 70% 的占用率，最大可能的占用率将是 55%，此时堆将完全满，混合收集为时已晚。
但我怀疑这是否真的如此，因为面对动态的年轻代大小调整，这会使文档产生误导和 IHOP 调整变得更加困难。使用人工测试用例和手动调整生成大小来验证这一点应该相当容易。
如果这不是问题，那么 GC pause (GCLocker Initiated GC) (young) 可能指向 bug 8140597，它已在 jdk9b94 中修复。
更新：Bug 8151176 中的描述确实表明，出于 IHO 百分比计算的目的，它计算了旧代 occupancy/overall 堆大小。这意味着年轻一代的占用率被完全忽略，这反过来意味着如果年轻一代的比例 > IHOP 那么它永远不会启动并发周期。
The reason is that static IHOP starts if old gen occupancy exceeds a fixed percentage of the current heap capacity. If either the user or ergonomics decide that the old gen can not be larger than that fraction of the heap capacity that triggers concurrent mark, marking will never start.
所以目前可用的解决方案是
- 约束年轻一代分数 < IHOP
- 降低 IHOP 以考虑最小可能的老一代分数
- 让JVM动态调整IHOP
更新 2：该错误上的 latest comment 表明该问题已修复一段时间，因此该答案应被视为历史性答案。
根据 documentation、XX:InitiatingHeapOccupancyPercent
Sets the Java heap occupancy threshold that triggers a marking cycle. The default occupancy is 45 percent of the entire Java heap.
在我当前的环境中，不会发生这种情况。
我的G1垃圾回收配置如下
-Xms25000m
-Xmx25000m
-XX:+UseG1GC
-XX:MaxGCPauseMillis=1000
-XX:GCTimeRatio=99
-XX:InitiatingHeapOccupancyPercent=70
-XX:MaxTenuringThreshold=8
-XX:+UnlockExperimentalVMOptions
-XX:G1MixedGCCountTarget=16
-XX:G1OldCSetRegionThresholdPercent=3
-XX:G1NewSizePercent=30
-XX:G1RSetUpdatingPauseTimePercent=5
对于 25g 堆和 70% 的 XX:InitiatingHeapOccupancyPercent，您会期望标记周期在 18g 被占用时开始。我正在跟踪垃圾收集日志，但这并没有发生。
摘录如下：
{Heap before GC invocations=592 (full 0):
garbage-first heap total 25600000K, used 22802164K [0x00000001a5800000, 0x00000001a60061a8, 0x00000007c0000000)
region size 8192K, 1526 young (12500992K), 25 survivors (204800K)
Metaspace used 37386K, capacity 37948K, committed 38144K, reserved 1083392K
class space used 3948K, capacity 4080K, committed 4096K, reserved 1048576K
2016-04-20T22:06:38.272+0000: 4213.406: [GC pause (GCLocker Initiated GC) (young)
Desired survivor size 801112064 bytes, new threshold 8 (max 8)
- age 1: 98537800 bytes, 98537800 total
- age 2: 7053912 bytes, 105591712 total
- age 3: 6556320 bytes, 112148032 total
- age 4: 8836064 bytes, 120984096 total
- age 5: 5725448 bytes, 126709544 total
- age 6: 6702728 bytes, 133412272 total
- age 7: 3831920 bytes, 137244192 total
- age 8: 4166336 bytes, 141410528 total
4213.406: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 184844, predicted base time: 44.67 ms, remaining time: 955.33 ms, target pause time: 1000.00 ms]
4213.406: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 1501 regions, survivors: 25 regions, predicted young region time: 21.21 ms]
4213.406: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 1501 regions, survivors: 25 regions, old: 0 regions, predicted pause time: 65.88 ms, target pause time: 1000.00 ms]
4213.475: [G1Ergonomics (Heap Sizing) attempt heap expansion, reason: recent GC overhead higher than threshold after GC, recent GC overhead: 1.40 %, threshold: 1.00 %, uncommitted: 0 bytes, calculated expansion amount: 0 bytes (20.00 %)]
, 0.0687163 secs]
[Parallel Time: 61.7 ms, GC Workers: 28]
[GC Worker Start (ms): Min: 4213406.9, Avg: 4213407.1, Max: 4213407.3, Diff: 0.4]
[Ext Root Scanning (ms): Min: 6.0, Avg: 6.2, Max: 6.4, Diff: 0.4, Sum: 173.1]
[Update RS (ms): Min: 33.5, Avg: 34.0, Max: 34.6, Diff: 1.1, Sum: 951.9]
[Processed Buffers: Min: 27, Avg: 36.6, Max: 48, Diff: 21, Sum: 1024]
[Scan RS (ms): Min: 0.1, Avg: 0.2, Max: 0.5, Diff: 0.4, Sum: 6.3]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
[Object Copy (ms): Min: 20.1, Avg: 20.6, Max: 20.8, Diff: 0.7, Sum: 577.5]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.7]
[Termination Attempts: Min: 1, Avg: 13.2, Max: 19, Diff: 18, Sum: 371]
[GC Worker Other (ms): Min: 0.0, Avg: 0.2, Max: 0.4, Diff: 0.3, Sum: 4.7]
[GC Worker Total (ms): Min: 60.9, Avg: 61.2, Max: 61.6, Diff: 0.6, Sum: 1714.2]
[GC Worker End (ms): Min: 4213468.2, Avg: 4213468.3, Max: 4213468.5, Diff: 0.3]
[Code Root Fixup: 0.4 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 1.2 ms]
[Other: 5.4 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.5 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.8 ms]
[Humongous Register: 0.2 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 2.4 ms]
[Eden: 11.7G(11.7G)->0.0B(11.7G) Survivors: 200.0M->200.0M Heap: 21.7G(24.4G)->10.0G(24.4G)]
Heap after GC invocations=593 (full 0):
garbage-first heap total 25600000K, used 10516798K [0x00000001a5800000, 0x00000001a60061a8, 0x00000007c0000000)
region size 8192K, 25 young (204800K), 25 survivors (204800K)
Metaspace used 37386K, capacity 37948K, committed 38144K, reserved 1083392K
class space used 3948K, capacity 4080K, committed 4096K, reserved 1048576K
}
[Times: user=1.70 sys=0.01, real=0.07 secs]
2016-04-20T22:06:38.342+0000: 4213.475: Total time for which application threads were stopped: 0.0701353 seconds, Stopping threads took: 0.0001600 seconds
我会提请你注意
{Heap before GC invocations=592 (full 0):
garbage-first heap total 25600000K, used 22802164K [0x00000001a5800000, 0x00000001a60061a8, 0x00000007c0000000)
[...]
[Eden: 11.7G(11.7G)->0.0B(11.7G) Survivors: 200.0M->200.0M Heap: 21.7G(24.4G)->10.0G(24.4G)]
在此回收之前，超过 70% 的堆已被占用。为什么那没有触发标记周期？
应用程序继续进行新生代收集，填满旧区域，最终导致分配失败和冗长的 Full GC。
将 InitiatingHeapOccupancyPercent 减少到 55 没有明显的效果。
在 20 岁时，它确实开始进行混合收集，但只有在 ~80% 的堆被占用时才开始。
JDK-6976060 表明标记周期的需要是在新生代GC结束时计算的。根据它是在年轻 GC 之前还是之后使用占用率统计信息，这可能意味着也可能不意味着出于 IHOP 计算的目的，eden space 始终被视为 0% 占用。 45% 的伊甸园大小意味着永远无法达到 70% 的占用率，最大可能的占用率将是 55%，此时堆将完全满，混合收集为时已晚。
但我怀疑这是否真的如此，因为面对动态的年轻代大小调整，这会使文档产生误导和 IHOP 调整变得更加困难。使用人工测试用例和手动调整生成大小来验证这一点应该相当容易。
如果这不是问题，那么 GC pause (GCLocker Initiated GC) (young) 可能指向 bug 8140597，它已在 jdk9b94 中修复。
更新：Bug 8151176 中的描述确实表明，出于 IHO 百分比计算的目的，它计算了旧代 occupancy/overall 堆大小。这意味着年轻一代的占用率被完全忽略，这反过来意味着如果年轻一代的比例 > IHOP 那么它永远不会启动并发周期。
The reason is that static IHOP starts if old gen occupancy exceeds a fixed percentage of the current heap capacity. If either the user or ergonomics decide that the old gen can not be larger than that fraction of the heap capacity that triggers concurrent mark, marking will never start.
所以目前可用的解决方案是
- 约束年轻一代分数 < IHOP
- 降低 IHOP 以考虑最小可能的老一代分数
- 让JVM动态调整IHOP
更新 2：该错误上的 latest comment 表明该问题已修复一段时间，因此该答案应被视为历史性答案。