Skip to content

Performance degradation in Web layer after upgrade to Spring 6 #31098

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
alexey-anufriev opened this issue Aug 23, 2023 · 39 comments
Closed

Performance degradation in Web layer after upgrade to Spring 6 #31098

alexey-anufriev opened this issue Aug 23, 2023 · 39 comments
Assignees
Labels
in: web Issues in web modules (web, webmvc, webflux, websocket)

Comments

@alexey-anufriev
Copy link
Contributor

Affects: 6.0.10 (Spring Boot 3.1.1)

Summary:
After upgrade to Spring Boot 3.x application started to take more time for web requests processing.

Description:
Initially, the application was based on Spring Boot 2.7.14 (Java 17). But since we upgraded to Spring Boot 3.1.1 we noticed performance degradation in web layer. Requests processing took extra time in comparison with Boot 2.x. Upgrade to Spring Boot 3.1.2 made it ever worse. Tomcat's MessageBytes serialization started to perform even slower. So we reverted to Spring Boot 3.1.1.

One more thing that was discovered in the profiler is slow performance of AntMatcher. So we followed the recommendation from upgrade guide of Spring Boot 2.6 and witched to PathParser. As it turns out, this did not make much of an improvement (see details below).

CPU

Here are some details captured using DataDog profiler.

Here is a request processing of the URL that has path variables:
image

And here is a request processing of the URL that has no path variables:
image

Memory

One more thing that was discovered is memory consumption, most of the allocations are happening here:
image

This is the size per minute
image


How can this be improved? One thought is around some kind of caching for PathParser to avoid extra calculations while request matching.

@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged or decided on label Aug 23, 2023
@bclozel
Copy link
Member

bclozel commented Aug 23, 2023

Thanks for the report @alexey-anufriev , but there not so much actionable here, or at least conflicting messages.

You're first mentioning Tomcat's MessageBytes performance, which is out of our control.
You are also pointing to AntPathMatcher and PathPattern as areas of improvements. At this point, I'm not sure where the performance loss comes from and whether this is related to those classes. Did you compare the profiling output of 2.7.x and 3.1.x for your application? Did the ratio of the request matching phase grow in the overall execution with this upgrade?

Again, without much context, it's hard to understand why this part of the execution is slow. Request matching is of course an important part and we've optimized it with PathPatternParser and PathPattern. Depending on the request and if the path matches, some other conditions are processed (content negotiation, request parameters and others). It's not surprising some requests require less processing for the matching phase as optimizations happen along the way.

Discussing about performance is often tricky as it's easy to waste time setting up an imperfect benchmark test harness and draw the wrong conclusions. Comparing the same application with two different versions and pointing to the difference should be a good first step. Pointing to parts of the request processing and asking for performance improvements is not a good way to start; we've got multiple micro-benchmarks in the Framework codebase and spending time there is not always the most efficient way to optimize for your case.

How can this be improved? One thought is around some kind of caching for PathParser to avoid extra calculations while request matching.

The PathPatternParser is only called once during startup and create efficient PathPattern instances for matching against incoming requests. We optimized this quite a bit already in the past using a JMH benchmark. I don't understand the suggestion here. What should be cached?

@bclozel bclozel added status: waiting-for-feedback We need additional information before we can continue in: web Issues in web modules (web, webmvc, webflux, websocket) labels Aug 23, 2023
@alexey-anufriev
Copy link
Contributor Author

Fair enough, let me prepare benchmarks.

@bclozel
Copy link
Member

bclozel commented Aug 23, 2023

@alexey-anufriev I'm not suggesting you to prepare benchmarks, quite the opposite. It takes a lot of time to design and implement a benchmark and consider its biases.

Here, I'm really requesting a full picture of the CPU time (your datadog flame graph) for the 2.7.x and 3.1.x versions of the same application. Comparing CPU time there should point to possible regressions that I could look into.

