<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=iso-2022-jp">
<style type="text/css" style="display:none;"><!-- P {margin-top:0;margin-bottom:0;} --></style>
</head>
<body dir="ltr">
<div id="divtagdefaultwrapper" style="font-size:12pt;color:#000000;font-family:Calibri,Helvetica,sans-serif;" dir="ltr">
<p></p>
<div>Hi,<br>
<br>
We have seen issues with G1 in several internal applications after upgrading from JDK17 to JDK21. We monitor heap occupancy after each collection cycle, and we saw spikes in occupancy after the upgrade. I believe this comes with some performance impact due
to more mixed collections and more evacuation failures. I haven$B!G(Bt fully understood the issue yet, but I think I have enough info to share something useful and would appreciate any insight. Note that I also created JDK-8355972 which is related but I think this
case is more interesting.<br>
<br>
The typical presentation is:<br>
<br>
```<br>
[T12:09:06.485] GC(12062) Pause Cleanup 948M$B"*(B948M(2048M) 0.603ms<br>
[T12:10:10.533] GC(12063) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 1614M$B"*(B963M(2048M) 6.027ms<br>
[T12:11:15.090] GC(12064) Pause Young (Mixed) (G1 Evacuation Pause) (Evacuation Failure) 2047M$B"*(B1510M(2048M) 17.484ms<br>
[T12:12:19.429] GC(12065) Pause Young (Mixed) (G1 Evacuation Pause) (Evacuation Failure) 2048M$B"*(B1824M(2048M) 17.754ms<br>
[T12:12:19.442] GC(12066) Pause Young (Mixed) (G1 Evacuation Pause) 1954M$B"*(B1724M(2048M) 2.315ms<br>
[T12:12:19.449] GC(12067) Pause Young (Concurrent Start) (G1 Humongous Allocation) 1753M$B"*(B1723M(2048M) 2.558ms<br>
[T12:12:19.490] GC(12068) Pause Remark 1894M$B"*(B776M(2048M) 2.824ms<br>
[T12:12:19.506] GC(12068) Pause Cleanup 806M$B"*(B806M(2048M) 0.538ms<br>
[T12:12:19.589] GC(12069) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 862M$B"*(B616M(2048M) 2.500ms<br>
```<br>
<br>
We have a long gap between prepare mixed and mixed collections, during which time the heap is completely filled. Mixed collections are relatively ineffective, and we need a concurrent cycle to reduce occupancy significantly. This cycle repeats. On JDK17, this
application never saw mixed collections, but on JDK21 they$B!G(Bre dominant. All cases so far have significant humongous allocations. I created a reproducer which exhibits the same pattern including the change between 17 and 21. With the reproducer, JDK17 performs
no mixed collections at all, where JDK21 runs them repeatedly. The behaviour changes significantly after JDK-8253413 which allows eden to grow much larger - before this we would reach a stable pattern with no mixed collections, after this change we never stop
doing mixed collections. My guess is that the large eden plays poorly with humongous allocations in this case - it extends the time between the prepare mixed and the mixed collection, during which time humongous allocations pile up. When eden eventually fills,
we$B!G(Bre in a bad state - large amounts of humongous, presumed live, objects and no free space for evacuation.<br>
<br>
Reproducer:<br>
```<br>
// java -Xlog:gc -Xms100M -Xmx100M -XX:+UnlockDiagnosticVMOptions -XX:-G1UsePreventiveGC MixedGcHumongous.java<br>
public class MixedGcHumongous {<br>
public static void main(String[] args) throws Exception {<br>
System.gc(); // start from stable state<br>
for (int i = 0; i < 1000; i++) {<br>
Integer[] humongous = new Integer[200_000]; Thread.sleep(10); // ~0.8MB (humongous)<br>
allocateTempNormal(20_000); Thread.sleep(10); // 40 bytes per entry = ~2MB<br>
}<br>
}<br>
static void allocateTempNormal(int count) throws Exception {<br>
java.util.LinkedList<Integer> temp = new java.util.LinkedList<>();<br>
for (int j = 0; j < count; j++) temp.add(j);<br>
}<br>
}<br>
```<br>
<br>
JDK17<br>
```<br>
[1.130s][info][gc] GC(1) Pause Young (Normal) (G1 Evacuation Pause) 57M$B"*(B34M(100M) 0.864ms<br>
[1.307s][info][gc] GC(2) Pause Young (Concurrent Start) (G1 Humongous Allocation) 49M$B"*(B42M(100M) 0.627ms<br>
[1.328s][info][gc] GC(4) Pause Young (Concurrent Start) (G1 Humongous Allocation) 44M$B"*(B43M(100M) 0.360ms<br>
[1.333s][info][gc] GC(5) Pause Remark 44M$B"*(B4M(100M) 1.115ms<br>
[1.334s][info][gc] GC(5) Pause Cleanup 4M$B"*(B4M(100M) 0.035ms<br>
[2.130s][info][gc] GC(6) Pause Young (Concurrent Start) (G1 Humongous Allocation) 72M$B"*(B42M(100M) 0.529ms<br>
[2.151s][info][gc] GC(8) Pause Young (Concurrent Start) (G1 Humongous Allocation) 44M$B"*(B43M(100M) 0.439ms<br>
[2.155s][info][gc] GC(9) Pause Remark 44M$B"*(B4M(100M) 1.098ms<br>
[2.156s][info][gc] GC(9) Pause Cleanup 4M$B"*(B4M(100M) 0.035ms<br>
...<br>
```<br>
<br>
JDK21<br>
```<br>
[1.410s][info][gc] GC(2) Pause Young (Concurrent Start) (G1 Humongous Allocation) 76M$B"*(B45M(100M) 0.702ms<br>
[1.432s][info][gc] GC(4) Pause Young (Concurrent Start) (G1 Humongous Allocation) 47M$B"*(B45M(100M) 0.488ms<br>
[1.437s][info][gc] GC(5) Pause Remark 46M$B"*(B4M(100M) 1.584ms<br>
[1.438s][info][gc] GC(5) Pause Cleanup 4M$B"*(B4M(100M) 0.034ms<br>
[2.537s][info][gc] GC(6) Pause Young (Prepare Mixed) (G1 Evacuation Pause) (Evacuation Failure) 98M$B"*(B58M(100M) 2.300ms<br>
[3.009s][info][gc] GC(7) Pause Young (Mixed) (G1 Evacuation Pause) (Evacuation Failure) 98M$B"*(B83M(100M) 1.943ms<br>
[3.026s][info][gc] GC(8) Pause Young (Concurrent Start) (G1 Humongous Allocation) 84M$B"*(B84M(100M) 6.328ms<br>
[3.031s][info][gc] GC(9) Pause Remark 85M$B"*(B6M(100M) 1.316ms<br>
[3.032s][info][gc] GC(9) Pause Cleanup 6M$B"*(B6M(100M) 0.039ms<br>
... mixed collections continue<br>
```<br>
<br>
JDK20 commit 27b0f7726b7, before JDK-8253413<br>
```<br>
[1.338s][info][gc] GC(2) Pause Young (Concurrent Start) (G1 Humongous Allocation) 73M$B"*(B43M(100M) 0.798ms<br>
[1.360s][info][gc] GC(4) Pause Young (Concurrent Start) (G1 Humongous Allocation) 45M$B"*(B43M(100M) 0.472ms<br>
[1.363s][info][gc] GC(5) Pause Remark 44M$B"*(B4M(100M) 1.146ms<br>
[1.365s][info][gc] GC(5) Pause Cleanup 4M$B"*(B4M(100M) 0.048ms<br>
[2.297s][info][gc] GC(6) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 84M$B"*(B50M(100M) 2.315ms<br>
[2.423s][info][gc] GC(7) Pause Young (Mixed) (G1 Evacuation Pause) 60M$B"*(B55M(100M) 0.876ms<br>
[2.433s][info][gc] GC(8) Pause Young (Concurrent Start) (G1 Humongous Allocation) 56M$B"*(B55M(100M) 0.480ms<br>
[2.437s][info][gc] GC(9) Pause Remark 56M$B"*(B4M(100M) 1.123ms<br>
[2.438s][info][gc] GC(9) Pause Cleanup 4M$B"*(B4M(100M) 0.036ms<br>
[3.161s][info][gc] GC(10) Pause Young (Prepare Mixed) (G1 Evacuation Pause) 66M$B"*(B39M(100M) 1.064ms<br>
[3.265s][info][gc] GC(11) Pause Young (Mixed) (G1 Evacuation Pause) 48M$B"*(B45M(100M) 2.403ms<br>
[3.276s][info][gc] GC(12) Pause Young (Concurrent Start) (G1 Humongous Allocation) 45M$B"*(B44M(100M) 0.418ms<br>
[3.279s][info][gc] GC(13) Pause Remark 45M$B"*(B4M(100M) 1.121ms<br>
[3.280s][info][gc] GC(13) Pause Cleanup 4M$B"*(B4M(100M) 0.038ms<br>
[4.093s][info][gc] GC(14) Pause Young (Concurrent Start) (G1 Humongous Allocation) 74M$B"*(B43M(100M) 0.545ms<br>
[4.114s][info][gc] GC(16) Pause Young (Concurrent Start) (G1 Humongous Allocation) 45M$B"*(B44M(100M) 0.428ms<br>
[4.118s][info][gc] GC(17) Pause Remark 45M$B"*(B4M(100M) 1.141ms<br>
[4.119s][info][gc] GC(17) Pause Cleanup 4M->4M(100M) 0.028ms<br>
... no further mixed collections, settles similarly to JDK17<br>
```<br>
<br>
The symptoms (at least in my reproducer) are fixed again by JDK-8140326 in JDK22, but I$B!G(Bm not sure if that fully addresses the issue or just avoids some of the symptoms in this case.<br>
<br>
I$B!G(Bd appreciate any thoughts on this issue, do you think it is a meaningful regression in JDK21 that should be addressed, or we were just lucky before that we avoided slipping into this pattern? Does JDK-8140326 address the issue or is there more to it?<br>
<br>
Thanks!<br>
<br>
Oliver<br>
</div>
<p></p>
</div>
<br><br><br>Amazon Development Centre (London) Ltd.Registered in England and Wales with registration number 04543232 with its registered office at 1 Principal Place, Worship Street, London EC2A 2FA, United Kingdom.<br><br><br>
</body>
</html>