G1 GC shows large time in Other phase

Issue

• In our GC logging, we see occassionally see a long time spent in the Other phase. What would contribute to a large spike here?

[2022-10-09T13:16:39.707+0000][3783.195s][debug][gc,heap           ] GC(9) Heap before GC invocations=9 (full 0): garbage-first heap   total 10743808K, used 1819374K [0x0000000570400000, 0x0000000800000000)
[2022-10-09T13:16:49.276+0000][3792.764s][debug][gc,heap           ] GC(9)   region size 4096K, 425 young (1740800K), 7 survivors (28672K)
[2022-10-09T13:16:49.276+0000][3792.764s][debug][gc,heap           ] GC(9)  Metaspace       used 91225K, capacity 98503K, committed 98816K, reserved 339968K
[2022-10-09T13:16:49.276+0000][3792.764s][debug][gc,heap           ] GC(9)   class space    used 10833K, capacity 13361K, committed 13440K, reserved 253952K
[2022-10-09T13:16:49.276+0000][3792.764s][info ][gc,start          ] GC(9) Pause Young (Normal) (G1 Evacuation Pause)
[2022-10-09T13:16:49.276+0000][3792.764s][info ][gc,task           ] GC(9) Using 8 workers of 8 for evacuation
[2022-10-09T13:16:49.276+0000][3792.764s][debug][gc,tlab           ] GC(9) TLAB totals: thrds: 223  refills: 9596 max: 462 slow allocs: 767 max 41 waste:  1.5% gc: 16198888B max: 1568112B slow: 6511096B max: 409312B fast: 0B max: 0B
[2022-10-09T13:16:49.276+0000][3792.764s][debug][gc,alloc,region   ] GC(9) Mutator Allocation stats, regions: 418, wasted size: 4224B ( 0.0%)
[2022-10-09T13:16:49.276+0000][3792.764s][debug][gc,age            ] GC(9) Desired survivor size 113246208 bytes, new threshold 15 (max threshold 15)
[2022-10-09T13:16:49.276+0000][3792.764s][debug][gc,ergo,cset      ] GC(9) Finish choosing CSet. old: 0 regions, predicted old region time: 0.00ms, time remaining: 0.43
[2022-10-09T13:16:49.276+0000][3792.764s][debug][gc,refine         ] Activated worker 0, on threshold: 19, current: 80
[2022-10-09T13:16:49.287+0000][3792.776s][debug][gc,ergo           ] GC(9) Running G1 Clear Card Table Task using 4 workers for 4 units of work for 446 regions.
[2022-10-09T13:16:49.288+0000][3792.776s][debug][gc,ref            ] GC(9) Skipped phase1 of Reference Processing due to unavailable references
[2022-10-09T13:16:49.288+0000][3792.776s][debug][gc,ergo           ] GC(9) Running G1 Free Collection Set using 8 workers for collection set length 425
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,ihop           ] GC(9) Basic information (value update), threshold: 7701161574B (70.00), target occupancy: 11001659392B, current occupancy: 115332592B, recent allocation size: 0B, recent allocation duration: 773718.23ms, recent old gen allocation rate: 0.00B/s, recent marking phase length: 0.00ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,ihop           ] GC(9) Adaptive IHOP information (value update), threshold: 7701161574B (82.35), internal target occupancy: 9351410483B, occupancy: 115332592B, additional buffer size: 2462056448B, predicted old gen allocation rate: 18218.99B/s, predicted marking phase length: 0.00ms, prediction active: false
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,ergo,refine    ] GC(9) Updated Refinement Zones: green: 16, yellow: 48, red: 80
[2022-10-09T13:16:49.289+0000][3792.777s][info ][gc,phases         ] GC(9)   Pre Evacuate Collection Set: 0.1ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Prepare TLABs: 0.1ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Choose Collection Set: 0.0ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Humongous Register: 0.1ms
[2022-10-09T13:16:49.289+0000][3792.777s][info ][gc,phases         ] GC(9)   Evacuate Collection Set: 10.7ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Ext Root Scanning (ms):   Min:  0.9, Avg:  1.0, Max:  1.0, Diff:  0.1, Sum:  7.8, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Update RS (ms):           Min:  0.4, Avg:  0.7, Max:  1.6, Diff:  1.2, Sum:  5.5, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)       Processed Buffers:        Min: 1, Avg: 26.9, Max: 111, Diff: 110, Sum: 215, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)       Scanned Cards:            Min: 194, Avg: 509.4, Max: 1890, Diff: 1696, Sum: 4075, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)       Skipped Cards:            Min: 0, Avg:  1.8, Max: 8, Diff: 8, Sum: 14, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Scan RS (ms):             Min:  0.0, Avg:  0.0, Max:  0.1, Diff:  0.1, Sum:  0.3, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)       Scanned Cards:            Min: 0, Avg:  2.6, Max: 21, Diff: 21, Sum: 21, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)       Claimed Cards:            Min: 0, Avg:  4.4, Max: 32, Diff: 32, Sum: 35, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)       Skipped Cards:            Min: 0, Avg:  2.1, Max: 17, Diff: 17, Sum: 17, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Code Root Scanning (ms):  Min:  0.0, Avg:  0.2, Max:  1.1, Diff:  1.1, Sum:  1.4, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     AOT Root Scanning (ms):   skipped
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Object Copy (ms):         Min:  7.5, Avg:  8.5, Max:  8.9, Diff:  1.5, Sum: 67.7, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Termination (ms):         Min:  0.0, Avg:  0.0, Max:  0.0, Diff:  0.0, Sum:  0.0, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)       Termination Attempts:     Min: 1, Avg:  1.0, Max: 1, Diff: 0, Sum: 8, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     GC Worker Other (ms):     Min:  0.1, Avg:  0.2, Max:  0.3, Diff:  0.3, Sum:  1.7, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     GC Worker Total (ms):     Min: 10.4, Avg: 10.5, Max: 10.7, Diff:  0.3, Sum: 84.3, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][info ][gc,phases         ] GC(9)   Post Evacuate Collection Set: 1.2ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Code Roots Fixup: 0.0ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Clear Card Table: 0.3ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Reference Processing: 0.2ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)       Reconsider SoftReferences: 0.0ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         SoftRef (ms):             skipped
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)       Notify Soft/WeakReferences: 0.1ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         SoftRef (ms):             Min:  0.0, Avg:  0.0, Max:  0.0, Diff:  0.0, Sum:  0.0, Workers: 1
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         WeakRef (ms):             Min:  0.0, Avg:  0.0, Max:  0.0, Diff:  0.0, Sum:  0.0, Workers: 1
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         FinalRef (ms):            Min:  0.0, Avg:  0.0, Max:  0.0, Diff:  0.0, Sum:  0.0, Workers: 1
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         Total (ms):               Min:  0.0, Avg:  0.0, Max:  0.0, Diff:  0.0, Sum:  0.0, Workers: 1
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)       Notify and keep alive finalizable: 0.1ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         Balance queues: 0.0ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         FinalRef (ms):            Min:  0.0, Avg:  0.0, Max:  0.1, Diff:  0.0, Sum:  0.3, Workers: 8
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)       Notify PhantomReferences: 0.0ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         PhantomRef (ms):          Min:  0.0, Avg:  0.0, Max:  0.0, Diff:  0.0, Sum:  0.0, Workers: 1
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)       SoftReference:
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         Discovered: 0
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         Cleared: 0
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)       WeakReference:
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         Discovered: 5
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         Cleared: 5
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)       FinalReference:
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         Discovered: 38
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         Cleared: 0
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)       PhantomReference:
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         Discovered: 2
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases,ref     ] GC(9)         Cleared: 2
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Weak Processing: 0.1ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Merge Per-Thread State: 0.0ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Code Roots Purge: 0.0ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Redirty Cards: 0.0ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     DerivedPointerTable Update: 0.0ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Free Collection Set: 0.5ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Humongous Reclaim: 0.0ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Start New Collection Set: 0.0ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Resize TLABs: 0.0ms
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,phases         ] GC(9)     Expand Heap After Collection: 0.0ms
[2022-10-09T13:16:49.289+0000][3792.777s][info ][gc,phases         ] GC(9)   Other: 9569.7ms
[2022-10-09T13:16:49.289+0000][3792.777s][info ][gc,heap           ] GC(9) Eden regions: 418->0(580)
[2022-10-09T13:16:49.289+0000][3792.777s][info ][gc,heap           ] GC(9) Survivor regions: 7->7(54)
[2022-10-09T13:16:49.289+0000][3792.777s][info ][gc,heap           ] GC(9) Old regions: 22->22
[2022-10-09T13:16:49.289+0000][3792.777s][info ][gc,heap           ] GC(9) Humongous regions: 0->0
[2022-10-09T13:16:49.289+0000][3792.777s][info ][gc,metaspace      ] GC(9) Metaspace: 91225K->91225K(339968K)
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,heap           ] GC(9) Heap after GC invocations=10 (full 0): garbage-first heap   total 10743808K, used 112629K [0x0000000570400000, 0x0000000800000000)
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,heap           ] GC(9)   region size 4096K, 7 young (28672K), 7 survivors (28672K)
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,heap           ] GC(9)  Metaspace       used 91225K, capacity 98503K, committed 98816K, reserved 339968K
[2022-10-09T13:16:49.289+0000][3792.777s][debug][gc,heap           ] GC(9)   class space    used 10833K, capacity 13361K, committed 13440K, reserved 253952K
[2022-10-09T13:16:49.289+0000][3792.777s][info ][gc                ] GC(9) Pause Young (Normal) (G1 Evacuation Pause) 1780M->109M(10492M) 13.288ms
[2022-10-09T13:16:49.289+0000][3792.777s][info ][gc,cpu            ] GC(9) User=0.07s Sys=0.01s Real=0.01s