Java Performance Engineering: Tuning G1GC with the -XX:Max-GC-Pause-Time Parameter (Part 1)
G1GC is one of the key aspect for JVM Performance optimisation.
Before starting with tuning , we need to ask and clarify the objective.
What are we tuning it for :
Latency - For latency, goal is to have min GC pause time and max GC activity concurrently with application runtime.
or Throughput - whereas for throughput we may f the Pause time in favour of having a efficient GC cycles. Objective shall be to minimize GC overhead in terms of CPU cycles it consumes and threads it creates in JVM for GC purpose.
Little recap about GC pause time '-XX:MaxGCPauseTimeMillis'
G1GC provides a argument to limit max GC pause time. By default , it's value is 200ms.
Nevertheless, You may see this target getting violated frequently. It's a guidance to the G1GC not a guarantee to the user.
How it works:
On a high level, GC pause time targets have to be achieved in two manners:
Increasing the concurrent GC phases like Mark, Sweep and compaction. Which can be speed up by increasing the Parallel GC threads.
Adapting or running GC across a smaller set of Young regions.Running frequently to keep GC Pause time under target.
Focus on tuning with GC pause time
We carried out 4 experiments with different values of -XX:MaxGCPauseTimeMillis.
GCPause set from 200 ms to 1ms (which is unrealistic low for g1gc but achievable with Z1GC)
High Level comparison of G1GC tuning activities
GC pause targets achieved for target values of 200 ms and 50 ms
For 10 ms and 1 ms , GC targets missed as expected
But most surprising is the Heap utilisation while we set GCpauseTime to 1ms
Heap utilisation went up to 2.5 Gb for first 3 activity but went only to 250 Mb for 1 ms GcPauseTime target.
More interesting insights
Apart from above comparison, took note of few more insights while looking further into JVM Observability.
Heap utilisation :
Heap utilisation pattern remains similar for GCPauseTime of 200 ms , 50 ms and 10 ms but varied for 1 ms.
Heap utilisation went up to 2.5 Gb for first 3 activity but went only to 250 Mb for 1 ms GcPauseTime target.
GC cycle distribution:
GC count remains similar for GCPauseTime of 200 ms , 50 ms and 10 ms but varied for 1 ms.
GC count increased dramatically to 4x as compared to GC cycle count for 1 ms GcPauseTime target.
This could be understood as heap utilisation also decreased by 90% and probably, GC running frequently to achieve such aggressive gc pause time.
G1 region count:
We know , G1 GC divided heap into 2048 different regions instead of just 1 old and 1 young/eden area.
While looking at region count again significant difference observed between first 3 activities and last one with 1ms gcPauseTime.
Eden region decreased from 1219 to 109 only.
There could be much more to dig into it.
For now, I will keep it up to here and try to analyse it further in another blog.
Simplifying Performance Engineering
4moVery interesting observations have come out of this experiment. Keep it up! Which jdk flavour(vendor) and version you used btw? I believe at least the newer version should have slight differences due to optimization that has gone into g1gc algo.