Skip to content

TypeMappedAnnotation.getValue(int,boolean,boolean) burns a lot of CPU, 2x total CPU usage on process after upgrade from 5.1 to 5.2 #24961

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
jensim opened this issue Apr 23, 2020 · 5 comments
Assignees
Labels
in: core Issues in core modules (aop, beans, core, context, expression) status: superseded An issue that has been superseded by another type: regression A bug that is also a regression

Comments

@jensim
Copy link

jensim commented Apr 23, 2020

Affects: 5.2
Type: Bug

SpringFramework 5.2 has a regression in CPU performance when dealing with RequestParameters with default values in combination with having a Filter that looks at the HttpServletRequest & HttpServletResponse (AccessLogging). The impact on CPU is massive when upgrading from 5.1 to 5.2.

I replicated the behaviour here
https://github.com/jensim/spring-boot-compare-22-21

@philwebb
@jhoeller
@sbrannen

@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged or decided on label Apr 23, 2020
@jhoeller jhoeller added this to the 5.2.6 milestone Apr 23, 2020
@jhoeller
Copy link
Contributor

@sbrannen Could you please have a look at this as well while you're in the area with #24861 already...

@snicoll snicoll changed the title Bug: TypeMappedAnnotation.getValue(int,boolean,boolean) burns a lot of CPU, 2x total CPU usage on process after upgrade from 5.1 to 5.2 TypeMappedAnnotation.getValue(int,boolean,boolean) burns a lot of CPU, 2x total CPU usage on process after upgrade from 5.1 to 5.2 Apr 23, 2020
@sbrannen sbrannen added the in: core Issues in core modules (aop, beans, core, context, expression) label Apr 23, 2020
@sbrannen sbrannen self-assigned this Apr 23, 2020
sbrannen added a commit that referenced this issue Apr 25, 2020
Prior to the introduction of the MergedAnnotation API in Spring Framework
5.2, our SynthesizedAnnotationInvocationHandler utilized a cache for
annotation attribute values; whereas, the new
SynthesizedMergedAnnotationInvocationHandler has no such caching in
place.

Issues such as gh-24961 indicate a regression in performance caused by
the lack of such an attribute value cache. For example, the required
attribute in @RequestParam is looked up using the internal meta-model
in the MergedAnnotation API twice per request for each @RequestParam in
a given controller handler method.

This commit reintroduces the attribute value cache to avoid the
unnecessary performance overhead associated with multiple lookups of
the same attribute in a synthesized annotation. This applies not only
to direct attribute method invocations but also to invocations of
equals() and hashCode() on a synthesized annotation.

Note, however, that this commit does NOT address multiple lookups of
annotation attribute values for invocations of toString(). That behavior
currently remains unchanged in the implementation of
org.springframework.core.annotation.TypeMappedAnnotation.toString().

Closes gh-24970
@sbrannen
Copy link
Member

@jensim in light of the fix for #24970, could you please try out a 5.2.6 snapshot build to see if that improves the situation for you?

Looking forward to your feedback!

@sbrannen sbrannen added type: regression A bug that is also a regression status: waiting-for-feedback We need additional information before we can continue and removed status: waiting-for-triage An issue we've not yet triaged or decided on labels Apr 26, 2020
@jensim
Copy link
Author

jensim commented Apr 26, 2020

Big thanks @sbrannen for looking at this
I did some new testruns with 5.2.6-BUILD-SNAPSHOT, and documented it in my demo-repo.
Basically it's a lot better than 5.2.5.RELEASE, and should no longer be blocking us from upgrading our applications.
5.1.14.RELEASE
5.2.6.BUILD-SNAPSHOT
Its still a noticeable regression over 5.1, if you are looking for it.

But, the lesson we take away from it at my company is not to have this many request-params on a GET request just because the verb is semantically more correct. A POST with a body is A LOT more efficient CPU/speed-wise in spring.

@jensim jensim closed this as completed Apr 26, 2020
@sbrannen sbrannen removed this from the 5.2.6 milestone Apr 27, 2020
@sbrannen sbrannen added status: superseded An issue that has been superseded by another and removed status: waiting-for-feedback We need additional information before we can continue labels Apr 27, 2020
@sbrannen
Copy link
Member

I've marked this issue as superseded by #24970.

Big thanks @sbrannen for looking at this

You're welcome.

I did some new testruns with 5.2.6-BUILD-SNAPSHOT, and documented it in my demo-repo .
Basically it's a lot better than 5.2.5.RELEASE, and should no longer be blocking us from upgrading our applications.

Great. Very glad to hear that.

And... thank for providing the feedback!

Its still a noticeable regression over 5.1, if you are looking for it.

We are indeed considering other ways to improve the performance of our annotation processing.

But, the lesson we take away from it at my company is not to have this many request-params on a GET request just because the verb is semantically more correct. A POST with a body is A LOT more efficient CPU/speed-wise in spring.

Any time you have that many request parameters in a single controller method it's good to investigate whether it would be better to bind them all to a single "command object" (@ModelAttribute) or to submit them as the request body (@RequestBody).

@sbrannen
Copy link
Member

Its still a noticeable regression over 5.1, if you are looking for it.

We are indeed considering other ways to improve the performance of our annotation processing.

See #24981

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
in: core Issues in core modules (aop, beans, core, context, expression) status: superseded An issue that has been superseded by another type: regression A bug that is also a regression
Projects
None yet
Development

No branches or pull requests

4 participants