@spring-projects-issues spring-projects-issues added status: feedback-provided Feedback has been provided and removed status: waiting-for-feedback We need additional information before we can continue labels Aug 23, 2023
@bclozel bclozel added status: waiting-for-feedback We need additional information before we can continue and removed status: feedback-provided Feedback has been provided labels Aug 23, 2023
@alexey-anufriev
Copy link
Contributor Author

Ok, let me try to do fast comparison.

This is before the upgrade:
image

And this is after:
image

@spring-projects-issues spring-projects-issues added status: feedback-provided Feedback has been provided and removed status: waiting-for-feedback We need additional information before we can continue labels Aug 23, 2023
@bclozel
Copy link
Member

bclozel commented Aug 23, 2023

Thanks for the update!

If I understand correctly, both applications are Spring MVC, one using the AntPathMatcher and the other the PathPatternParser variant. It would be nice to check whether the same behavior can be seen in Spring Boot 2.7. By default there, the PathPatternParser strategy is chosen as well. Did you opt-out explicitly in 2.7.x? If so, can you try with the same matching strategy in 2.7.x?

it looks like the MvcRequestMatcher is triggering the matching operation here, as you've probably migrated your Security configuration as requested by Spring Security. Still, the matching phase should not take longer than usual so this bit is interesting.

It would be interesting to get more information about the particular endpoints involved here:

  • can you share the patterns exposed by your controllers?
  • can you share the request you are sending to the application?

With that information I can start building a sample application involving Spring Security, a few controller endpoints and find out if there is a performance issue with the matching phase.

@bclozel bclozel added status: waiting-for-feedback We need additional information before we can continue and removed status: feedback-provided Feedback has been provided labels Aug 23, 2023
@alexey-anufriev
Copy link
Contributor Author

  1. Yes, we explicitly opted out and kept AntMatcher in 2.7.
  2. Sample APIs are the following:
GET /api/org/{orgId}/usr/{userId}/membership
GET /api/org/toggle/{toggleKey}/enabled
GET /api/org/toggles
GET /api/orgs
GET /api/orgs/{id}

POST /api/auth/key
POST /api/auth/token
  1. As you see, these are mostly GET requests, so the content of those is pretty common: auth header, maybe CSP, and so on. In general, not that much of the content.
  2. You are right, Security confguration has been migrated according to the upgrade guide.
  3. I will also provide the behaviour on 2.7 with PathParser.

@spring-projects-issues spring-projects-issues added status: feedback-provided Feedback has been provided and removed status: waiting-for-feedback We need additional information before we can continue labels Aug 24, 2023
@alexey-anufriev
Copy link
Contributor Author

And this is how 2.7 works with PathParser configured

image

@alexey-anufriev
Copy link
Contributor Author

One more interesting observation that I mentioned before: Tomcat regression.

So here we have Spring boot 3.1.1

  • avg latency is around 500 ms
  • MessageByes.toString is not even noticeable
    image

And here we have Spring boot 3.1.2

  • avg latency is around 800 ms
  • MessageByes.toString is quite noticeable
    image

@alexey-anufriev
Copy link
Contributor Author

