High CPU usage when shifting from Java 8 to Java 11 with G1GC

Question

We are having following VM settings for our server. This configuration works perfectly when running Java 8. But when we switch JVM to Java 11 OpenJDK, the server stop responding due to CPU usage collapse. Is there anything we need to setup regarding Java11 G1 args that is essential on Java 11 environment?

# G1 GC
-XX:+UseG1GC
-XX:+DisableExplicitGC
-XX:+ParallelRefProcEnabled

# Shenandoah GC
#-XX:+UseShenandoahGC

-Xmx22g
-Xms22g
-Xss256k

-XX:-OmitStackTraceInFastThrow
-XX:-LoopUnswitching

-XX:+PrintFlagsFinal

Posting gc.log.

On Java 8 (Normal behaviour):

2022-05-09T14:17:40.705+0200: 445817.099: Total time for which application threads were stopped: 0.0738060 seconds, Stopping threads took: 0.0006159 seconds
{Heap before GC invocations=24877 (full 0):
 garbage-first heap   total 23068672K, used 20592926K [0x0000000240000000, 0x0000000240805800, 0x00000007c0000000)
  region size 8192K, 1629 young (13344768K), 4 survivors (32768K)
 Metaspace       used 80739K, capacity 84679K, committed 85808K, reserved 1126400K
  class space    used 8821K, capacity 9496K, committed 9776K, reserved 1048576K
2022-05-09T14:17:56.077+0200: 445832.471: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 855638016 bytes, new threshold 15 (max 15)
- age   1:    2676696 bytes,    2676696 total
- age   2:    1049760 bytes,    3726456 total
- age   3:     965160 bytes,    4691616 total
- age   4:    1030856 bytes,    5722472 total
- age   5:    1077872 bytes,    6800344 total
- age   6:     942896 bytes,    7743240 total
- age   7:    1048488 bytes,    8791728 total
- age   8:     947104 bytes,    9738832 total
- age   9:    1052488 bytes,   10791320 total
- age  10:     916376 bytes,   11707696 total
- age  11:    1015048 bytes,   12722744 total
- age  12:     921096 bytes,   13643840 total
- age  13:    1031928 bytes,   14675768 total
- age  14:    1021640 bytes,   15697408 total
- age  15:     475776 bytes,   16173184 total
Heap after GC invocations=24878 (full 0):
 garbage-first heap   total 23068672K, used 7274381K [0x0000000240000000, 0x0000000240805800, 0x00000007c0000000)
  region size 8192K, 3 young (24576K), 3 survivors (24576K)
 Metaspace       used 80739K, capacity 84679K, committed 85808K, reserved 1126400K
  class space    used 8821K, capacity 9496K, committed 9776K, reserved 1048576K
}
 [Times: user=0.67 sys=0.00, real=0.07 secs]

Java 11 (problematic):

