Cache and late resolve annotations on bean properties to improve performance [SPR-9166]

[spring-projects-issues]

Taylor S. Wicksell opened SPR-9166 and commented

The same type of deadlock seen in #13722 can actually be triggered from numerous locations in the framework beyond just converter cache lookup. After the release of 3.1.1 we noticed the same issue being triggered from multiple calls from the Spring Form tag.

"tomcat-http--49" daemon prio=10 tid=0x0000000052868800 nid=0x2ad1 waiting for monitor entry [0x0000000047048000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at java.lang.reflect.Proxy.getProxyClass(Proxy.java:417)
	- waiting to lock <0x00000005f59f31c0> (a java.util.HashMap)
	at java.lang.reflect.Proxy.newProxyInstance(Proxy.java:581)
	at sun.reflect.annotation.AnnotationParser.annotationForMap(AnnotationParser.java:239)
	at sun.reflect.annotation.AnnotationParser.parseAnnotation(AnnotationParser.java:229)
	at sun.reflect.annotation.AnnotationParser.parseAnnotations2(AnnotationParser.java:69)
	at sun.reflect.annotation.AnnotationParser.parseAnnotations(AnnotationParser.java:52)
	at java.lang.reflect.Field.declaredAnnotations(Field.java:1014)
	- locked <0x000000072fe2e428> (a java.lang.reflect.Field)
	at java.lang.reflect.Field.getDeclaredAnnotations(Field.java:1007)
	at java.lang.reflect.AccessibleObject.getAnnotations(AccessibleObject.java:175)
	at org.springframework.core.convert.Property.resolveAnnotations(Property.java:197)
	at org.springframework.core.convert.Property.<init>(Property.java:65)
	at org.springframework.beans.BeanWrapperImpl.property(BeanWrapperImpl.java:525)
	at org.springframework.beans.BeanWrapperImpl.getPropertyTypeDescriptor(BeanWrapperImpl.java:401)
	at org.springframework.validation.AbstractPropertyBindingResult.findEditor(AbstractPropertyBindingResult.java:159)
	at org.springframework.web.servlet.support.BindStatus.<init>(BindStatus.java:125)
	at org.springframework.web.servlet.tags.form.AbstractDataBoundFormElementTag.getBindStatus(AbstractDataBoundFormElementTag.java:178)
	at org.springframework.web.servlet.tags.form.ErrorsTag.shouldRender(ErrorsTag.java:140)
	at org.springframework.web.servlet.tags.form.AbstractHtmlElementBodyTag.writeTagContent(AbstractHtmlElementBodyTag.java:47)
	at org.springframework.web.servlet.tags.form.AbstractFormTag.doStartTagInternal(AbstractFormTag.java:102)
	at org.springframework.web.servlet.tags.RequestContextAwareTag.doStartTag(RequestContextAwareTag.java:79)

The root issue seems to be the reading of annotations using reflection in the constructor of org.springframework.core.convert.Property. This condition can be recreated fairly easily by calling this constructor from a unit test using multiple threads, as shown here: https://gist.github.com/1894670

It would seem like deferring the parsing of annotations until they are actually requested could help to mitigate this issue greatly.

---

Affects: 3.0.6, 3.1.1

Issue Links:

• Use concurrent cache to improve performance of GenericTypeResolver [SPR-8701] #13343 Use concurrent cache to improve performance of GenericTypeResolver
• SWF-1528 Webflow upgrade from 2.0.8 to 2.3.0 - 6% CPU Increase On Websphere
• Develop ConcurrentReferenceHashMap [SPR-9796] #14429 Develop ConcurrentReferenceHashMap

Referenced from: commits 02ce826

2 votes, 6 watchers

[spring-projects-issues]

Taylor S. Wicksell commented

https://github.com/Gradinko/spring-framework/commit/d8f3b0c3e307f5b6d70a8da3fe8bef9c3db4acd4

Made an attempt at delaying the parsing of annotations as a proof of concept. Broke no unit tests, greatly mitigated blocking issue in web application, showed good improvement in unit test referenced in description;

With current Spring 3.1.1.RELEASE
INFO : ThreadedPropertyPerformanceTest - Finished with 10 thread(s). Average time: 33869ms
INFO : ThreadedPropertyPerformanceTest - Finished with 50 thread(s). Average time: 29984ms

After modifications to delay processing of annotations
INFO : ThreadedPropertyPerformanceTest - Finished with 10 thread(s). Average time: 6901ms
INFO : ThreadedPropertyPerformanceTest - Finished with 50 thread(s). Average time: 6858ms

Change could definitely be made cleaner, but hopefully this can help guide towards a solution.

[spring-projects-issues]

Daniel Mikusa commented

Taylor,

You had previously asked why TypeDescriptor is comparing annotations in its equals method. I have an answer to your question.

This is important for situations where type conversion may be influenced by an annotation. For example, if one class field is annotated with @DateTimeFormat and another is not, the a different TypeConverter would be used. As long as you are not using formatting annotations, it should not make much difference.

In other words, you fix here should work as long as you don't try to use Annotation driven formatting.

http://static.springsource.org/spring/docs/3.1.x/spring-framework-reference/html/validation.html#format-CustomFormatAnnotations

Dan

[spring-projects-issues]

Chris Beams commented

Taylor originally submitted a proposed fix for this issue at #18. I've asked him to follow the contributor guidelines and create a new pull request.

[spring-projects-issues]

Taylor S. Wicksell commented

Phil, I don't think my original commit was really pull-worthy, but just a demonstration of the problem and my own fix which worked for my use case. Here is that commit for reference if it helps at all in your investigation of this issue > twicksell@d8f3b0c

[spring-projects-issues]

Phil Webb commented

Hi Taylor,

Both your commit and especially the test case that you provided have been very useful. I am investigating to see if we can use your approach in combination with some caching to speed things up.

Cheers,
Phil.

[spring-projects-issues]

Phil Webb commented

#146

[spring-projects-issues]

Phil Webb commented

A fix for this is now committed. Running the test case provided by Taylor S. Wicksell my timing reduced from 42.93s to 1.93s.