ZGC Concurrent Mark Work distribution
Sundara Mohan M
m.sundar85 at gmail.com
Fri Feb 4 02:02:19 UTC 2022
Hi Per,
I tried using -XX:-UseDynamicNumberOfGCThreads and seeing no of threads
is reduced
With -UseDynamicNumberOfGCThreads
GC Precious Log:
NUMA Support: Enabled
NUMA Nodes: 2
CPUs: 72 total, 72 available
Memory: 191885M
Large Page Support: Disabled
* GC Workers: 9/44 (static)* Address Space Type:
Contiguous/Unrestricted/Complete
Address Space Size: 1024000M x 3 = 3072000M
Heap Backing File: /memfd:java_heap
Heap Backing Filesystem: tmpfs (0x1021994)
Min Capacity: 64000M
Initial Capacity: 64000M
Max Capacity: 64000M
Medium Page Size: 32M
Pre-touch: Disabled
Available space on backing filesystem: N/A
Uncommit: Implicitly Disabled (-Xms equals -Xmx)
Runtime Workers: 44
Without -UseDynamicNumberOfGCThreads
GC Precious Log:
NUMA Support: Enabled
NUMA Nodes: 2
CPUs: 72 total, 72 available
Memory: 191856M
Large Page Support: Disabled
* GC Workers: 18 (dynamic)* Address Space Type:
Contiguous/Unrestricted/Complete
Address Space Size: 1024000M x 3 = 3072000M
Heap Backing File: /memfd:java_heap
Heap Backing Filesystem: tmpfs (0x1021994)
Min Capacity: 64000M
Initial Capacity: 64000M
Max Capacity: 64000M
Medium Page Size: 32M
Pre-touch: Disabled
Available space on backing filesystem: N/A
Uncommit: Implicitly Disabled (-Xms equals -Xmx)
Runtime Workers: 44
1. Why is removing UseDynamicNumberOfGCThreads reducing the number of GC
Workers? Is 9 thread from pool of 44 always used for concurrent work?
2. Can we get the same number of workers using the ConcGCThread flag?
After using -UseDynamicNumberOfGCThreads sometimes i still see Allocation
Stall, do you think increasing GC Worker might help in that case?
Thanks
Sundar
On Wed, Feb 2, 2022 at 4:37 PM Sundara Mohan M <m.sundar85 at gmail.com> wrote:
> Hi Per,
> Thanks. Will try XX:-UseDynamicNumberOfGCThreads/
> -XX:SoftMaxHeapSize options.
>
> Regards
> Sundar
>
> On Wed, Feb 2, 2022 at 4:26 AM Per Liden <per.liden at oracle.com> wrote:
>
>> Hi,
>>
>> On 2/2/22 01:47, Sundara Mohan M wrote:
>> > Hi Per,
>> > Here is one instance where it is not able to cleanup as quickly as
>> > possible because of not using all threads, attaching the log file as
>> well.
>> >
>> > [2022-02-02T00:00:48.623+0000][100081.286s][debug][gc,director ] Rule:
>> > Allocation Rate (Dynamic GC Workers), MaxAllocRate: 8681.7MB/s
>> > (+/-1.2%), Free: 12800MB,
>> > GCCPUTime: 2.779, GCDuration: 1.406s, TimeUntilOOM: 1.457s,
>> TimeUntilGC:
>> > -0.049s, GCWorkers: 2 -> 2
>> > [2022-02-02T00:00:48.624+0000][100081.286s][info ][gc,start ]
>> > GC(7968) Garbage Collection (Allocation Rate)
>> > [2022-02-02T00:00:48.624+0000][100081.286s][info ][gc,task ]
>> > GC(7968) Using 2 workers
>> > [2022-02-02T00:00:48.625+0000][100081.287s][info ][gc,phases ]
>> > GC(7968) Pause Mark Start 0.051ms
>> > [2022-02-02T00:00:48.625+0000][100081.287s][info ][safepoint ]
>> > Safepoint "ZMarkStart", Time since last: 4730735883 ns, Reaching
>> > safepoint: 893580 ns, At safep
>> > oint: 450222 ns, Total: 1343802 ns
>> > [2022-02-02T00:00:48.640+0000][100081.302s][debug][gc,task ]
>> > GC(7968) Executing Task: ZMarkRootsTask, Active Workers: 2
>> > [2022-02-02T00:00:48.640+0000][100081.303s][debug][gc,phases ]
>> > GC(7968) Concurrent Roots OopStorageSet (ZWorker#12) 0.751ms
>> > [2022-02-02T00:00:48.640+0000][100081.303s][debug][gc,phases ]
>> > GC(7968) Concurrent Roots OopStorageSet (ZWorker#4) 0.802ms
>> > [2022-02-02T00:00:48.651+0000][100081.313s][debug][gc,phases ]
>> > GC(7968) Concurrent Roots ClassLoaderDataGraph (ZWorker#4) 10.565ms
>> > [2022-02-02T00:00:48.652+0000][100081.314s][debug][gc,phases ]
>> > GC(7968) Concurrent Roots ClassLoaderDataGraph (ZWorker#12) 11.789ms
>> > [2022-02-02T00:00:48.660+0000][100081.322s][debug][gc,phases ]
>> > GC(7968) Concurrent Roots JavaThreads (ZWorker#12) 7.919ms
>> > [2022-02-02T00:00:48.660+0000][100081.322s][debug][gc,phases ]
>> > GC(7968) Concurrent Roots JavaThreads (ZWorker#4) 9.086ms
>> > [2022-02-02T00:00:48.724+0000][100081.386s][debug][gc,phases ]
>> > GC(7968) Concurrent Roots CodeCache (ZWorker#12) 63.954ms
>> > [2022-02-02T00:00:48.724+0000][100081.386s][debug][gc,phases ]
>> > GC(7968) Concurrent Roots CodeCache (ZWorker#4) 63.921ms
>> > *[2022-02-02T00:00:48.724+0000][100081.386s][debug][gc,task ]
>> > GC(7968) Executing Task: ZMarkTask, Active Workers: 2
>> > *[2022-02-02T00:00:49.899+0000][100082.561s][debug][gc,phases ]
>> > GC(7968) Concurrent Mark Try Terminate (ZWorker#1) 1.064ms
>> > [2022-02-02T00:00:49.905+0000][100082.567s][debug][gc,phases ]
>> > GC(7968) Concurrent Mark Try Terminate (ZWorker#1) 1.065ms
>> > [2022-02-02T00:00:49.906+0000][100082.568s][debug][gc,phases ]
>> > GC(7968) Concurrent Mark Try Flush (ZWorker#15) 2.011ms
>> > [2022-02-02T00:00:49.914+0000][100082.576s][debug][gc,phases ]
>> > GC(7968) Concurrent Mark Try Flush (ZWorker#15) 0.897ms
>> > [2022-02-02T00:00:49.914+0000][100082.576s][debug][gc,phases ]
>> > GC(7968) Concurrent Mark Try Terminate (ZWorker#1) 1.062ms
>> > [2022-02-02T00:00:49.915+0000][100082.577s][debug][gc,phases ]
>> > GC(7968) Concurrent Mark Try Flush (ZWorker#15) 0.652ms
>> > [2022-02-02T00:00:49.915+0000][100082.577s][debug][gc,phases ]
>> > GC(7968) Concurrent Mark Try Terminate (ZWorker#1) 1.061ms
>> > [2022-02-02T00:00:49.915+0000][100082.578s][debug][gc,phases ]
>> > GC(7968) Concurrent Mark Try Flush (ZWorker#15) 0.760ms
>> > [2022-02-02T00:00:49.916+0000][100082.578s][debug][gc,phases ]
>> > GC(7968) Concurrent Mark Try Terminate (ZWorker#15) 0.775ms
>> > [2022-02-02T00:00:49.916+0000][100082.578s][debug][gc,phases ]
>> > GC(7968) Concurrent Mark Try Terminate (ZWorker#15) 0.000ms
>> > [2022-02-02T00:00:49.916+0000][100082.578s][debug][gc,phases ]
>> > GC(7968) Concurrent Mark (ZWorker#15) 1191.122ms
>> > [2022-02-02T00:00:49.916+0000][100082.578s][debug][gc,phases ]
>> > GC(7968) Concurrent Mark Try Terminate (ZWorker#1) 1.063ms
>> > [2022-02-02T00:00:49.916+0000][100082.578s][debug][gc,phases ]
>> > GC(7968) Concurrent Mark (ZWorker#1) 1191.971ms
>> > *[2022-02-02T00:00:49.917+0000][100082.579s][info ][gc,phases ]
>> > GC(7968) Concurrent Mark 1291.496ms*
>> > [2022-02-02T00:00:49.918+0000][100082.580s][info ][gc,phases ]
>> > GC(7968) Pause Mark End 0.076ms
>> > [2022-02-02T00:00:49.918+0000][100082.580s][info ][safepoint ]
>> > Safepoint "ZMarkEnd", Time since last: 1291581196 ns, Reaching
>> > safepoint: 983741 ns, At safepoi
>> > nt: 411088 ns, Total: 1394829 ns
>> > [2022-02-02T00:00:49.918+0000][100082.580s][info ][gc,phases ]
>> > GC(7968) Concurrent Mark Free 0.001ms
>> > [2022-02-02T00:00:49.918+0000][100082.580s][debug][gc,task ]
>> > GC(7968) Executing Task: ZReferenceProcessorTask, Active Workers: 2
>> > [2022-02-02T00:00:49.922+0000][100082.584s][debug][gc,phases ]
>> > GC(7968) Concurrent References Process (ZDriver) 3.803ms
>> > [2022-02-02T00:00:49.922+0000][100082.584s][debug][gc,task ]
>> > GC(7968) Executing Task: ZProcessWeakRootsTask, Active Workers: 2
>> > [2022-02-02T00:00:49.975+0000][100082.637s][debug][gc,phases ]
>> > GC(7968) Concurrent Weak Roots OopStorageSet (ZWorker#16) 52.890ms
>> > [2022-02-02T00:00:49.975+0000][100082.637s][debug][gc,phases ]
>> > GC(7968) Concurrent Weak Roots OopStorageSet (ZWorker#7) 52.888ms
>> > [2022-02-02T00:00:49.986+0000][100082.648s][debug][gc,phases ]
>> > GC(7968) Concurrent References Enqueue (ZDriver) 0.006ms
>> > [2022-02-02T00:00:49.986+0000][100082.648s][info ][gc,phases ]
>> > GC(7968) Concurrent Process Non-Strong References 68.404ms
>> > [2022-02-02T00:00:49.988+0000][100082.650s][info ][gc,phases ]
>> > GC(7968) Concurrent Reset Relocation Set 1.898ms
>> > *[2022-02-02T00:00:49.989+0000][100082.651s][info ][gc ]
>> > Allocation Stall (WorkerExecutorService thread for WorkerAsyncPool-52)
>> > 0.029ms
>> > [2022-02-02T00:00:49.989+0000][100082.651s][info ][gc ]
>> > Allocation Stall (WorkerExecutorService thread for WorkerAsyncPool-45)
>> > 0.894ms
>> > [2022-02-02T00:00:49.989+0000][100082.651s][info ][gc ]
>> > Allocation Stall (WorkerExecutorService thread for WorkerAsyncPool-63)
>> > 0.214ms
>> > [2022-02-02T00:00:49.989+0000][100082.651s][info ][gc ]
>> > Allocation Stall (WorkerExecutorService thread for WorkerAsyncPool-59)
>> > 0.401ms*
>> > [2022-02-02T00:00:49.998+0000][100082.660s][debug][gc,task ]
>> > GC(7968) Executing Task: ZRelocationSetInstallTask, Active Workers: 2
>> >
>> > My thought was if it had used more threads and finished the Concurrent
>> > Mark phase quickly it might not have ended up in the Allocation Stall.
>> >
>> > 1. Do you think removing the dynamic number of threads might help in
>> > this case?
>> > 2. Is there something that can be optimized in work allocation?
>>
>> It looks like the heuristics doesn't get things completely right here,
>> and uses too few threads. You can try using
>> -XX:-UseDynamicNumberOfGCThreads to always use all threads.
>>
>> Alternatively, you can also play with -XX:SoftMaxHeapSize to give
>> yourself more headroom to avoid allocation stalls.
>>
>> Finally, you could also play with -XX:ZAllocationSpikeTolerance, to make
>> the heuristics more defensive in case the allocation rate is spiky.
>>
>> As a side note, in the future we will be able to resize the number of
>> worker threads we use while the GC is running. E.g. if we pick 2 and in
>> the middle of the GC cycle see that it's too few, we can increase the
>> number of threads on the fly.
>>
>> cheers,
>> Per
>>
>> >
>> >
>> > Thanks
>> > Sundar
>> >
>> >
>> > On Mon, Jan 31, 2022 at 12:37 AM Per Liden <per.liden at oracle.com
>> > <mailto:per.liden at oracle.com>> wrote:
>> >
>> > Hi,
>> >
>> > It's hard to tell without seeing the complete GC log, but I suspect
>> > that
>> > the heuristics just picks different number of threads here. The
>> > heuristics will pick the number of threads currently needed, based
>> on
>> > available memory, allocation rate, etc. Each GC cycle will print
>> "Using
>> > XX workers" in the log. I wrote about this feature in my latest blog
>> > post under "Dynamic Number of GC Threads"
>> > (https://malloc.se/blog/zgc-jdk17 <https://malloc.se/blog/zgc-jdk17
>> >).
>> >
>> > cheers,
>> > Per
>> >
>> > On 1/27/22 20:20, Sundara Mohan M wrote:
>> > > Adding complete log of that phase in case if it helps
>> > > -01-27T18:51:41.121+0000][34725.483s][info ][gc,phases ]
>> > GC(2927) Pause
>> > > Mark Start 0.046ms
>> > > [2022-01-27T18:51:41.121+0000][34725.483s][info ][safepoint ]
>> > Safepoint
>> > > "ZMarkStart", Time since last: 8392610571 ns, Reaching safepoint:
>> > 606586
>> > > ns, At safepoint: 438685 ns, Total: 1045271 ns
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#11) 0.000ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#8) 0.102ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#0) 0.110ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#2) 0.062ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#9) 0.183ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#13) 0.209ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#6) 0.001ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#1) 0.098ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#12) 0.109ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#5) 0.112ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#17) 0.000ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#15) 0.103ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#16) 0.147ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#7) 0.067ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#4) 0.143ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#10) 0.048ms
>> > > [2022-01-27T18:51:41.134+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#3) 0.057ms
>> > > [2022-01-27T18:51:41.135+0000][34725.496s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots OopStorageSet (ZWorker#14) 0.249ms
>> > > [2022-01-27T18:51:41.139+0000][34725.500s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#5) 4.032ms
>> > > [2022-01-27T18:51:41.139+0000][34725.500s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#16) 3.921ms
>> > > [2022-01-27T18:51:41.139+0000][34725.500s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#7) 3.888ms
>> > > [2022-01-27T18:51:41.139+0000][34725.500s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#3) 3.685ms
>> > > [2022-01-27T18:51:41.139+0000][34725.500s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#4) 3.857ms
>> > > [2022-01-27T18:51:41.139+0000][34725.500s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#10) 3.725ms
>> > > [2022-01-27T18:51:41.139+0000][34725.500s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#12) 4.064ms
>> > > [2022-01-27T18:51:41.139+0000][34725.500s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#6) 4.137ms
>> > > [2022-01-27T18:51:41.139+0000][34725.500s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#17) 3.998ms
>> > > [2022-01-27T18:51:41.139+0000][34725.500s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#0) 4.301ms
>> > > [2022-01-27T18:51:41.139+0000][34725.500s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#8) 4.335ms
>> > > [2022-01-27T18:51:41.139+0000][34725.500s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#14) 3.658ms
>> > > [2022-01-27T18:51:41.139+0000][34725.500s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#15) 3.966ms
>> > > [2022-01-27T18:51:41.139+0000][34725.500s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#13) 4.267ms
>> > > [2022-01-27T18:51:41.139+0000][34725.501s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#1) 4.165ms
>> > > [2022-01-27T18:51:41.139+0000][34725.501s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#2) 4.619ms
>> > > [2022-01-27T18:51:41.140+0000][34725.502s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#9) 5.835ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#7) 4.247ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#3) 4.243ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#6) 4.168ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#17) 4.091ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#9) 2.713ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#10) 4.187ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#0) 4.071ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#2) 3.897ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#16) 4.277ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#5) 4.319ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#4) 4.231ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#15) 3.997ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#13) 3.983ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#14) 4.049ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#1) 3.968ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#8) 4.092ms
>> > > [2022-01-27T18:51:41.143+0000][34725.505s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots JavaThreads (ZWorker#12) 4.155ms
>> > > [2022-01-27T18:51:41.148+0000][34725.510s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#11) 13.665ms
>> > > [2022-01-27T18:51:41.174+0000][34725.535s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#12) 28.078ms
>> > > [2022-01-27T18:51:41.174+0000][34725.536s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#0) 30.133ms
>> > > [2022-01-27T18:51:41.174+0000][34725.535s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#3) 30.557ms
>> > > [2022-01-27T18:51:41.174+0000][34725.535s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#13) 29.600ms
>> > > [2022-01-27T18:51:41.174+0000][34725.535s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#5) 29.829ms
>> > > [2022-01-27T18:51:41.174+0000][34725.535s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#9) 30.148ms
>> > > [2022-01-27T18:51:41.174+0000][34725.535s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#10) 30.083ms
>> > > [2022-01-27T18:51:41.174+0000][34725.535s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#15) 29.707ms
>> > > [2022-01-27T18:51:41.174+0000][34725.535s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#7) 30.647ms
>> > > [2022-01-27T18:51:41.174+0000][34725.535s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#4) 29.814ms
>> > > [2022-01-27T18:51:41.174+0000][34725.535s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#8) 29.350ms
>> > > [2022-01-27T18:51:41.174+0000][34725.536s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#14) 29.569ms
>> > > [2022-01-27T18:51:41.174+0000][34725.536s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#1) 29.496ms
>> > > [2022-01-27T18:51:41.174+0000][34725.535s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#17) 30.227ms
>> > > [2022-01-27T18:51:41.174+0000][34725.536s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#6) 30.641ms
>> > > [2022-01-27T18:51:41.174+0000][34725.536s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#16) 29.984ms
>> > > [2022-01-27T18:51:41.174+0000][34725.536s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#2) 30.087ms
>> > > [2022-01-27T18:51:41.174+0000][34725.535s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Roots CodeCache (ZWorker#11) 25.501ms
>> > > [2022-01-27T18:51:41.319+0000][34725.681s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#9) 1.061ms
>> > > [2022-01-27T18:51:41.319+0000][34725.681s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#6) 1.062ms
>> > > [2022-01-27T18:51:41.319+0000][34725.681s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#15) 1.060ms
>> > > [2022-01-27T18:51:41.319+0000][34725.681s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#16) 1.061ms
>> > > [2022-01-27T18:51:41.319+0000][34725.681s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#3) 1.065ms
>> > > [2022-01-27T18:51:41.319+0000][34725.681s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#5) 1.061ms
>> > > [2022-01-27T18:51:41.320+0000][34725.681s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Flush (ZWorker#12) 1.921ms
>> > > [2022-01-27T18:51:41.322+0000][34725.684s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#9) 1.061ms
>> > > [2022-01-27T18:51:41.322+0000][34725.684s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#8) 1.062ms
>> > > [2022-01-27T18:51:41.322+0000][34725.684s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#1) 1.063ms
>> > > [2022-01-27T18:51:41.322+0000][34725.684s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#13) 1.059ms
>> > > [2022-01-27T18:51:41.322+0000][34725.684s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#14) 1.066ms
>> > > [2022-01-27T18:51:41.322+0000][34725.684s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#7) 1.065ms
>> > > [2022-01-27T18:51:41.322+0000][34725.684s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#16) 1.061ms
>> > > [2022-01-27T18:51:41.322+0000][34725.684s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#15) 1.063ms
>> > > [2022-01-27T18:51:41.323+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#5) 1.061ms
>> > > [2022-01-27T18:51:41.323+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#9) 1.057ms
>> > > [2022-01-27T18:51:41.323+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Flush (ZWorker#12) 0.743ms
>> > > [2022-01-27T18:51:41.323+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#0) 1.061ms
>> > > [2022-01-27T18:51:41.324+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#14) 1.057ms
>> > > [2022-01-27T18:51:41.324+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#8) 1.060ms
>> > > [2022-01-27T18:51:41.324+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#6) 1.059ms
>> > > [2022-01-27T18:51:41.324+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#17) 1.061ms
>> > > [2022-01-27T18:51:41.324+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#11) 1.063ms
>> > > [2022-01-27T18:51:41.324+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#13) 1.063ms
>> > > [2022-01-27T18:51:41.324+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#2) 1.058ms
>> > > [2022-01-27T18:51:41.324+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#3) 1.061ms
>> > > [2022-01-27T18:51:41.324+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#7) 1.060ms
>> > > [2022-01-27T18:51:41.324+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Flush (ZWorker#12) 0.356ms
>> > > [2022-01-27T18:51:41.324+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#4) 1.061ms
>> > > [2022-01-27T18:51:41.324+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#15) 1.059ms
>> > > [2022-01-27T18:51:41.324+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#10) 1.060ms
>> > > [2022-01-27T18:51:41.324+0000][34725.685s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#16) 1.060ms
>> > > [2022-01-27T18:51:41.324+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#1) 1.060ms
>> > > [2022-01-27T18:51:41.324+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Flush (ZWorker#12) 0.311ms
>> > > [2022-01-27T18:51:41.324+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#9) 1.060ms
>> > > [2022-01-27T18:51:41.324+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#5) 1.058ms
>> > > [2022-01-27T18:51:41.324+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Flush (ZWorker#12) 0.285ms
>> > > [2022-01-27T18:51:41.324+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#12) 0.297ms
>> > > [2022-01-27T18:51:41.324+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#12) 0.000ms
>> > > [2022-01-27T18:51:41.324+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#12) 150.092ms
>> > > [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#0) 1.059ms
>> > > [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#0) 150.279ms
>> > > [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#14) 1.055ms
>> > > [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#14) 149.355ms
>> > > [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#8) 1.060ms
>> > > [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#8) 150.312ms
>> > > [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#6) 1.060ms
>> > > [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#6) 150.323ms
>> > > [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#17) 1.062ms
>> > > [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#11) 1.058ms
>> > > [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#13) 1.060ms
>> > > [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#2) 1.059ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#2) 150.423ms
>> > > [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#13) 150.437ms
>> > > [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#11) 150.374ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#3) 1.061ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#3) 150.537ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#7) 1.061ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#7) 150.550ms
>> > > [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#17) 150.364ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#15) 1.056ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#16) 1.059ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#1) 1.060ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#1) 150.613ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#4) 1.064ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#16) 150.584ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#10) 1.059ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#10) 150.706ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#4) 150.629ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#15) 150.601ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#9) 1.028ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#9) 150.938ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Try Terminate (ZWorker#5) 1.057ms
>> > > [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark (ZWorker#5) 151.063ms
>> > > *[2022-01-27T18:51:41.325+0000][34725.687s][info ][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark 204.119ms*
>> > > [2022-01-27T18:51:41.326+0000][34725.688s][info ][gc,phases ]
>> > GC(2927)
>> > > Pause Mark End 0.070ms
>> > > [2022-01-27T18:51:41.326+0000][34725.688s][info ][safepoint ]
>> > Safepoint
>> > > "ZMarkEnd", Time since last: 204207403 ns, Reaching safepoint:
>> > 210401 ns,
>> > > At safepoint: 237941 ns, Total: 448342 ns
>> > > [2022-01-27T18:51:41.326+0000][34725.688s][info ][gc,phases ]
>> > GC(2927)
>> > > Concurrent Mark Free 0.001ms
>> > > [2022-01-27T18:51:41.327+0000][34725.688s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent References Process (ZDriver) 0.738ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#13) 3.344ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#4) 3.354ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#8) 3.366ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#0) 3.328ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#11) 3.365ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#14) 3.336ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#5) 3.362ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#1) 3.354ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#9) 3.351ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#3) 3.328ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#17) 3.333ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#10) 3.334ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#2) 3.345ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#7) 3.338ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#6) 3.329ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#15) 3.350ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#16) 3.366ms
>> > > [2022-01-27T18:51:41.330+0000][34725.692s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#12) 3.370ms
>> > > [2022-01-27T18:51:41.331+0000][34725.693s][debug][gc,phases ]
>> > GC(2927)
>> > > Concurrent References Enqueue (ZDriver) 0.011ms
>> > > [2022-01-27T18:51:41.331+0000][34725.693s][info ][gc,phases ]
>> > GC(2927)
>> > > Concurrent Process Non-Strong References 5.192ms
>> > > [2022-01-27T18:51:41.333+0000][34725.695s][info ][gc,phases ]
>> > GC(2927)
>> > > Concurrent Reset Relocation Set 2.186ms
>> > > [2022-01-27T18:51:41.349+0000][34725.711s][info ][gc,phases ]
>> > GC(2927)
>> > > Concurrent Select Relocation Set 15.721ms
>> > > [2022-01-27T18:51:41.350+0000][34725.711s][info ][gc,phases ]
>> > GC(2927)
>> > > Pause Relocate Start 0.016ms
>> > > [2022-01-27T18:51:41.350+0000][34725.712s][info ][safepoint ]
>> > Safepoint
>> > > "ZRelocateStart", Time since last: 23235346 ns, Reaching
>> > safepoint: 315064
>> > > ns, At safepoint: 290299 ns, Total: 605363 ns
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,phases ]
>> > GC(2927)
>> > > Concurrent Relocate 19.017ms
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,marking ]
>> > GC(2927)
>> > > Mark: 16 stripe(s), 4 proactive flush(es), 1 terminate
>> flush(es), 0
>> > > completion(s), 0 continuation(s)
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,marking ]
>> > GC(2927)
>> > > Mark Stack Usage: 32M
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,metaspace]
>> > GC(2927)
>> > > Metaspace: 169M used, 178M committed, 1184M reserved
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,ref ]
>> > GC(2927)
>> > > Soft: 40709 encountered, 0 discovered, 0 enqueued
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,ref ]
>> > GC(2927)
>> > > Weak: 33476 encountered, 7667 discovered, 4604 enqueued
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,ref ]
>> > GC(2927)
>> > > Final: 415 encountered, 0 discovered, 0 enqueued
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,ref ]
>> > GC(2927)
>> > > Phantom: 5155 encountered, 3828 discovered, 205 enqueued
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,reloc ]
>> > GC(2927)
>> > > Small Pages: 23233 / 46466M, Empty: 17842M, Relocated: 61M,
>> > In-Place: 0
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,reloc ]
>> > GC(2927)
>> > > Medium Pages: 161 / 5152M, Empty: 5056M, Relocated: 9M,
>> In-Place: 0
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,reloc ]
>> > GC(2927)
>> > > Large Pages: 0 / 0M, Empty: 0M, Relocated: 0M, In-Place: 0
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,reloc ]
>> > GC(2927)
>> > > Forwarding Usage: 13M
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,heap ]
>> > GC(2927)
>> > > Min Capacity: 64000M(100%)
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,heap ]
>> > GC(2927)
>> > > Max Capacity: 64000M(100%)
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,heap ]
>> > GC(2927)
>> > > Soft Max Capacity: 64000M(100%)
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,heap ]
>> > GC(2927)
>> > > Mark Start Mark End Relocate Start
>> > > Relocate End High Low
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,heap ]
>> > GC(2927)
>> > > Capacity: 64000M (100%) 64000M (100%) 64000M
>> (100%)
>> > > 64000M (100%) 64000M (100%) 64000M (100%)
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,heap ]
>> > GC(2927)
>> > > Free: 12382M (19%) 11392M (18%) 34172M (53%)
>> > 61184M
>> > > (96%) 61184M (96%) 11326M (18%)
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,heap ]
>> > GC(2927)
>> > > Used: 51618M (81%) 52608M (82%) 29828M (47%)
>> > 2816M
>> > > (4%) 52674M (82%) 2816M (4%)
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,heap ]
>> > GC(2927)
>> > > Live: - 1303M (2%) 1303M (2%)
>> > 1303M
>> > > (2%) - -
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,heap ]
>> > GC(2927)
>> > > Allocated: - 990M (2%) 1108M (2%)
>> > > 1195M (2%) - -
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,heap ]
>> > GC(2927)
>> > > Garbage: - 50314M (79%) 27416M (43%)
>> > 316M
>> > > (0%) - -
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc,heap ]
>> > GC(2927)
>> > > Reclaimed: - - 22898M (36%)
>> > > 49997M (78%) - -
>> > > [2022-01-27T18:51:41.369+0000][34725.731s][info ][gc ]
>> > GC(2927)
>> > > Garbage Collection (Proactive) 51618M(81%)->2816M(4%)
>> > > [2022-01-27T18:51:51.319+0000][34735.681s][info ][gc,start ]
>> > GC(2928)
>> > > Garbage Collection (Allocation Rate)
>> > > [2022-01-27T18:51:51.321+0000][34735.682s][info ][gc,phases ]
>> > GC(2928)
>> > > Pause Mark Start 0.042ms
>> > > [2022-01-27T18:51:51.321+0000][34735.683s][info ][safepoint ]
>> > Safepoint
>> > > "ZMarkStart", Time since last: 9969777477 ns, Reaching safepoint:
>> > 887200
>> > > ns, At safepoint: 523517 ns, Total: 1410717 ns
>> > > [2022-01-27T18:51:51.334+0000][34735.696s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Roots OopStorageSet (ZWorker#17) 0.542ms
>> > > [2022-01-27T18:51:51.334+0000][34735.696s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Roots OopStorageSet (ZWorker#10) 0.575ms
>> > > [2022-01-27T18:51:51.343+0000][34735.705s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#17) 9.161ms
>> > > [2022-01-27T18:51:51.344+0000][34735.706s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#10) 9.817ms
>> > > [2022-01-27T18:51:51.351+0000][34735.713s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Roots JavaThreads (ZWorker#10) 7.569ms
>> > > [2022-01-27T18:51:51.351+0000][34735.713s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Roots JavaThreads (ZWorker#17) 8.243ms
>> > > [2022-01-27T18:51:51.407+0000][34735.769s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Roots CodeCache (ZWorker#17) 55.952ms
>> > > [2022-01-27T18:51:51.407+0000][34735.769s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Roots CodeCache (ZWorker#10) 55.988ms
>> > > [2022-01-27T18:51:52.336+0000][34736.698s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Mark Try Terminate (ZWorker#14) 1.064ms
>> > > [2022-01-27T18:51:52.337+0000][34736.699s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Mark Try Flush (ZWorker#12) 2.343ms
>> > > [2022-01-27T18:51:52.342+0000][34736.703s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Mark Try Flush (ZWorker#12) 0.685ms
>> > > [2022-01-27T18:51:52.342+0000][34736.704s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Mark Try Flush (ZWorker#12) 0.294ms
>> > > [2022-01-27T18:51:52.342+0000][34736.704s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Mark Try Terminate (ZWorker#12) 0.320ms
>> > > [2022-01-27T18:51:52.342+0000][34736.704s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Mark Try Terminate (ZWorker#12) 0.000ms
>> > > [2022-01-27T18:51:52.342+0000][34736.704s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Mark (ZWorker#12) 934.304ms
>> > > [2022-01-27T18:51:52.342+0000][34736.704s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Mark Try Terminate (ZWorker#14) 1.062ms
>> > > [2022-01-27T18:51:52.342+0000][34736.704s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Mark (ZWorker#14) 934.339ms
>> > >
>> > > *[2022-01-27T18:51:52.342+0000][34736.704s][info ][gc,phases ]
>> > GC(2928)
>> > > Concurrent Mark
>> > 1021.048ms*[2022-01-27T18:51:52.342+0000][34736.704s][info
>> > > ][gc,phases ] GC(2928) Pause Mark End 0.095ms
>> > > [2022-01-27T18:51:52.343+0000][34736.704s][info ][safepoint ]
>> > Safepoint
>> > > "ZMarkEnd", Time since last: 1021138351 ns, Reaching safepoint:
>> > 256951 ns,
>> > > At safepoint: 333825 ns, Total: 590776 ns
>> > > [2022-01-27T18:51:52.343+0000][34736.704s][info ][gc,phases ]
>> > GC(2928)
>> > > Concurrent Mark Free 0.001ms
>> > > [2022-01-27T18:51:52.345+0000][34736.707s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent References Process (ZDriver) 2.019ms
>> > > [2022-01-27T18:51:52.364+0000][34736.726s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#13) 19.096ms
>> > > [2022-01-27T18:51:52.364+0000][34736.726s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#7) 19.068ms
>> > > [2022-01-27T18:51:52.365+0000][34736.727s][debug][gc,phases ]
>> > GC(2928)
>> > > Concurrent References Enqueue (ZDriver) 0.010ms
>> > > [2022-01-27T18:51:52.365+0000][34736.727s][info ][gc,phases ]
>> > GC(2928)
>> > > Concurrent Process Non-Strong References 22.133ms
>> > > [2022-01-27T18:51:52.368+0000][34736.730s][info ][gc,phases ]
>> > GC(2928)
>> > > Concurrent Reset Relocation Set 2.875ms
>> > > [2022-01-27T18:51:52.384+0000][34736.745s][info ][gc,phases ]
>> > GC(2928)
>> > > Concurrent Select Relocation Set 15.834ms
>> > > [2022-01-27T18:51:52.384+0000][34736.746s][info ][gc,phases ]
>> > GC(2928)
>> > > Pause Relocate Start 0.015ms
>> > > [2022-01-27T18:51:52.384+0000][34736.746s][info ][safepoint ]
>> > Safepoint
>> > > "ZRelocateStart", Time since last: 41003214 ns, Reaching
>> > safepoint: 303280
>> > > ns, At safepoint: 155476 ns, Total: 458756 ns
>> > > [2022-01-27T18:51:52.445+0000][34736.806s][info ][gc,phases ]
>> > GC(2928)
>> > > Concurrent Relocate 60.419ms
>> > > [2022-01-27T18:51:52.445+0000][34736.806s][info ][gc,marking ]
>> > GC(2928)
>> > > Mark: 2 stripe(s), 2 proactive flush(es), 1 terminate flush(es),
>> 0
>> > > completion(s), 0 continuation(s)
>> > > [2022-01-27T18:51:52.445+0000][34736.806s][info ][gc,marking ]
>> > GC(2928)
>> > > Mark Stack Usage: 32M
>> > > [2022-01-27T18:51:52.445+0000][34736.806s][info ][gc,metaspace]
>> > GC(2928)
>> > > Metaspace: 169M used, 178M committed, 1184M reserved
>> > > [2022-01-27T18:51:52.445+0000][34736.806s][info ][gc,ref ]
>> > GC(2928)
>> > > Soft: 40719 encountered, 0 discovered, 0 enqueued
>> > > [2022-01-27T18:51:52.445+0000][34736.806s][info ][gc,ref ]
>> > GC(2928)
>> > > Weak: 33189 encountered, 9016 discovered, 4318 enqueued
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,ref ]
>> > GC(2928)
>> > > Final: 795 encountered, 387 discovered, 380 enqueued
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,ref ]
>> > GC(2928)
>> > > Phantom: 5175 encountered, 3937 discovered, 219 enqueued
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,reloc ]
>> > GC(2928)
>> > > Small Pages: 20919 / 41838M, Empty: 15862M, Relocated: 87M,
>> > In-Place: 0
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,reloc ]
>> > GC(2928)
>> > > Medium Pages: 130 / 4160M, Empty: 4064M, Relocated: 11M,
>> In-Place: 0
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,reloc ]
>> > GC(2928)
>> > > Large Pages: 20 / 128M, Empty: 128M, Relocated: 0M, In-Place: 0
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,reloc ]
>> > GC(2928)
>> > > Forwarding Usage: 19M
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,heap ]
>> > GC(2928)
>> > > Min Capacity: 64000M(100%)
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,heap ]
>> > GC(2928)
>> > > Max Capacity: 64000M(100%)
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,heap ]
>> > GC(2928)
>> > > Soft Max Capacity: 64000M(100%)
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,heap ]
>> > GC(2928)
>> > > Mark Start Mark End Relocate Start
>> > > Relocate End High Low
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,heap ]
>> > GC(2928)
>> > > Capacity: 64000M (100%) 64000M (100%) 64000M
>> (100%)
>> > > 64000M (100%) 64000M (100%) 64000M (100%)
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,heap ]
>> > GC(2928)
>> > > Free: 17874M (28%) 13228M (21%) 33154M (52%)
>> > 57394M
>> > > (90%) 57434M (90%) 13142M (21%)
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,heap ]
>> > GC(2928)
>> > > Used: 46126M (72%) 50772M (79%) 30846M (48%)
>> > 6606M
>> > > (10%) 50858M (79%) 6566M (10%)
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,heap ]
>> > GC(2928)
>> > > Live: - 1301M (2%) 1301M (2%)
>> > 1301M
>> > > (2%) - -
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,heap ]
>> > GC(2928)
>> > > Allocated: - 4646M (7%) 4774M (7%)
>> > > 5004M (8%) - -
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,heap ]
>> > GC(2928)
>> > > Garbage: - 44824M (70%) 24770M (39%)
>> > 299M
>> > > (0%) - -
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc,heap ]
>> > GC(2928)
>> > > Reclaimed: - - 20054M (31%)
>> > > 44524M (70%) - -
>> > > [2022-01-27T18:51:52.445+0000][34736.807s][info ][gc ]
>> > GC(2928)
>> > > Garbage Collection (Allocation Rate) 46126M(72%)->6606M(10%)
>> > > [2022-01-27T18:52:00.820+0000][34745.182s][info ][gc,start ]
>> > GC(2929)
>> > > Garbage Collection (Allocation Rate)
>> > > [2022-01-27T18:52:00.821+0000][34745.183s][info ][gc,phases ]
>> > GC(2929)
>> > > Pause Mark Start 0.057ms
>> > > [2022-01-27T18:52:00.822+0000][34745.184s][info ][safepoint ]
>> > Safepoint
>> > > "ZMarkStart", Time since last: 8436197260 ns, Reaching safepoint:
>> > 1019671
>> > > ns, At safepoint: 515965 ns, Total: 1535636 ns
>> > > [2022-01-27T18:52:00.835+0000][34745.197s][debug][gc,phases ]
>> > GC(2929)
>> > > Concurrent Roots OopStorageSet (ZWorker#5) 0.991ms
>> > > [2022-01-27T18:52:00.851+0000][34745.213s][debug][gc,phases ]
>> > GC(2929)
>> > > Concurrent Roots ClassLoaderDataGraph (ZWorker#5) 15.777ms
>> > > [2022-01-27T18:52:00.864+0000][34745.226s][debug][gc,phases ]
>> > GC(2929)
>> > > Concurrent Roots JavaThreads (ZWorker#5) 12.769ms
>> > > [2022-01-27T18:52:00.945+0000][34745.307s][debug][gc,phases ]
>> > GC(2929)
>> > > Concurrent Roots CodeCache (ZWorker#5) 81.380ms
>> > > [2022-01-27T18:52:02.766+0000][34747.127s][debug][gc,phases ]
>> > GC(2929)
>> > > Concurrent Mark Try Flush (ZWorker#16) 1.613ms
>> > > [2022-01-27T18:52:02.771+0000][34747.133s][debug][gc,phases ]
>> > GC(2929)
>> > > Concurrent Mark Try Flush (ZWorker#16) 0.717ms
>> > > [2022-01-27T18:52:02.771+0000][34747.133s][debug][gc,phases ]
>> > GC(2929)
>> > > Concurrent Mark Try Flush (ZWorker#16) 0.292ms
>> > > [2022-01-27T18:52:02.771+0000][34747.133s][debug][gc,phases ]
>> > GC(2929)
>> > > Concurrent Mark Try Terminate (ZWorker#16) 0.306ms
>> > > [2022-01-27T18:52:02.771+0000][34747.133s][debug][gc,phases ]
>> > GC(2929)
>> > > Concurrent Mark Try Terminate (ZWorker#16) 0.000ms
>> > > [2022-01-27T18:52:02.771+0000][34747.133s][debug][gc,phases ]
>> > GC(2929)
>> > > Concurrent Mark (ZWorker#16) 1825.719ms
>> > >
>> > > *[2022-01-27T18:52:02.771+0000][34747.133s][info ][gc,phases ]
>> > GC(2929)
>> > > Concurrent Mark
>> > 1949.325ms*[2022-01-27T18:52:02.774+0000][34747.136s][info
>> > > ][gc,phases ] GC(2929) Pause Mark End 0.212ms
>> > > [2022-01-27T18:52:02.775+0000][34747.136s][info ][safepoint ]
>> > Safepoint
>> > > "ZMarkEnd", Time since last: 1949455739 ns, Reaching safepoint:
>> > 2536816 ns,
>> > > At safepoint: 606241 ns, Total: 3143057 ns
>> > > [2022-01-27T18:52:02.775+0000][34747.136s][info ][gc,phases ]
>> > GC(2929)
>> > > Concurrent Mark Free 0.001ms
>> > > [2022-01-27T18:52:02.778+0000][34747.139s][debug][gc,phases ]
>> > GC(2929)
>> > > Concurrent References Process (ZDriver) 3.161ms
>> > > [2022-01-27T18:52:02.813+0000][34747.175s][debug][gc,phases ]
>> > GC(2929)
>> > > Concurrent Weak Roots OopStorageSet (ZWorker#4) 35.717ms
>> > > [2022-01-27T18:52:02.814+0000][34747.176s][debug][gc,phases ]
>> > GC(2929)
>> > > Concurrent References Enqueue (ZDriver) 0.007ms
>> > > [2022-01-27T18:52:02.814+0000][34747.176s][info ][gc,phases ]
>> > GC(2929)
>> > > Concurrent Process Non-Strong References 39.943ms
>> > > [2022-01-27T18:52:02.818+0000][34747.180s][info ][gc,phases ]
>> > GC(2929)
>> > > Concurrent Reset Relocation Set 3.587ms
>> > > [2022-01-27T18:52:02.833+0000][34747.195s][info ][gc,phases ]
>> > GC(2929)
>> > > Concurrent Select Relocation Set 15.208ms
>> > > [2022-01-27T18:52:02.834+0000][34747.195s][info ][gc,phases ]
>> > GC(2929)
>> > > Pause Relocate Start 0.017ms
>> > > [2022-01-27T18:52:02.834+0000][34747.196s][info ][safepoint ]
>> > Safepoint
>> > > "ZRelocateStart", Time since last: 58881245 ns, Reaching
>> > safepoint: 286775
>> > > ns, At safepoint: 232929 ns, Total: 519704 ns
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,phases ]
>> > GC(2929)
>> > > Concurrent Relocate 107.558ms
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,marking ]
>> > GC(2929)
>> > > Mark: 1 stripe(s), 2 proactive flush(es), 1 terminate flush(es),
>> 0
>> > > completion(s), 0 continuation(s)
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,marking ]
>> > GC(2929)
>> > > Mark Stack Usage: 32M
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,metaspace]
>> > GC(2929)
>> > > Metaspace: 169M used, 178M committed, 1184M reserved
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,ref ]
>> > GC(2929)
>> > > Soft: 40717 encountered, 0 discovered, 0 enqueued
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,ref ]
>> > GC(2929)
>> > > Weak: 32517 encountered, 8597 discovered, 3652 enqueued
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,ref ]
>> > GC(2929)
>> > > Final: 415 encountered, 6 discovered, 0 enqueued
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,ref ]
>> > GC(2929)
>> > > Phantom: 5031 encountered, 3633 discovered, 77 enqueued
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,reloc ]
>> > GC(2929)
>> > > Small Pages: 18075 / 36150M, Empty: 12846M, Relocated: 76M,
>> > In-Place: 0
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,reloc ]
>> > GC(2929)
>> > > Medium Pages: 117 / 3744M, Empty: 3584M, Relocated: 10M,
>> In-Place: 0
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,reloc ]
>> > GC(2929)
>> > > Large Pages: 16 / 104M, Empty: 104M, Relocated: 0M, In-Place: 0
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,reloc ]
>> > GC(2929)
>> > > Forwarding Usage: 15M
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,heap ]
>> > GC(2929)
>> > > Min Capacity: 64000M(100%)
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,heap ]
>> > GC(2929)
>> > > Max Capacity: 64000M(100%)
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,heap ]
>> > GC(2929)
>> > > Soft Max Capacity: 64000M(100%)
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,heap ]
>> > GC(2929)
>> > > Mark Start Mark End Relocate Start
>> > > Relocate End High Low
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,heap ]
>> > GC(2929)
>> > > Capacity: 64000M (100%) 64000M (100%) 64000M
>> (100%)
>> > > 64000M (100%) 64000M (100%) 64000M (100%)
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,heap ]
>> > GC(2929)
>> > > Free: 24002M (38%) 15544M (24%) 31836M (50%)
>> > 53224M
>> > > (83%) 53414M (83%) 15410M (24%)
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,heap ]
>> > GC(2929)
>> > > Used: 39998M (62%) 48456M (76%) 32164M (50%)
>> > 10776M
>> > > (17%) 48590M (76%) 10586M (17%)
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,heap ]
>> > GC(2929)
>> > > Live: - 1283M (2%) 1283M (2%)
>> > 1283M
>> > > (2%) - -
>> > > [2022-01-27T18:52:02.942+0000][34747.303s][info ][gc,heap ]
>> > GC(2929)
>> > > Allocated: - 8458M (13%) 8700M (14%)
>> > > 9205M (14%) - -
>> > > [2022-01-27T18:52:02.942+0000][34747.304s][info ][gc,heap ]
>> > GC(2929)
>> > > Garbage: - 38714M (60%) 22180M (35%)
>> > 286M
>> > > (0%) - -
>> > > [2022-01-27T18:52:02.942+0000][34747.304s][info ][gc,heap ]
>> > GC(2929)
>> > > Reclaimed: - - 16534M (26%)
>> > > 38427M (60%) - -
>> > > [2022-01-27T18:52:02.942+0000][34747.304s][info ][gc ]
>> > GC(2929)
>> > > Garbage Collection (Allocation Rate) 39998M(62%)->10776M(17%)
>> > >
>> > >
>> > > Thanks
>> > > Sundar
>> > >
>> > >
>> > > On Thu, Jan 27, 2022 at 11:00 AM Sundara Mohan M
>> > <m.sundar85 at gmail.com <mailto:m.sundar85 at gmail.com>>
>> > > wrote:
>> > >
>> > >> Hi,
>> > >> We are using ZGC in production environment with following
>> > settings
>> > >> *[2022-01-27T09:12:55.684+0000][0.046s][info][gc,init] Version:
>> > 17.0.1+12
>> > >> (release)*
>> > >> ..
>> > >> *[2022-01-27T09:12:55.684+0000][0.046s][info][gc,init] GC
>> > Workers: 18
>> > >> (dynamic)*
>> > >> ...
>> > >> [2022-01-27T09:12:55.686+0000][0.048s][info][gc,init] Min
>> > Capacity: 64000M
>> > >> [2022-01-27T09:12:55.686+0000][0.048s][info][gc,init] Initial
>> > Capacity:
>> > >> 64000M
>> > >> *[2022-01-27T09:12:55.686+0000][0.048s][info][gc,init] Max
>> Capacity:
>> > >> 64000M*
>> > >> [2022-01-27T09:12:55.686+0000][0.048s][info][gc,init] Medium
>> > Page Size: 32M
>> > >> [2022-01-27T09:12:55.686+0000][0.048s][info][gc,init] Pre-touch:
>> > Disabled
>> > >> [2022-01-27T09:12:55.686+0000][0.048s][info][gc,init] Available
>> > space on
>> > >> backing filesystem: N/A
>> > >> [2022-01-27T09:12:55.686+0000][0.048s][info][gc,init] Uncommit:
>> > Implicitly
>> > >> Disabled (-Xms equals -Xmx)
>> > >> *[2022-01-27T09:13:05.275+0000][9.636s][info][gc,init] Runtime
>> > Workers: 44*
>> > >> [2022-01-27T09:13:05.278+0000][9.640s][info][gc ] Using The
>> > Z Garbage
>> > >> Collector
>> > >>
>> > >> We run into GC cycle every 8-10 seconds. In some GC cycle
>> > Concurrent Mark
>> > >> phase is taking 2*s* and in some cycle it is taking 200*ms.*
>> > >>
>> > >> After enabling debug log for gc,phase saw in some cases more
>> > ZWorkers are
>> > >> doing work in other case it is given to only 1 or 2 ZWorker.
>> > >>
>> > >> Example log where work is done by multiple thread and took only
>> > 200ms
>> > >> [2022-01-27T18:51:41.324+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#12) 150.092ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#0) 1.059ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#0) 150.279ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#14) 1.055ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#14) 149.355ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#8) 1.060ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#8) 150.312ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#6) 1.060ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#6) 150.323ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#17) 1.062ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#11) 1.058ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#13) 1.060ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#2) 1.059ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#2) 150.423ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#13) 150.437ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#11) 150.374ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#3) 1.061ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#3) 150.537ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#7) 1.061ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#7) 150.550ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.686s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#17) 150.364ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#15) 1.056ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#16) 1.059ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#1) 1.060ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#1) 150.613ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#4) 1.064ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#16) 150.584ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#10) 1.059ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#10) 150.706ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#4) 150.629ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#15) 150.601ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#9) 1.028ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#9) 150.938ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark Try Terminate (ZWorker#5) 1.057ms
>> > >> [2022-01-27T18:51:41.325+0000][34725.687s][debug][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark (ZWorker#5) 151.063ms
>> > >> *[2022-01-27T18:51:41.325+0000][34725.687s][info ][gc,phases ]
>> > GC(2927)
>> > >> Concurrent Mark 204.119ms*
>> > >>
>> > >> Another case where it was run by only 1/2 worker and took 1/2s
>> > respectively
>> > >> ...
>> > >> *[2022-01-27T18:51:52.342+0000][34736.704s][debug][gc,phases ]
>> > GC(2928)
>> > >> Concurrent Mark (ZWorker#12) 934.304ms*
>> > >> [2022-01-27T18:51:52.342+0000][34736.704s][debug][gc,phases ]
>> > GC(2928)
>> > >> Concurrent Mark Try Terminate (ZWorker#14) 1.062ms
>> > >> *[2022-01-27T18:51:52.342+0000][34736.704s][debug][gc,phases ]
>> > GC(2928)
>> > >> Concurrent Mark (ZWorker#14) 934.339ms*
>> > >> *[2022-01-27T18:51:52.342+0000][34736.704s][info ][gc,phases ]
>> > GC(2928)
>> > >> Concurrent Mark 1021.048ms*
>> > >>
>> > >>
>> > >> [2022-01-27T18:52:00.822+0000][34745.184s][info ][safepoint ]
>> > Safepoint
>> > >> "ZMarkStart", Time since last: 8436197260 ns, Reaching
>> > safepoint: 1019671
>> > >> ns, At safepoint: 515965 ns, Total: 1
>> > >> 535636 ns
>> > >> [2022-01-27T18:52:00.835+0000][34745.197s][debug][gc,phases ]
>> > GC(2929)
>> > >> Concurrent Roots OopStorageSet (ZWorker#5) 0.991ms
>> > >> [2022-01-27T18:52:00.851+0000][34745.213s][debug][gc,phases ]
>> > GC(2929)
>> > >> Concurrent Roots ClassLoaderDataGraph (ZWorker#5) 15.777ms
>> > >> [2022-01-27T18:52:00.864+0000][34745.226s][debug][gc,phases ]
>> > GC(2929)
>> > >> Concurrent Roots JavaThreads (ZWorker#5) 12.769ms
>> > >> [2022-01-27T18:52:00.945+0000][34745.307s][debug][gc,phases ]
>> > GC(2929)
>> > >> Concurrent Roots CodeCache (ZWorker#5) 81.380ms
>> > >> [2022-01-27T18:52:02.766+0000][34747.127s][debug][gc,phases ]
>> > GC(2929)
>> > >> Concurrent Mark Try Flush (ZWorker#16) 1.613ms
>> > >> [2022-01-27T18:52:02.771+0000][34747.133s][debug][gc,phases ]
>> > GC(2929)
>> > >> Concurrent Mark Try Flush (ZWorker#16) 0.717ms
>> > >> [2022-01-27T18:52:02.771+0000][34747.133s][debug][gc,phases ]
>> > GC(2929)
>> > >> Concurrent Mark Try Flush (ZWorker#16) 0.292ms
>> > >> [2022-01-27T18:52:02.771+0000][34747.133s][debug][gc,phases ]
>> > GC(2929)
>> > >> Concurrent Mark Try Terminate (ZWorker#16) 0.306ms
>> > >> [2022-01-27T18:52:02.771+0000][34747.133s][debug][gc,phases ]
>> > GC(2929)
>> > >> Concurrent Mark Try Terminate (ZWorker#16) 0.000ms
>> > >>
>> > >>
>> > >> *[2022-01-27T18:52:02.771+0000][34747.133s][debug][gc,phases ]
>> > GC(2929)
>> > >> Concurrent Mark (ZWorker#16)
>> > >> 1825.719ms[2022-01-27T18:52:02.771+0000][34747.133s][info
>> > ][gc,phases ]
>> > >> GC(2929) Concurrent Mark 1949.325ms*
>> > >>
>> > >> Even though we have 18 threads, does anyone have any idea why
>> > the work is
>> > >> not distributed among multiple workers?
>> > >>
>> > >> Thanks
>> > >> Sundar
>> > >>
>> > >>
>> >
>>
>
More information about the zgc-dev
mailing list