G1 gc 'Other' takes a long time. What is the most possible cause and how to solve it?
jvm params:
-XX:+UseG1GC -XX:MaxGCPauseMillis=10 -Xmx2048m -Xms2048m -Xss512k -XX:NewRatio=2 -XX:MetaspaceSize=256m -XX:MaxMetaspaceSize=512m -XX:ReservedCodeCacheSize=256m -XX:InitialCodeCacheSize=256m -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -XX:+PrintTenuringDistribution -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=128M -Xloggc:/med/log/mall-product.gc.log -XX:+HeapDumpOnOutOfMemoryError
2021-11-04T12:36:18.118+0800: 96537.313: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 45088768 bytes, new threshold 15 (max 15)
- age 1: 3923792 bytes, 3923792 total
- age 2: 281104 bytes, 4204896 total
- age 3: 311088 bytes, 4515984 total
- age 4: 74304 bytes, 4590288 total
- age 5: 91728 bytes, 4682016 total
- age 6: 66368 bytes, 4748384 total
- age 7: 111832 bytes, 4860216 total
- age 8: 82232 bytes, 4942448 total
- age 9: 53752 bytes, 4996200 total
- age 10: 47432 bytes, 5043632 total
- age 11: 115944 bytes, 5159576 total
- age 12: 134000 bytes, 5293576 total
- age 13: 478392 bytes, 5771968 total
- age 14: 378696 bytes, 6150664 total
- age 15: 595856 bytes, 6746520 total
, 0.0161776 secs]
[Parallel Time: 12.3 ms, GC Workers: 4]
[GC Worker Start (ms): Min: 96537314.0, Avg: 96537314.0, Max: 96537314.1, Diff: 0.1]
[Ext Root Scanning (ms): Min: 4.2, Avg: 4.5, Max: 4.7, Diff: 0.5, Sum: 17.9]
[Update RS (ms): Min: 2.5, Avg: 2.5, Max: 2.5, Diff: 0.0, Sum: 10.0]
[Processed Buffers: Min: 28, Avg: 39.0, Max: 53, Diff: 25, Sum: 156]
[Scan RS (ms): Min: 0.4, Avg: 0.5, Max: 0.5, Diff: 0.0, Sum: 1.8]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Object Copy (ms): Min: 4.4, Avg: 4.6, Max: 4.8, Diff: 0.4, Sum: 18.4]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4]
[GC Worker Other (ms): Min: 0.1, Avg: 0.1, Max: 0.1, Diff: 0.0, Sum: 0.4]
[GC Worker Total (ms): Min: 12.1, Avg: 12.1, Max: 12.2, Diff: 0.2, Sum: 48.5]
[GC Worker End (ms): Min: 96537326.1, Avg: 96537326.2, Max: 96537326.2, Diff: 0.1]
[Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.3 ms]
[Other: 3.6 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 1.4 ms]
[Ref Enq: 0.1 ms]
[Redirty Cards: 0.1 ms]
[Humongous Register: 0.1 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 1.1 ms]
[Eden: 674.0M(674.0M)->0.0B(674.0M) Survivors: 8192.0K->8192.0K Heap: 1428.6M(2048.0M)->755.3M(2048.0M)]
Heap after GC invocations=2668 (full 0):
garbage-first heap total 2097152K, used 773428K [0x0000000080000000, 0x0000000080104000, 0x0000000100000000)
region size 1024K, 8 young (8192K), 8 survivors (8192K)
Metaspace used 133822K, capacity 141304K, committed 141440K, reserved 1173504K
class space used 16174K, capacity 17421K, committed 17536K, reserved 1048576K
}
[Times: user=0.05 sys=0.01, real=0.02 secs]
{Heap before GC invocations=2668 (full 0):
garbage-first heap total 2097152K, used 1463604K [0x0000000080000000, 0x0000000080104000, 0x0000000100000000)
region size 1024K, 682 young (698368K), 8 survivors (8192K)
Metaspace used 133822K, capacity 141304K, committed 141440K, reserved 1173504K
class space used 16174K, capacity 17421K, committed 17536K, reserved 1048576K
2021-11-04T12:37:22.250+0800: 96601.445: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 45088768 bytes, new threshold 15 (max 15)
- age 1: 3170160 bytes, 3170160 total
- age 2: 1426024 bytes, 4596184 total
- age 3: 396136 bytes, 4992320 total
- age 4: 67992 bytes, 5060312 total
- age 5: 123112 bytes, 5183424 total
- age 6: 64320 bytes, 5247744 total
- age 7: 75640 bytes, 5323384 total
- age 8: 56656 bytes, 5380040 total
- age 9: 87560 bytes, 5467600 total
- age 10: 79568 bytes, 5547168 total
- age 11: 34016 bytes, 5581184 total
- age 12: 47432 bytes, 5628616 total
- age 13: 115944 bytes, 5744560 total
- age 14: 133456 bytes, 5878016 total
- age 15: 477016 bytes, 6355032 total
, 0.1573301 secs]
[Parallel Time: 12.2 ms, GC Workers: 4]
[GC Worker Start (ms): Min: 96601587.8, Avg: 96601587.9, Max: 96601587.9, Diff: 0.1]
[Ext Root Scanning (ms): Min: 4.0, Avg: 4.3, Max: 4.7, Diff: 0.7, Sum: 17.1]
[Update RS (ms): Min: 2.0, Avg: 2.1, Max: 2.1, Diff: 0.0, Sum: 8.3]
[Processed Buffers: Min: 30, Avg: 38.5, Max: 46, Diff: 16, Sum: 154]
[Scan RS (ms): Min: 0.9, Avg: 0.9, Max: 1.0, Diff: 0.1, Sum: 3.6]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Object Copy (ms): Min: 4.3, Avg: 4.7, Max: 5.0, Diff: 0.7, Sum: 19.0]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4]
[GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.3]
[GC Worker Total (ms): Min: 12.0, Avg: 12.1, Max: 12.1, Diff: 0.1, Sum: 48.3]
[GC Worker End (ms): Min: 96601599.9, Avg: 96601599.9, Max: 96601600.0, Diff: 0.1]
[Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.3 ms]
[Other: 144.8 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 1.3 ms]
[Ref Enq: 0.1 ms]
[Redirty Cards: 0.1 ms]
[Humongous Register: 0.1 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.7 ms]
[Eden: 674.0M(674.0M)->0.0B(674.0M) Survivors: 8192.0K->8192.0K Heap: 1430.5M(2048.0M)->756.7M(2048.0M)]
Heap after GC invocations=2670 (full 0):
garbage-first heap total 2097152K, used 774853K [0x0000000080000000, 0x0000000080104000, 0x0000000100000000)
region size 1024K, 8 young (8192K), 8 survivors (8192K)
Metaspace used 133822K, capacity 141304K, committed 141440K, reserved 1173504K
class space used 16174K, capacity 17421K, committed 17536K, reserved 1048576K
}
[Times: user=0.05 sys=0.00, real=0.16 secs]
{Heap before GC invocations=2670 (full 0):
garbage-first heap total 2097152K, used 1465029K [0x0000000080000000, 0x0000000080104000, 0x0000000100000000)
region size 1024K, 682 young (698368K), 8 survivors (8192K)
Metaspace used 133824K, capacity 141304K, committed 141440K, reserved 1173504K
class space used 16174K, capacity 17421K, committed 17536K, reserved 1048576K
2021-11-04T12:38:26.994+0800: 96666.190: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 45088768 bytes, new threshold 15 (max 15)
- age 1: 3254096 bytes, 3254096 total
- age 2: 1682680 bytes, 4936776 total
- age 3: 837152 bytes, 5773928 total
- age 4: 280664 bytes, 6054592 total
- age 5: 204576 bytes, 6259168 total
- age 6: 41664 bytes, 6300832 total
- age 7: 114536 bytes, 6415368 total
- age 8: 64256 bytes, 6479624 total
- age 9: 68944 bytes, 6548568 total
- age 10: 39424 bytes, 6587992 total
- age 11: 73704 bytes, 6661696 total
- age 12: 66912 bytes, 6728608 total
- age 13: 33808 bytes, 6762416 total
- age 14: 47432 bytes, 6809848 total
- age 15: 115944 bytes, 6925792 total
, 0.0582912 secs]
[Parallel Time: 11.2 ms, GC Workers: 4]
[GC Worker Start (ms): Min: 96666233.8, Avg: 96666233.9, Max: 96666233.9, Diff: 0.1]
[Ext Root Scanning (ms): Min: 3.2, Avg: 3.5, Max: 3.7, Diff: 0.5, Sum: 14.0]
[Update RS (ms): Min: 2.2, Avg: 2.3, Max: 2.5, Diff: 0.4, Sum: 9.0]
[Processed Buffers: Min: 10, Avg: 39.0, Max: 57, Diff: 47, Sum: 156]
[Scan RS (ms): Min: 0.3, Avg: 0.6, Max: 0.7, Diff: 0.4, Sum: 2.4]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
[Object Copy (ms): Min: 4.5, Avg: 4.6, Max: 4.8, Diff: 0.3, Sum: 18.6]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4]
[GC Worker Other (ms): Min: 0.1, Avg: 0.1, Max: 0.1, Diff: 0.0, Sum: 0.3]
[GC Worker Total (ms): Min: 11.1, Avg: 11.1, Max: 11.1, Diff: 0.1, Sum: 44.4]
[GC Worker End (ms): Min: 96666245.0, Avg: 96666245.0, Max: 96666245.0, Diff: 0.0]
[Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.2 ms]
[Other: 46.8 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 1.4 ms]
[Ref Enq: 0.1 ms]
[Redirty Cards: 0.0 ms]
[Humongous Register: 0.0 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.8 ms]
[Eden: 674.0M(674.0M)->0.0B(673.0M) Survivors: 8192.0K->9216.0K Heap: 1431.6M(2048.0M)->758.3M(2048.0M)]
Heap after GC invocations=2672 (full 0):
garbage-first heap total 2097152K, used 776487K [0x0000000080000000, 0x0000000080104000, 0x0000000100000000)
region size 1024K, 9 young (9216K), 9 survivors (9216K)
Metaspace used 133824K, capacity 141304K, committed 141440K, reserved 1173504K
class space used 16174K, capacity 17421K, committed 17536K, reserved 1048576K
}
[Times: user=0.05 sys=0.00, real=0.06 secs]
{Heap before GC invocations=2672 (full 0):
garbage-first heap total 2097152K, used 1465639K [0x0000000080000000, 0x0000000080104000, 0x0000000100000000)
region size 1024K, 682 young (698368K), 9 survivors (9216K)
Metaspace used 133824K, capacity 141304K, committed 141440K, reserved 1173504K
class space used 16174K, capacity 17421K, committed 17536K, reserved 1048576K
