Annotation retrieval performance degradation after 5.2

[quaff]

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%.

#23792 doesn't improve much, @e-hubert would you run this test project and feedback?

[quaff]

5.1.9:

5.2.0:

[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.

[quaff]

@e-hubert I have the same result, it degrade since 5.2.0.M1 .

[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.

[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();
		}
	}
}

[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
4b5c370 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.

[quaff]

@e-hubert Thanks for your efforts, I suspect MergedAnnotation caused the performance degradation.

[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.

[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

[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.

[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.

[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.