Spring4-jvm on the perf lab has some "suspiciously" long JIT compilation events

[franz1981]

See Spring4-jvm

vs Quarkus3-jvm

I've hit a similar problem in the past, see https://redhatperf.github.io/post/method-data-scalability/ where, in production, a Spring application overloaded by an big amount of load (which is our case with wrk during warmup) leave the JIT C2 threads in Spring to fight for CPU time competing with the tomcat http threads (same here?), causing the C2 compilations to take much longer and running the Java code in sub-optimal state (Tier 3), prone to "false sharing" issues.

See https://developers.redhat.com/articles/2023/09/29/how-we-solved-hotspot-performance-puzzle for a similar topic (although not due to contention).

[franz1981]

Now; if this same behaviour happen because of something we configure in the perf lab, we need to understand how to improve the test to mitigate it or just fix it (if possible!).
e.g. #113 to have a "softer" ramp-up using hyperfoil, for the sake of letting compilations to just complete without leaving anything behind, for both frameworks - or run the steady state more than once, to make sure everything is "stable".

But, if the behaviour happen due to differences between Quarkus and Spring, where Quarkus is just feeding the JIT compiler with much less compilations (which is my personal xp TBH, since we don't use reflection, nor perform much scanning etc etc), than it is what it is, as we cannot solve architectural problems of other frameworks.

[franz1981]

Running the same benchmark locally, on a more modern machine with the same clock, I'm NOT having the same compilation problem, see

  │                                     │    Spring Local     │   Spring Perf-Lab    │ Quarkus Local │ Quarkus Perf-Lab │
  ├─────────────────────────────────────┼─────────────────────┼──────────────────────┼───────────────┼──────────────────┤
  │ Total compilations                  │ 507                 │ 476                  │ 184           │ 205              │
  ├─────────────────────────────────────┼─────────────────────┼──────────────────────┼───────────────┼──────────────────┤
  │ Total compilation time              │ 197s                │ 301s                 │ 56s           │ 68s              │
  ├─────────────────────────────────────┼─────────────────────┼──────────────────────┼───────────────┼──────────────────┤
  │ Compilations >1s                    │ 41                  │ 46                   │ 10            │ 11               │
  ├─────────────────────────────────────┼─────────────────────┼──────────────────────┼───────────────┼──────────────────┤
  │ Max compilation duration            │ 3.8s                │ 16.2s                │ 1.9s          │ 2.38s            │
  ├─────────────────────────────────────┼─────────────────────┼──────────────────────┼───────────────┼──────────────────┤
  │ Still compiling during measurement? │ Yes (16 C2 methods) │ Yes (30+ C2 methods) │ No            │ No               │
  └─────────────────────────────────────┴─────────────────────┴──────────────────────┴───────────────┴──────────────────┘

More - just in the perf lab:

  C2 Compilation Queue (methods waiting to be optimized)                                                                                                                
   
  ┌─────────────┬─────────────────┬──────────────────┬────────────────────────────────────────────┐                                                                     
  │ Time (EDT)  │ Spring C2 queue │ Quarkus C2 queue │                   Phase                    │                                                                   
  ├─────────────┼─────────────────┼──────────────────┼────────────────────────────────────────────┤                                                                     
  │ startup     │ 30              │ 0                │ App starting                               │                                                                   
  ├─────────────┼─────────────────┼──────────────────┼────────────────────────────────────────────┤
  │ +15s        │ 448             │ 890              │ Both queues filling                        │
  ├─────────────┼─────────────────┼──────────────────┼────────────────────────────────────────────┤                                                                     
  │ +30s        │ 1,428           │ 1,142 (peak)     │ Warmup load                                │
  ├─────────────┼─────────────────┼──────────────────┼────────────────────────────────────────────┤                                                                     
  │ +45s        │ 2,397           │ 876              │ Quarkus draining, Spring growing           │                                                                   
  ├─────────────┼─────────────────┼──────────────────┼────────────────────────────────────────────┤                                                                     
  │ +60s        │ 3,211           │ 552              │                                            │                                                                   
  ├─────────────┼─────────────────┼──────────────────┼────────────────────────────────────────────┤                                                                     
  │ +75s        │ 3,253           │ 174              │                                            │                                                                   
  ├─────────────┼─────────────────┼──────────────────┼────────────────────────────────────────────┤                                                                     
  │ +80s        │ 3,263 (peak)    │ 0                │ Quarkus done, Spring still growing         │                                                                   
  ├─────────────┼─────────────────┼──────────────────┼────────────────────────────────────────────┤                                                                     
  │ +2min       │ 3,207           │ 0                │ Warmup ends                                │                                                                   
  ├─────────────┼─────────────────┼──────────────────┼────────────────────────────────────────────┤                                                                     
  │ sleep       │ 3,124→1,363→0   │ 0                │ Spring drains during 30s sleep             │                                                                   
  ├─────────────┼─────────────────┼──────────────────┼────────────────────────────────────────────┤                                                                     
  │ measurement │ 212 spike→0     │ 0                │ Spring still compiling during measurement! │                                                                   
  └─────────────┴─────────────────┴──────────────────┴────────────────────────────────────────────┘                                                                                                    

Spring's C2 queue is never able to drain during warmup — it keeps growing to 3,263 because the 2 C2 threads can't keep up while competing with hundreds of Tomcat threads for CPU.
The queue only drains during the 30s sleep when the app threads are idle.
And even then, many methods get dropped (the queue goes from 3,263 to 0 but only 313 C2 compilations happen = most were discarded).

Ideally perf stat or perf c2c could help to understand what's going on as it really looks too similar to the mentioned article.

[franz1981]

Now, we have to validate what kind of problem it is, why it happens and if it makes sense to mitigate it or fix It yet.
And is still unknown if it cause any performance issue as native image w Spring has halved performance and it doesn't suffer from JIT contention, which seems to invalidate the theory that this could cause any peak tps issue.
But we need to verify it yet.

[franz1981]

It looks like that similar to the production case disabling background compilation so the trick but there is no improvements on spring side with it despite no compilations happen during the load.