Long pacing time seems to result in long response times

[Jeroen Borgers]

Hi,

In a load test on a JSF application we encountered long response times up
to 4 minutes instead of a few seconds, during a 20 min part of the test,
while putting constant load on it.  Pacing times seem large to me and I
want to find out if this is causing the bad response times. The CPU usage
on the host follows that of the jboss process which lowers from 45% to 12%
in that period. So it seems that the app is slowed down for about 20
minutes; 5 minutes the slowest and then slowly recovering.

There is a degenerate gc for 1.4 s., triggered by a TLAB allocation
failure, followed by 10 s. pacing (212 ms avg non-zero). Then pacing of 28
ms. followed by 28 s.(!) pacing (900 ms avg non-zero).
*1 Is this normal pacing behavior?

Configuration: x86-64b, 6 cores, VMWare, RHEL 7.9, OpenJDK 11.0.12, jboss
7.3.3.
jvm settings: -XX:+UseShenandoahGC -XX:+AlwaysPreTouch -XX:+UseNUMA
-XX:-UseBiasedLocking -XX:+UseTransparentHugePages
-Xlog:gc*:file=...log/gc-%t-%p.log:tags,uptime,time,level:filecount=5,filesize=3m
-Xlog:safepoint*:file=...log/safepoints-%t-%p.log:tags,uptime,time,level:filecount=5,filesize=3m

In our profiling tool it seems e.g. 88% of a long user tx (4 min) is spent
in locking.
*2. Is that how pacing shows?

We will try out -XX:ShenandoahPacingMaxDelay=10 in a new test with also a
bigger heap (12->16GB).
*3 Would that solve the issue?

*4 Would it help to provide gc logging here for better understanding what
happens?

Kind regards,

Jeroen Borgers

drs. Jeroen Borgers
Principal Consultant
jPinpoint Performance Services, jpinpoint com, The Netherlands.
 e-mail: jborgers at jpinpoint com