Pause Mark Start took a long time
Erik Osterlund
erik.osterlund at oracle.com
Wed Jul 13 08:03:56 UTC 2022
Hi,
The GC code does almost nothing in the mark start operation, so I have a difficult time seeing that the actual GC code would have much to do with this kind of delay. However, it does do some logging. I wonder if the log statement in the safepoint is being flushed to disk synchronously, and since you are running in some kind of cloud environment, perhaps the disk is accessed over the network, which might experience some kind of delays. If that is the case, then perhaps using -Xlog:async instead might be a good idea for you. It should be available in JDK 17 which you appear to be using.
Please let me know if that helps or not.
Thanks,
/Erik
On 13 Jul 2022, at 09:44, kang wangk <wangkang0902 at gmail.com<mailto:wangkang0902 at gmail.com>> wrote:
Hi,
I am running ZGC in production(Deployed in k8s) with following settings
-Xms4000m -Xmx4000m -XX:ConcGCThreads=2 -XX:-UseDynamicNumberOfGCThreads -XX:+UseZGC -XX:-ZProactive -XX:ZAllocationSpikeTolerance=3 -XX:ZCollectionInterval=60
Occasionally encounter a long Pause Mark Start time(the longest pause time is 5s)
Here are some GC logs blow
[2022-07-12T10:52:52.242+0800][10][info][gc,init] Initializing The Z Garbage Collector
[2022-07-12T10:52:52.242+0800][10][info][gc,init] Version: 17.0.3+8-LTS-111 (release)
[2022-07-12T10:52:52.242+0800][10][info][gc,init] NUMA Support: Disabled
[2022-07-12T10:52:52.242+0800][10][info][gc,init] CPUs: 64 total, 4 available
[2022-07-12T10:52:52.242+0800][10][info][gc,init] Memory: 10240M
[2022-07-12T10:52:52.243+0800][10][info][gc,init] Large Page Support: Disabled
[2022-07-12T10:52:52.243+0800][10][info][gc,init] GC Workers: 2/3 (static)
[2022-07-12T10:52:52.243+0800][10][info][gc,init] Address Space Type: Contiguous/Unrestricted/Complete
[2022-07-12T10:52:52.243+0800][10][info][gc,init] Address Space Size: 64000M x 3 = 192000M
[2022-07-12T10:52:52.243+0800][10][info][gc,init] Heap Backing File: /memfd:java_heap
[2022-07-12T10:52:52.243+0800][10][info][gc,init] Heap Backing Filesystem: tmpfs (0x1021994)
[2022-07-12T10:52:52.243+0800][10][info][gc,init] Min Capacity: 4000M
[2022-07-12T10:52:52.243+0800][10][info][gc,init] Initial Capacity: 4000M
[2022-07-12T10:52:52.243+0800][10][info][gc,init] Max Capacity: 4000M
[2022-07-12T10:52:52.243+0800][10][info][gc,init] Medium Page Size: 32M
[2022-07-12T10:52:52.243+0800][10][info][gc,init] Pre-touch: Enabled
[2022-07-12T10:52:52.243+0800][10][info][gc,init] Available space on backing filesystem: N/A
[2022-07-12T10:52:52.243+0800][10][info][gc,init] Uncommit: Implicitly Disabled (-Xms equals -Xmx)
[2022-07-12T10:52:55.014+0800][10][info][gc,init] Runtime Workers: 3
[2022-07-12T10:52:55.014+0800][10][info][gc ] Using The Z Garbage Collector
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] === Garbage Collection Statistics =======================================================================================================================
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Last 10s Last 10m Last 10h Total
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Avg / Max Avg / Max Avg / Max Avg / Max
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Collector: Garbage Collection Cycle 0.000 / 0.000 215.897 / 245.004 199.964 / 281.004 198.501 / 327.779 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Contention: Mark Segment Reset Contention 0 / 0 0 / 3 0 / 13 0 / 17 ops/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Contention: Mark SeqNum Reset Contention 0 / 0 0 / 2 0 / 3 0 / 4 ops/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Critical: Allocation Stall 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Critical: Allocation Stall 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Critical: GC Locker Stall 0 / 0 0 / 1 0 / 1 0 / 1 ops/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Critical: GC Locker Stall 0.000 / 0.000 0.001 / 0.001 0.022 / 0.138 0.032 / 0.197 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Critical: Relocation Stall 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Critical: Relocation Stall 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Memory: Allocation Rate 106 / 124 109 / 240 100 / 308 104 / 352 MB/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Memory: Out Of Memory 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Memory: Page Cache Flush 0 / 0 0 / 0 0 / 0 0 / 0 MB/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Memory: Page Cache Hit L1 53 / 62 54 / 76 49 / 94 51 / 176 ops/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Memory: Page Cache Hit L2 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Memory: Page Cache Hit L3 0 / 0 0 / 0 0 / 1 0 / 123 ops/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Memory: Page Cache Miss 0 / 0 0 / 0 0 / 0 0 / 1 ops/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Memory: Uncommit 0 / 0 0 / 0 0 / 0 0 / 0 MB/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Memory: Undo Object Allocation Failed 0 / 0 0 / 94 0 / 189 0 / 438 ops/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Memory: Undo Object Allocation Succeeded 0 / 0 0 / 90 0 / 571 0 / 571 ops/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Memory: Undo Page Allocation 0 / 1 0 / 3 0 / 7 0 / 9 ops/s
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Phase: Concurrent Mark 0.000 / 0.000 162.242 / 191.178 149.779 / 233.888 149.319 / 253.310 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Phase: Concurrent Mark Continue 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Phase: Concurrent Mark Free 0.000 / 0.000 0.001 / 0.003 0.001 / 0.035 0.001 / 0.035 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Phase: Concurrent Process Non-Strong References 0.000 / 0.000 40.077 / 43.167 36.932 / 73.540 35.951 / 73.540 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Phase: Concurrent Relocate 0.000 / 0.000 9.764 / 13.321 9.670 / 18.334 9.656 / 64.541 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Phase: Concurrent Reset Relocation Set 0.000 / 0.000 0.246 / 0.377 0.234 / 0.385 0.228 / 0.459 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Phase: Concurrent Select Relocation Set 0.000 / 0.000 2.843 / 3.684 2.670 / 4.496 2.647 / 9.518 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Phase: Pause Mark End 0.000 / 0.000 0.036 / 0.059 0.030 / 0.080 0.029 / 0.105 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Phase: Pause Mark Start 0.000 / 0.000 0.040 / 0.050 0.057 / 17.923 0.085 / 116.781 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Phase: Pause Relocate Start 0.000 / 0.000 0.022 / 0.032 0.021 / 0.060 0.021 / 0.063 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Subphase: Concurrent Classes Purge 0.000 / 0.000 1.484 / 2.016 1.290 / 2.861 1.230 / 3.239 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Subphase: Concurrent Classes Unlink 0.000 / 0.000 34.848 / 38.008 32.338 / 68.815 31.461 / 68.815 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Subphase: Concurrent Mark 0.000 / 0.000 158.162 / 187.147 146.016 / 230.654 145.542 / 250.339 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Subphase: Concurrent Mark Try Flush 0.000 / 0.000 0.208 / 0.536 0.197 / 79.168 0.179 / 79.168 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Subphase: Concurrent Mark Try Terminate 0.000 / 0.000 0.468 / 1.076 0.455 / 5.019 0.449 / 32.389 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Subphase: Concurrent References Enqueue 0.000 / 0.000 0.001 / 0.008 0.002 / 0.015 0.002 / 0.031 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Subphase: Concurrent References Process 0.000 / 0.000 0.417 / 0.662 0.297 / 0.828 0.305 / 4.058 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Subphase: Concurrent Roots ClassLoaderDataGraph 0.000 / 0.000 0.421 / 1.062 0.393 / 1.062 0.392 / 1.062 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Subphase: Concurrent Roots CodeCache 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Subphase: Concurrent Roots JavaThreads 0.000 / 0.000 2.863 / 3.649 2.609 / 4.023 2.636 / 4.221 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Subphase: Concurrent Roots OopStorageSet 0.000 / 0.000 0.101 / 0.148 0.094 / 0.172 0.092 / 0.748 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Subphase: Concurrent Weak Roots OopStorageSet 0.000 / 0.000 2.895 / 3.442 2.633 / 3.805 2.588 / 4.245 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] Subphase: Pause Mark Try Complete 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.003 / 0.006 ms
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] System: Java Threads 0 / 0 204 / 227 173 / 227 167 / 227 threads
[2022-07-13T14:18:33.036+0800][18][info][gc,stats ] =========================================================================================================================================================
[2022-07-13T14:18:37.836+0800][16][info][gc,task ] GC(2822) Using 2 workers
[2022-07-13T14:18:38.568+0800][23][info][gc,phases ] GC(2822) Pause Mark Start 731.329ms
[2022-07-13T14:18:38.568+0800][23][info][safepoint ] Safepoint "ZMarkStart", Time since last: 33682417078 ns, Reaching safepoint: 78660 ns, At safepoint: 731509582 ns, Total: 731588242 ns
[2022-07-13T14:18:38.763+0800][16][info][gc,phases ] GC(2822) Concurrent Mark 195.357ms
[2022-07-13T14:18:38.763+0800][23][info][gc,phases ] GC(2822) Pause Mark End 0.037ms
[2022-07-13T14:18:38.763+0800][23][info][safepoint ] Safepoint "ZMarkEnd", Time since last: 195457277 ns, Reaching safepoint: 59774 ns, At safepoint: 69617 ns, Total: 129391 ns
[2022-07-13T14:18:38.763+0800][16][info][gc,phases ] GC(2822) Concurrent Mark Free 0.002ms
[2022-07-13T14:18:38.807+0800][16][info][gc,phases ] GC(2822) Concurrent Process Non-Strong References 43.503ms
[2022-07-13T14:18:38.807+0800][16][info][gc,phases ] GC(2822) Concurrent Reset Relocation Set 0.266ms
[2022-07-13T14:18:38.811+0800][16][info][gc,phases ] GC(2822) Concurrent Select Relocation Set 3.787ms
[2022-07-13T14:18:38.811+0800][23][info][gc,phases ] GC(2822) Pause Relocate Start 0.022ms
[2022-07-13T14:18:38.811+0800][23][info][safepoint ] Safepoint "ZRelocateStart", Time since last: 47720139 ns, Reaching safepoint: 71865 ns, At safepoint: 50103 ns, Total: 121968 ns
[2022-07-13T14:18:38.823+0800][16][info][gc,phases ] GC(2822) Concurrent Relocate 12.090ms
[2022-07-13T14:18:38.823+0800][16][info][gc,load ] GC(2822) Load: 17.47/17.79/16.25
[2022-07-13T14:18:38.823+0800][16][info][gc,mmu ] GC(2822) MMU: 2ms/0.0%, 5ms/0.0%, 10ms/0.0%, 20ms/0.0%, 50ms/0.0%, 100ms/0.0%
[2022-07-13T14:18:38.823+0800][16][info][gc,marking ] GC(2822) Mark: 2 stripe(s), 2 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s)
[2022-07-13T14:18:38.823+0800][16][info][gc,marking ] GC(2822) Mark Stack Usage: 32M
[2022-07-13T14:18:38.823+0800][16][info][gc,nmethod ] GC(2822) NMethods: 23051 registered, 1360 unregistered
[2022-07-13T14:18:38.823+0800][16][info][gc,metaspace] GC(2822) Metaspace: 113M used, 114M committed, 516M reserved
[2022-07-13T14:18:38.823+0800][16][info][gc,ref ] GC(2822) Soft: 1059 encountered, 271 discovered, 0 enqueued
[2022-07-13T14:18:38.823+0800][16][info][gc,ref ] GC(2822) Weak: 16086 encountered, 1352 discovered, 0 enqueued
[2022-07-13T14:18:38.823+0800][16][info][gc,ref ] GC(2822) Final: 30 encountered, 2 discovered, 0 enqueued
[2022-07-13T14:18:38.823+0800][16][info][gc,ref ] GC(2822) Phantom: 290 encountered, 250 discovered, 1 enqueued
[2022-07-13T14:18:38.823+0800][16][info][gc,reloc ] GC(2822) Small Pages: 1852 / 3704M, Empty: 698M, Relocated: 10M, In-Place: 0
[2022-07-13T14:18:38.823+0800][16][info][gc,reloc ] GC(2822) Medium Pages: 2 / 64M, Empty: 32M, Relocated: 0M, In-Place: 0
[2022-07-13T14:18:38.823+0800][16][info][gc,reloc ] GC(2822) Large Pages: 0 / 0M, Empty: 0M, Relocated: 0M, In-Place: 0
[2022-07-13T14:18:38.823+0800][16][info][gc,reloc ] GC(2822) Forwarding Usage: 3M
[2022-07-13T14:18:38.823+0800][16][info][gc ] GC(2822) Garbage Collection (High Usage) 3768M(94%)->238M(6%)
[2022-07-13T14:18:42.813+0800][23][info][safepoint ] Safepoint "Cleanup", Time since last: 4000282554 ns, Reaching safepoint: 1161862 ns, At safepoint: 32230 ns, Total: 1194092 ns
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] === Garbage Collection Statistics =======================================================================================================================
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Last 10s Last 10m Last 10h Total
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Avg / Max Avg / Max Avg / Max Avg / Max
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Collector: Garbage Collection Cycle 987.238 / 987.238 256.494 / 987.238 200.744 / 987.238 198.781 / 987.238 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Contention: Mark Segment Reset Contention 0 / 0 0 / 3 0 / 13 0 / 17 ops/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Contention: Mark SeqNum Reset Contention 0 / 0 0 / 2 0 / 3 0 / 4 ops/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Critical: Allocation Stall 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Critical: Allocation Stall 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Critical: GC Locker Stall 0 / 0 0 / 1 0 / 1 0 / 1 ops/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Critical: GC Locker Stall 0.000 / 0.000 0.001 / 0.001 0.022 / 0.138 0.032 / 0.197 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Critical: Relocation Stall 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Critical: Relocation Stall 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Memory: Allocation Rate 105 / 128 109 / 240 100 / 308 104 / 352 MB/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Memory: Out Of Memory 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Memory: Page Cache Flush 0 / 0 0 / 0 0 / 0 0 / 0 MB/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Memory: Page Cache Hit L1 51 / 64 54 / 76 49 / 94 51 / 176 ops/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Memory: Page Cache Hit L2 0 / 0 0 / 0 0 / 0 0 / 0 ops/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Memory: Page Cache Hit L3 1 / 16 0 / 16 0 / 16 0 / 123 ops/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Memory: Page Cache Miss 0 / 0 0 / 0 0 / 0 0 / 1 ops/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Memory: Uncommit 0 / 0 0 / 0 0 / 0 0 / 0 MB/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Memory: Undo Object Allocation Failed 1 / 14 0 / 94 0 / 189 0 / 438 ops/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Memory: Undo Object Allocation Succeeded 10 / 109 0 / 109 0 / 571 0 / 571 ops/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Memory: Undo Page Allocation 0 / 4 0 / 4 0 / 7 0 / 9 ops/s
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Phase: Concurrent Mark 195.357 / 195.357 163.985 / 195.357 149.824 / 233.888 149.336 / 253.310 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Phase: Concurrent Mark Continue 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Phase: Concurrent Mark Free 0.002 / 0.002 0.001 / 0.003 0.001 / 0.035 0.001 / 0.035 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Phase: Concurrent Process Non-Strong References 43.503 / 43.503 40.257 / 43.503 36.939 / 73.540 35.954 / 73.540 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Phase: Concurrent Relocate 12.090 / 12.090 9.887 / 13.321 9.672 / 18.334 9.657 / 64.541 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Phase: Concurrent Reset Relocation Set 0.266 / 0.266 0.247 / 0.377 0.234 / 0.385 0.228 / 0.459 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Phase: Concurrent Select Relocation Set 3.787 / 3.787 2.893 / 3.787 2.671 / 4.496 2.647 / 9.518 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Phase: Pause Mark End 0.037 / 0.037 0.036 / 0.059 0.030 / 0.080 0.029 / 0.105 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Phase: Pause Mark Start 731.329 / 731.329 38.529 / 731.329 0.782 / 731.329 0.344 / 731.329 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Phase: Pause Relocate Start 0.022 / 0.022 0.022 / 0.032 0.021 / 0.060 0.021 / 0.063 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Subphase: Concurrent Classes Purge 1.826 / 1.826 1.502 / 2.016 1.290 / 2.861 1.230 / 3.239 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Subphase: Concurrent Classes Unlink 38.001 / 38.001 35.014 / 38.008 32.344 / 68.815 31.464 / 68.815 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Subphase: Concurrent Mark 190.810 / 191.151 159.881 / 191.151 146.060 / 230.654 145.558 / 250.339 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Subphase: Concurrent Mark Try Flush 0.259 / 0.548 0.211 / 0.548 0.197 / 79.168 0.179 / 79.168 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Subphase: Concurrent Mark Try Terminate 0.545 / 1.065 0.472 / 1.076 0.456 / 5.019 0.449 / 32.389 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Subphase: Concurrent References Enqueue 0.009 / 0.009 0.002 / 0.009 0.002 / 0.015 0.002 / 0.031 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Subphase: Concurrent References Process 0.338 / 0.338 0.412 / 0.662 0.297 / 0.828 0.305 / 4.058 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Subphase: Concurrent Roots ClassLoaderDataGraph 0.376 / 0.659 0.419 / 1.062 0.393 / 1.062 0.392 / 1.062 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Subphase: Concurrent Roots CodeCache 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Subphase: Concurrent Roots JavaThreads 3.345 / 3.622 2.889 / 3.649 2.610 / 4.023 2.636 / 4.221 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Subphase: Concurrent Roots OopStorageSet 0.103 / 0.110 0.101 / 0.148 0.094 / 0.172 0.092 / 0.748 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Subphase: Concurrent Weak Roots OopStorageSet 2.779 / 2.780 2.889 / 3.442 2.633 / 3.805 2.588 / 4.245 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] Subphase: Pause Mark Try Complete 0.000 / 0.000 0.000 / 0.000 0.000 / 0.000 0.003 / 0.006 ms
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] System: Java Threads 226 / 234 205 / 234 173 / 234 167 / 234 threads
[2022-07-13T14:18:43.036+0800][18][info][gc,stats ] =========================================================================================================================================================
In my opinion, this stage is very light. What can cause this phenomenon
Thanks!
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/zgc-dev/attachments/20220713/7bc1734b/attachment-0001.htm>
More information about the zgc-dev
mailing list