I have a web application based on struts2 and spring, after upgrading to spring 5.2.0, I found performance degraded, I confirm it caused by AutowireCapableBeanFactory.createBean() .
I write an very simple test project AutowirePerformance.zip, 1000000 iterations takes about 2100ms with 5.1.9 but 2800ms with 5.2.0, it means throughput decreased 25%.
https://github.com/spring-projects/spring-framework/issues/23792 doesn't improve much, @e-hubert would you run this test project and feedback?
Comment From: quaff
5.1.9:
5.2.0:
Comment From: e-hubert-opti
@quaff I run your test program locally on my box and can confirm your results. In addition to your tests with 5.1.9 and 5.2.0 I can add that in my tests 5.1.11 is still fast, while already the first 5.2.0 milestone M1 shows a degredation. Right from the first glance on the profiler output this time I could not immediately spot an exact cause though.
Comment From: quaff
@e-hubert I have the same result, it degrade since 5.2.0.M1 .
Comment From: quaff
In a typical struts2 application, Action and Result are created by spring per request, I tested one scenario in my real application, this degradation could decrease 30% throughput.
Comment From: quaff
ctx.getBean("prototypeBean") also hit performance degradation, throughput decreased about 10% when upgrade from 5.1.x to 5.2.x, this is my simple test
public class GetBeanTest {
public static void main(String[] args) throws Exception {
AnnotationConfigApplicationContext ctx = new AnnotationConfigApplicationContext(MyConfiguration.class);
// warming
for (int i = 0; i < 1000; i++)
ctx.getBean("action");
int iterations = 1000000;
StopWatch sw = new StopWatch();
sw.start();
for (int i = 0; i < iterations; i++)
ctx.getBean("action");
sw.stop();
System.out.println(sw.getLastTaskTimeMillis());
ctx.close();
}
@Configuration
@ComponentScan
static class MyConfiguration {
@Bean
@Scope("prototype")
public Action action() {
return new Action();
}
}
}
Comment From: e-hubert-opti
As we are moving closer towards 5.2.2 milestone completion, I invested a bit more time trying to locate a change causing the reported regression. It looks like the merge commit from 5.1.x to master 4b5c370701e8e58b123b2940b4c5eb6d36e11b1b containing 669 files was causing the regression on master. Slightly confusing, because 5.1.x HEAD shows good performance.
So next I tried a different approach comparing the HEAD revisons of master and 5.1.x supecting a relation to annotation processing changes (maybe some steps of #22560). I tried to replace a consistent set of classes in master with their 5.1.x predecessors. Only changing the following classes, I could come back to the original performance: AbstractAliasAwareAnnotationAttributeExtractor.java (add) AnnotatedElementUtils.java AnnotatedGenericBeanDefinition.java AnnotatedTypeMetadata.java AnnotationAttributeExtractor.java (add) AnnotationMatchingPointcut.java AnnotationMetadata.java AnnotationMetadataReadingVisitor.java AnnotationUtils.java AutowiredAnnotationBeanPostProcessor.java CommonAnnotationBeanPostProcessor.java ComponentScanAnnotationParser.java ConfigurationClass.java ConfigurationClassParser.java ConfigurationClassPostProcessor.java ConfigurationClassUtils.java DefaultAnnotationAttributeExtractor.java EventListenerMethodProcessor.java InitDestroyAnnotationBeanPostProcessor.java MapAnnotationAttributeExtractor.java (add) MethodMetadataReadingVisitor.java ParserStrategyUtils.java ScheduledAnnotationBeanPostProcessor.java SimpleAnnotationMetadata.java (remove) SimpleAnnotationMetadataReadingVisitor.java (remove) SimpleMetadataReader.java SimpleMethodMetadata.java (remove) SimpleMethodMetadataReadingVisitor.java (remove) SpringCacheAnnotationParser.java StandardAnnotationMetadata.java StandardClassMetadata.java StandardMethodMetadata.java SynthesizedAnnotationInvocationHandler.java (add)
Unfortunately, my timebox ended without a concrete result, but nevertheless I wanted to share these intermediate findings, as they might be of help for someone else looking into this.
Comment From: quaff
@e-hubert Thanks for your efforts, I suspect MergedAnnotation caused the performance degradation.
Comment From: jhoeller
This should be partially covered by #24485 now, available in the upcoming 5.2.4.BUILD-SNAPSHOT. Any further insights what the remaining difference could be caused by, please let me know.
Comment From: quaff
@jhoeller here is my test results.
| Version | Time(ms) |
|---|---|
| 5.1.13.RELEASE | 2608 |
| 5.2.3.RELEASE | 3146 |
| 5.2.4.BUILD-SNAPSHOT | 2750 |
Comment From: e-hubert-opti
Today, I again invested one very likely closely related performance degradation of about 25% based on a comparison of 5.1.9 and 5.2.4 which occurs when using
org.springframework.context.annotation.AnnotationBeanNameGenerator#generateBeanName
The actual difference seems to originate from an implementation change of
org.springframework.core.type.AnnotationMetadata#getMetaAnnotationTypes
in 5.1.x the used implementation
org.springframework.core.type.classreading.AnnotationMetadataReadingVisitor#getMetaAnnotationTypes
does a simple map lookup, whereas in 5.2.x the new default implementation of the interface is used which does way more complex stream processing and use of AnnotationsScanner. Please see the following flame graph:
I hope the provided information can be of help while further improving the performance of 5.2 in regard to annotation processing.
Comment From: e-hubert-opti
Just to add, I also double checked with 5.2.5 and 5.2.6-SN and I did not notice a change.
Comment From: jhoeller
I've created a separate issue (#24980) for a different solution to the problem in 5.2.6: AnnotationBeanNameGenerator caches the meta-annotation types for its stereotype check now which should be even more efficient than the minimal ASM retrieval solution that we had in the 5.1.x line.
With that addressed, I'll close this umbrella ticket for its original purpose. Let's create separate issues if any specific optimizations remain that we can address in 5.3, potentially backported to 5.2.x.