The fastest combination seems to be the following:

  • Spring Boot 3.1.1
  • explicit use of AntMatcher as matching strategy and in security: .authorizeHttpRequests(c -> c.requestMatchers(antMatcher("...")).permitAll()

image

@alexey-anufriev
Copy link
Contributor Author

hi @bclozel, are there any updates here? or maybe some additional information required?

@bclozel
Copy link
Member

bclozel commented Sep 1, 2023

I'm still working on it. So far nothing conclusive. I do see that the mvc request matcher is taking longer, which is not unexpected since it's doing more in the first place. The number of req/s is still comparable, and the ratio of time taken by request matching is still nowhere near where your samples are.

I've profiled locally with Yourkit and wrk on a sample app that should be comparable.

With ant matcher:

antrequestmatcher

With mvc request matcher:

mvcrequestmatcher

I'll continue investigating this in the next days and keep you posted. I might share the sample with you at some point or write JMH benchmarks to see if I can optimize a few spikes I'm seeing.

@bclozel bclozel self-assigned this Sep 1, 2023
@alexey-anufriev
Copy link
Contributor Author

Thank you for the update. Looking forward to the next steps.

@smotron
Copy link

smotron commented Oct 18, 2023

I can share some observations...
We have a time-critical web application including Spring Security. Updating Spring Boot 3.0.5 to 3.1.2 increased our average execution time from ~10ms to 12ms. Nothing was changed beside the version update. The additional time is added somewhere before entering the controller.

@akhilbrao
Copy link

Hi @bclozel - Is there any suggestion for this observation. @alexey-anufriev the tomcat latency around toString upon checking their repo there isn’t any updates made on that code. Can you share how did you mitigate this issue.

@bclozel
Copy link
Member

bclozel commented Oct 23, 2023

@smotron @akhilbrao I'm afraid this issue does not intend to cover all performance aspects of Spring web frameworks with Security. We are still investigating (although I had to prioritize 6.1 work as the release is approaching) and we'll share our findings here.

Our initial findings do not point to a particular place nor show a huge difference in latency nor throughput. We might find some optimization opportunities along the way but as you can see Spring is only involved in some parts of the flame charts. Spring Boot upgrades usually involve lots of other components as well.

@akhilbrao
Copy link

@bclozel thanks for the update. We have recently upgraded to spring boot 3.1.2 lets see how the performance would be. Though we don’t have many url patterns. @alexey-anufriev when you find some time let us know the solution for tomcat if you had done anything.

@janickr
Copy link

janickr commented Nov 14, 2023

@alexey-anufriev We have the exact same issue, after some digging I found that the MessageBytes.toString was a Tomcat regression, and that it will be fixed in 11.0.0-M1, 10.1.16, 9.0.83 and 8.5.96 (see https://bz.apache.org/bugzilla/show_bug.cgi?id=68026 )

@alexey-anufriev
Copy link
Contributor Author

@bclozel, thank you for the update! Happy to assist with further experiments.

@janickr, yes, this we also noticed, unfortunately 10.1.16 has just been recently released, but hope it will be available in the next Spring Boot.

@bclozel
Copy link
Member

bclozel commented Dec 15, 2023

spring-projects/spring-security#14128 is now fixed and available in Spring Security 6.1.6-SNAPSHOT and 6.2.1-SNAPSHOT. Please test your applications with the current Spring Boot 3.2.1-SNAPSHOT version to check the performance changes. Release is scheduled next week for Spring Boot.

@snicoll snicoll added status: waiting-for-feedback We need additional information before we can continue and removed status: feedback-provided Feedback has been provided labels Dec 15, 2023
@alexey-anufriev
Copy link
Contributor Author

@bclozel, thank you for your effort, I will test the new build and will come back with the results soon.

@spring-projects-issues spring-projects-issues added status: feedback-provided Feedback has been provided and removed status: waiting-for-feedback We need additional information before we can continue labels Dec 19, 2023
@bclozel bclozel added status: waiting-for-feedback We need additional information before we can continue and removed status: feedback-provided Feedback has been provided labels Dec 27, 2023
@spring-projects-issues
Copy link
Collaborator

If you would like us to look at this issue, please provide the requested information. If the information is not provided within the next 7 days this issue will be closed.

@spring-projects-issues spring-projects-issues added the status: feedback-reminder We've sent a reminder that we need additional information before we can continue label Jan 3, 2024
@spring-projects-issues
Copy link
Collaborator

Closing due to lack of requested feedback. If you would like us to look at this issue, please provide the requested information and we will re-open the issue.

@spring-projects-issues spring-projects-issues closed this as not planned Won't fix, can't repro, duplicate, stale Jan 10, 2024
@spring-projects-issues spring-projects-issues removed status: waiting-for-feedback We need additional information before we can continue status: feedback-reminder We've sent a reminder that we need additional information before we can continue status: waiting-for-triage An issue we've not yet triaged or decided on labels Jan 10, 2024
@alexey-anufriev
Copy link
Contributor Author

It took a bit of time to validate the fix completely (also considering NY holidays), but we are done now, and I can confirm, that we not only got rid of performance degradation, but also got performance boost with path-parser vs ant-matcher.

@bclozel, and the rest of spring team, thank you for your effort and help!

@bclozel
Copy link
Member

bclozel commented Jan 15, 2024

@alexey-anufriev Awesome, thanks for letting us know!

@SoundaryaDassC
Copy link

@bclozel Thanks for considering the issue and getting it fixed.
@alexey-anufriev just wanted to confirm ant-matcher performance is better.

@tushar-meesho

This comment has been minimized.

@alexey-anufriev
Copy link
Contributor Author

hi @tushar-meesho, yes, Spring Boot 3.2.1 contains a fix (note that normally you should not use a SNAPSHOT version, it is just for testing). Also, 3.2.5 has it included, so don't see a reason to not upgrade to the latest one.

@goafabric
Copy link

Hi, @alexey-anufriev
i just stumbled on this issue today .. after discovering that a simple request in boot 3.25 with security will take 100ms
while in boot 2.7 it's only 5 ms.

So in one of your previous posts you mentioned that you could verify that it's fixed?
Because the increased reponse time is still there in 3.25 for me.
(i am aware that you are not a member of the spring team ..)

thanks in advance

@alexey-anufriev
Copy link
Contributor Author

hi @goafabric,

yes, APM showed good metrics and latency went back to normal, so it was confirmed that the performance is good

@orubel
Copy link

orubel commented Mar 31, 2025

Hi, @alexey-anufriev i just stumbled on this issue today .. after discovering that a simple request in boot 3.25 with security will take 100ms while in boot 2.7 it's only 5 ms.

Yeah I'm still getting this in 3.2 with security as well

@smotron
Copy link

smotron commented Mar 31, 2025

I can share some observations... We have a time-critical web application including Spring Security. Updating Spring Boot 3.0.5 to 3.1.2 increased our average execution time from ~10ms to 12ms. Nothing was changed beside the version update. The additional time is added somewhere before entering the controller.

I can confirm that it was fixed. After the fix our execution time for a time-critical operation was even faster than before with 9ms and it is still there, today.

@orubel
Copy link

orubel commented Mar 31, 2025

@smotron Thx. I'll check the filters/interceptors. I'll just add a trace

@orubel
Copy link

orubel commented Apr 18, 2025

@smotron so I ran traces on filters/interceptors and even swapped out the cache. No effective change. Was getting 7000/rps with security (jwt, oauth, session mngmt, cors, rbac/abac) but NOW it is only 6000/rps.

I test the RPS using Apachebench and Beapi-bench using 500 concurrency and 5000 requests over 50 tests (with a 1 second pause between tests); generally, the test hits its stride at around the 10th test.

I have been testing this for about a month now and it is undeniable that the web functionality has deteriorated significantly.

I should also add that I am using a SimpleUrlHandlerMapping rather that RequestMappingHandlerMapping. I doubt this would effect anything unless they optimized for one type of mapping and neglected the others. This is the only real difference I can see aside from switching my cache provider(ehcache2 to caffeine)

I'm beginning to think this may be a stability fix and my numbers now reflect additionals checks being done.

@orubel
Copy link

orubel commented Apr 18, 2025

So I ran the benchmark again and noticed that the WAIT TIME is extraordinarily high. Is there some sort of thread management that could be causing this? It is just a 100kb cached result being returned...

I'm thinking at this pooint the issue may be my Tomcat Config.

Image

@orubel
Copy link

orubel commented Apr 18, 2025

NVM. That was it. Tomcat config not optimized. Was adding an async executor and had not optimized it.

Adding this reference.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
in: web Issues in web modules (web, webmvc, webflux, websocket)
Projects
None yet
Development

No branches or pull requests