[2022-05-09T14:41:40.411+0200][2997.918s][debug][gc,heap       ] GC(39) Heap before GC invocations=39 (full 0): garbage-first heap   total 23068672K, used 14412202K [0x0000000280000000, 0x0000000800000000)
[2022-05-09T14:41:40.411+0200][2997.918s][debug][gc,heap       ] GC(39)   region size 8192K, 1138 young (9322496K), 25 survivors (204800K)
[2022-05-09T14:41:40.411+0200][2997.918s][debug][gc,heap       ] GC(39)  Metaspace       used 80640K, capacity 82691K, committed 82992K, reserved 1122304K
[2022-05-09T14:41:40.411+0200][2997.918s][debug][gc,heap       ] GC(39)   class space    used 8493K, capacity 9282K, committed 9344K, reserved 1048576K
[2022-05-09T14:41:40.412+0200][2997.918s][info ][gc,start      ] GC(39) Pause Young (Normal) (G1 Evacuation Pause)
[2022-05-09T14:41:40.412+0200][2997.918s][info ][gc,task       ] GC(39) Using 23 workers of 23 for evacuation
[2022-05-09T14:41:40.412+0200][2997.918s][debug][gc,age        ] GC(39) Desired survivor size 599785472 bytes, new threshold 15 (max threshold 15)
[2022-05-09T14:41:40.462+0200][2997.969s][trace][gc,age        ] GC(39) Age table with threshold 15 (max threshold 15)
[2022-05-09T14:41:40.462+0200][2997.969s][trace][gc,age        ] GC(39) - age   1:   48083760 bytes,   48083760 total
[2022-05-09T14:41:40.462+0200][2997.969s][trace][gc,age        ] GC(39) - age   2:    1923768 bytes,   50007528 total
[2022-05-09T14:41:40.462+0200][2997.969s][trace][gc,age        ] GC(39) - age   3:    1885432 bytes,   51892960 total
[2022-05-09T14:41:40.462+0200][2997.969s][trace][gc,age        ] GC(39) - age   4:    2276496 bytes,   54169456 total
[2022-05-09T14:41:40.462+0200][2997.969s][trace][gc,age        ] GC(39) - age   5:    3542976 bytes,   57712432 total
[2022-05-09T14:41:40.462+0200][2997.969s][trace][gc,age        ] GC(39) - age   6:    3618312 bytes,   61330744 total
[2022-05-09T14:41:40.462+0200][2997.969s][trace][gc,age        ] GC(39) - age   7:    3050352 bytes,   64381096 total
[2022-05-09T14:41:40.462+0200][2997.969s][trace][gc,age        ] GC(39) - age   8:    2058992 bytes,   66440088 total
[2022-05-09T14:41:40.463+0200][2997.970s][info ][gc,phases     ] GC(39)   Pre Evacuate Collection Set: 0.1ms
[2022-05-09T14:41:40.463+0200][2997.970s][info ][gc,phases     ] GC(39)   Evacuate Collection Set: 48.1ms
[2022-05-09T14:41:40.463+0200][2997.970s][info ][gc,phases     ] GC(39)   Post Evacuate Collection Set: 2.2ms
[2022-05-09T14:41:40.463+0200][2997.970s][info ][gc,phases     ] GC(39)   Other: 1.5ms
[2022-05-09T14:41:40.463+0200][2997.970s][info ][gc,heap       ] GC(39) Eden regions: 1113->0(1444)
[2022-05-09T14:41:40.463+0200][2997.970s][trace][gc,heap       ] GC(39)  Used: 0K, Waste: 0K
[2022-05-09T14:41:40.463+0200][2997.970s][info ][gc,heap       ] GC(39) Survivor regions: 25->11(143)
[2022-05-09T14:41:40.463+0200][2997.970s][trace][gc,heap       ] GC(39)  Used: 86937K, Waste: 3174K
[2022-05-09T14:41:40.463+0200][2997.970s][info ][gc,heap       ] GC(39) Old regions: 576->576
[2022-05-09T14:41:40.463+0200][2997.970s][trace][gc,heap       ] GC(39)  Used: 4716743K, Waste: 1848K
[2022-05-09T14:41:40.463+0200][2997.970s][info ][gc,heap       ] GC(39) Humongous regions: 47->47
[2022-05-09T14:41:40.463+0200][2997.970s][trace][gc,heap       ] GC(39)  Used: 385024K, Waste: 0K
[2022-05-09T14:41:40.463+0200][2997.970s][info ][gc,metaspace  ] GC(39) Metaspace: 80640K->80640K(1122304K)
[2022-05-09T14:41:40.463+0200][2997.970s][debug][gc,heap       ] GC(39) Heap after GC invocations=40 (full 0): garbage-first heap   total 23068672K, used 5188704K [0x0000000280000000, 0x0000000800000000)
[2022-05-09T14:41:40.463+0200][2997.970s][debug][gc,heap       ] GC(39)   region size 8192K, 11 young (90112K), 11 survivors (90112K)
[2022-05-09T14:41:40.463+0200][2997.970s][debug][gc,heap       ] GC(39)  Metaspace       used 80640K, capacity 82691K, committed 82992K, reserved 1122304K
[2022-05-09T14:41:40.463+0200][2997.970s][debug][gc,heap       ] GC(39)   class space    used 8493K, capacity 9282K, committed 9344K, reserved 1048576K
[2022-05-09T14:41:40.463+0200][2997.970s][info ][gc            ] GC(39) Pause Young (Normal) (G1 Evacuation Pause) 14082M->5067M(22528M) 51.873ms
[2022-05-09T14:41:40.464+0200][2997.970s][info ][gc,cpu        ] GC(39) User=0.72s Sys=0.01s Real=0.05s

For your ref-https://stackoverflow.com/questions/61797907/how-to-reduce-cpu-usage-for-java-11-with-g1gc-on-gcp — Sibin Rasiya, May 04 '22 at 11:39
The option "PrintFLSStatistics" is a CMS collector option, which means you should remove it when using G1. Be careful not to mix options between collectors. Please post parts of gc.log for a Java 8 run and a Java 11 run. About 200 of the last lines would likely help diagnose your issue. — dchristle, May 07 '22 at 21:14
@dchristle thank you for your response. I added gc.log samples into the original question. The only thing I can see is that heap survivors number is different bw 8th and 11th: 4 for 8th and 25th for 11th. And Age 1 is 10x times different (java11 one is bigger) — Sviatlana, May 09 '22 at 12:54

High CPU usage when shifting from Java 8 to Java 11 with G1GC

0 Answers0