ZGC Concurrent Mark Work distribution
Per Liden
per.liden at oracle.com
Wed Feb 2 12:26:31 UTC 2022
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