Thanks Zdeněk for the response .
1)We have enabled GC logs and we see that mixed GC takes more than 1 sec and it
occurs once in 2 hours approximately , whereas with tomcat 9.0.38 mixed GC
occurs every 20 mins approximately with very small GC Pause, both the GC log
comparisons i.e. with tomcat 9.0.56 and 9.0.38 were done with the same object
allocation rate
2022-08-18T12:58:47.240-0400: 4956324.814: [GC pause (G1 Evacuation Pause)
(mixed), 1.8309540 secs]
[Parallel Time: 1778.2 ms, GC Workers: 6]
[GC Worker Start (ms): Min: 4956324838.5, Avg: 4956324838.9, Max:
4956324839.2, Diff: 0.7]
[Ext Root Scanning (ms): Min: 19.5, Avg: 19.9, Max: 20.9, Diff: 1.4, Sum:
119.6]
[Update RS (ms): Min: 5.4, Avg: 5.4, Max: 5.5, Diff: 0.0, Sum: 32.6]
[Processed Buffers: Min: 71, Avg: 109.3, Max: 128, Diff: 57, Sum: 656]
[Scan RS (ms): Min: 1137.0, Avg: 1138.0, Max: 1138.6, Diff: 1.6, Sum:
6827.8]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum:
0.1]
[Object Copy (ms): Min: 613.2, Avg: 613.8, Max: 614.8, Diff: 1.6, Sum:
3682.5]
[Termination (ms): Min: 0.0, Avg: 0.3, Max: 0.4, Diff: 0.4, Sum: 1.8]
[Termination Attempts: Min: 1, Avg: 893.3, Max: 1141, Diff: 1140, Sum:
5360]
[GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.5]
[GC Worker Total (ms): Min: 1777.1, Avg: 1777.5, Max: 1777.9, Diff: 0.8,
Sum: 10664.9]
[GC Worker End (ms): Min: 4956326616.4, Avg: 4956326616.4, Max:
4956326616.5, Diff: 0.1]
[Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 1.8 ms]
[Other: 51.0 ms]
[Choose CSet: 23.1 ms]
[Ref Proc: 2.4 ms]
[Ref Enq: 0.2 ms]
[Redirty Cards: 2.6 ms]
[Humongous Register: 0.1 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 20.8 ms]
[Eden: 2144.0M(2144.0M)->0.0B(2128.0M) Survivors: 104.0M->120.0M Heap:
6632.0M(22.0G)->3296.0M(22.0G)]
[Times: user=8.61 sys=2.00, real=1.83 secs]
2)The 5gb of swap that is used is not completely by this process , we have few
other processes running .
3)These parameters in production are fine-tuned for the process.
Thanks and Regards
Arshiya Shariff
-----Original Message-----
From: Zdeněk Henek <vrab...@gmail.com>
Sent: 30 August 2022 19:43
To: Tomcat Users List <users@tomcat.apache.org>
Subject: Re: Increase in GC Pause time in tomcat http2 9.0.56
HI Arshiya,
MaxGCPauseMillis=100
maybe this is too strict? Causing you run into full gc. Jdk8 G1GC
implementation has single thread full gc and these take more time to finish?
Just guessing as you have not written if the long pause gcs are young gen
pauses or full gc pauses.
Another option which could cause longer gc pauses could be usage of swap file /
swap partition. Check and monitor how much memory is used and how the swap is
used.
Your system has 120gb of ram. That is a lot, but still it does use approx 18gb
swap file! There is used 5gb of that swap. I think it may be better to remove
that swap file completely or reduce swappiness param in your OS.
There is assigned 22gb heap, G1GC in jdk8 uses a lot of memory for G1 GC
metadata. It could be up to 6gb in your case. I would consider upgrade to
jdk17 and plan upgrades to newer jdk frequently if you can. There are
significant improvements in G1GC in new jdk versions, not only metadatas size.
I would start troubleshooting removing all gc related params and let G1GC
decide all the params during runtime. It is usually a good starting point to
troubleshooting G1GC if you don't know what is wrong.
Enable gc logs and use gc log analyser to see what is going on there. There is
page with list of available GC analyzers here
https://protect2.fireeye.com/v1/url?k=31323334-501d5122-313273af-454445555731-3a2e7b00ac43e57a&q=1&e=b7c12870-06e4-4332-b0b8-6462d5cfa43d&u=http%3A%2F%2Ffasterj.com%2Ftools%2Fgcloganalysers.shtml
Regards,
Zdenek
On Tue, Aug 30, 2022 at 3:31 PM Arshiya Shariff
<arshiya.shar...@ericsson.com.invalid> wrote:
> We haven’t made any changes to the gc params when migrating tomcat :
>
> Please find the configurations:
>
> Java HotSpot(TM) 64-Bit Server VM (25.241-b07) for linux-amd64 JRE
> (1.8.0_241-b07), built on Dec 11 2019 02:22:16 by "java_re" with gcc
> 7.3.0
> Memory: 4k page, physical 119478416k(781944k free), swap
> 18862076k(13762004k free)
> -XX:ConcGCThreads=3 -XX:G1HeapRegionSize=8388608
> -XX:G1NewSizePercent=10
> -XX:G1ReservePercent=20 -XX:InitialHeapSize=23622320128
> -XX:InitiatingHeapOccupancyPercent=60 -XX:MaxGCPauseMillis=100
> -XX:MaxHeapSize=23622320128 -XX:MaxMetaspaceSize=268435456
> -XX:MaxNewSize=14168358912 -XX:MinHeapDeltaBytes=8388608
> -XX:ParallelGCThreads=6 -XX:+UnlockExperimentalVMOptions
> -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseG1GC
> -XX:+UseGCLogFileRotation
>
> Thanks and Regards
> Arshiya Shariff
>
> -----Original Message-----
> From: Rob Sargent <rsarg...@xmission.com>
> Sent: 30 August 2022 18:22
> To: users@tomcat.apache.org
> Subject: Re: Increase in GC Pause time in tomcat http2 9.0.56
>
>
>
> On 8/30/22 06:11, Arshiya Shariff wrote:
> > Hi All ,
> > We have migrated our application (which transports http/2 packets)
> > from
> embedded tomcat version 9.0.38 to 9.0.56 in production .
> >
> > We observe that , in 9.0.56 mixed GC occurs less frequently than in
> 9.0.38 , but when it happens there are GC Pauses for more than 1
> second , which is causing the application to be unresponsive during
> that time and as a side effect we are facing other issues like delay
> in WINDOW_UPDATE frames being sent.
> >
> > Has anyone faced similar issue with increased GC Pause time ?
> >
> > Thanks and Regards
> > Arshiya Shariff
> >
> And no change to the JVM?
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
> For additional commands, e-mail: users-h...@tomcat.apache.org
>
