How to analyze GC Foot print Log and tune G1 GC property?

Hello Rakesh!

 I would like to share with you couple of pointers.

 a. Here is a talk that I gave on 'GC tuning & Troubleshooting' in JAX London conference. It can give you an good overview for beginners to get started on GC tuning.

 b. We had published a white paper 'Simple & Effective G1 Garbage Collector Tuning Tips', which can give insights on tuning G1 GC.  

Thanks for quick respose. 

Can you quickly give some tips based on the analysis, what particular setting we can change so that number of Full GC occurence come down as well as we can mitigate the long pauses.

Regards

Rakesh

Hi Rakesh,

1) Footprint is basically the amount CPU consumed. Based on your GC algorithm, memory settings, CPU consumption will vary. Some GC algorithms will consume more CPU (like Parallel, CMS), whereas other algorithms such as Serial will consume less CPU.

According to memory tuning Gurus, you can pick only 2 of them at a time.

• If you want good throughput and latency, then footprint will degrade.
• If you want good throughput and footprint, then latency will degrade.
• If you want good latency and footprint, then throughput will degrade.

2) If you are looking to tune G1 GC performance, here are the important G1 GC algorithm related JVM arguments.

Hi Team, Thanks for replying.

Our G1GC setting are below:

-XX:+UseG1GC
-XX:InitiatingHeapOccupancyPercent=45
-XX:ConcGCThreads=2
-XX:ParallelGCThreads=8
-XX:+ParallelRefProcEnabled
-XX:MaxGCPauseMillis=200
-XX:+UnlockExperimentalVMOptions
-XX:G1NewSizePercent=50
-XX:G1MaxNewSizePercent=80
-XX:+UseStringDeduplication
-XX:MaxMetaspaceSize=512m

System logical processor are 8, and total memory is 32 GB , out of total half memory (16GB) is allocated to our java process. we are using jdk1.8.0_241-b07.

We enabled the GC footprint and I investigated the GC logs and there are very high number of "Full GC (Metadata GC Threshold)"

2021-01-14T15:43:54.793+1100: 10755.311: [Full GC (Metadata GC Threshold) 2021-01-14T15:43:54.796+1100: 10755.313: [GC concurrent-root-region-scan-end, 0.0022897 secs]
2021-01-14T15:43:54.796+1100: 10755.313: [GC concurrent-mark-start]
 3318M->2618M(6840M), 4.9676785 secs]
   [Eden: 0.0B(3164.0M)->0.0B(3424.0M) Survivors: 256.0M->0.0B Heap: 3318.8M(6840.0M)->2618.3M(6840.0M)], [Metaspace: 360673K->348932K(1486848K)]
 [Times: user=7.38 sys=0.00, real=4.97 secs]

Look like Metaspace GC creating the issue. can you help us to fine tune these property so that we can avoid long pauses. latency is important in our project.

your help is much appreciated.

Regards

Rakesh

Hello Rakesh!

 Here are my high-level thoughts:

a. Your metaspace GC events are triggerred when your application's metaspace size reaches ~360mb. See the below graph. May be if you can set '-XX:MetaspaceSize=256m', metaspace GC events might get triggerred much earlier. At that point, since there is going to be less objects in metaspace, reclamation will be quicker. Your metaspace GC pause times might get smaller than 4 seconds. If it didn't yield favourable results we can try '-XX:MinMetaspaceFreeRatio' property. For more details refer to this article.

b. GC algorithms has internal ergonomics to determine the GC thread count. So you don't want to meddle with it, unless there is a necessity. So eliminate these 2 properties:

-XX:ConcGCThreads=2
-XX:ParallelGCThreads=8

c. Default value for '-XX:InitiatingHeapOccupancyPercent' is 45. So you don't have to pass '-XX:InitiatingHeapOccupancyPercent=45'

Hi Ram,

Thanks for investigation and provide your valuable suggestation. I will discuss your input with my management try to take action.

Today morning I again take the GC log:

https://gceasy.io/my-gc-report.jsp?p=c2hhcmVkLzIwMjEvMDEvMTQvLS1nYy1sb2dfMTVKYW4wOTAwLmxvZy0tMjItMjMtNTU=&channel=WEB

in this report there are very long pauses, one pause was 15 sec,  Meanwhile can you please go through this report share your valuable input.

Regards

Rakesh

Thanks Ram,

We have changed the G1GC changes today afternoon as per your recommendation. we are observing the load on the system. next two days load will be less due to weekend, therefore I will fetch the GC logs monday 10 AM and share the report with you in seprate question.

Thanks once again for your prompt response and valuable feedback.

Regards

Rakesh