Synchronization issues occur on a form which heavily uses [SPR-9084]

[spring-projects-issues]

Daniel Mikusa opened SPR-9084 and commented

Given a Spring MVC application which uses the Spring Forms JSP tags for data binding, a page that has a large number of field can cause blocking to occur.

Attached is a thread dump from an actual application which is experiencing this problem. Also attached is a sample application which can be used to demonstrate the problem.

To run the demo, use the command "mvn:tomcat". Once the application is deployed to Tomcat, run the included JMeter test to put load on the application. As the JMeter test runs, you should see the "max" time gradually increasing. I let it run for about 5 minutes and the max time crept up to around 10 seconds per response. Taking a thread dump at this time should show the issue.

In addition, I've ran the demo, replicating the problem, and have taken a snapshot with YourKit. The snapshot is attached.

From the snapshot, it appears that a significant portion of the contention appears to be around the following two items:

http-8080-8 [BLOCKED] CPU time: 0:03
java.util.Collections$SynchronizedMap.get(Object)
org.springframework.core.GenericTypeResolver.getTypeVariableMap(Class)
org.springframework.core.GenericTypeResolver.resolveParameterType(MethodParameter, Class)
org.springframework.core.convert.Property.resolveParameterType(MethodParameter)
org.springframework.core.convert.Property.resolveReadMethodParameter()
org.springframework.core.convert.Property.resolveMethodParameter()
org.springframework.core.convert.Property.<init>(Class, Method, Method)
org.springframework.beans.BeanWrapperImpl.property(PropertyDescriptor)
org.springframework.beans.BeanWrapperImpl.getPropertyTypeDescriptor(String)
org.springframework.validation.AbstractPropertyBindingResult.formatFieldValue(String, Object)
org.springframework.validation.AbstractBindingResult.getFieldValue(String)
org.springframework.web.servlet.support.BindStatus.<init>(RequestContext, String, boolean)
org.springframework.web.servlet.tags.form.AbstractDataBoundFormElementTag.getBindStatus()
org.springframework.web.servlet.tags.form.AbstractDataBoundFormElementTag.getPropertyPath()
org.springframework.web.servlet.tags.form.AbstractDataBoundFormElementTag.getName()
org.springframework.web.servlet.tags.form.AbstractDataBoundFormElementTag.autogenerateId()
org.springframework.web.servlet.tags.form.AbstractDataBoundFormElementTag.resolveId()
org.springframework.web.servlet.tags.form.AbstractDataBoundFormElementTag.writeDefaultAttributes(TagWriter)
org.springframework.web.servlet.tags.form.AbstractHtmlElementTag.writeDefaultAttributes(TagWriter)
org.springframework.web.servlet.tags.form.InputTag.writeTagContent(TagWriter)
org.springframework.web.servlet.tags.form.AbstractFormTag.doStartTagInternal()
org.springframework.web.servlet.tags.RequestContextAwareTag.doStartTag()
org.apache.jsp.WEB_002dINF.views.home_jsp._jspx_meth_form_005finput_005f0(JspTag, PageContext, int[])
org.apache.jsp.WEB_002dINF.views.home_jsp._jspService(HttpServletRequest, HttpServletResponse)
org.apache.catalina.core.ApplicationDispatcher.forward(ServletRequest, ServletResponse)
org.springframework.web.servlet.view.InternalResourceView.renderMergedOutputModel(Map, HttpServletRequest, HttpServletResponse)
org.springframework.web.servlet.view.AbstractView.render(Map, HttpServletRequest, HttpServletResponse)
org.springframework.web.servlet.DispatcherServlet.render(ModelAndView, HttpServletRequest, HttpServletResponse)
org.springframework.web.servlet.DispatcherServlet.doDispatch(HttpServletRequest, HttpServletResponse)
org.springframework.web.servlet.DispatcherServlet.doService(HttpServletRequest, HttpServletResponse)
org.springframework.web.servlet.FrameworkServlet.processRequest(HttpServletRequest, HttpServletResponse)
org.springframework.web.servlet.FrameworkServlet.doPost(HttpServletRequest, HttpServletResponse)
java.lang.Thread.run()

and

http-8080-18 [BLOCKED] CPU time: 0:00
java.util.Arrays.equals(Object[], Object[])
org.springframework.util.ObjectUtils.nullSafeEquals(Object, Object)
org.springframework.core.convert.TypeDescriptor.equals(Object)
org.springframework.core.convert.support.GenericConversionService$ConverterCacheKey.equals(Object)
java.util.concurrent.ConcurrentHashMap.get(Object)
org.springframework.core.convert.support.GenericConversionService.getConverter(TypeDescriptor, TypeDescriptor)
org.springframework.core.convert.support.GenericConversionService.canConvert(TypeDescriptor, TypeDescriptor)
org.springframework.validation.AbstractPropertyBindingResult.formatFieldValue(String, Object)
org.springframework.validation.AbstractBindingResult.getFieldValue(String)
org.springframework.web.servlet.support.BindStatus.<init>(RequestContext, String, boolean)
org.springframework.web.servlet.tags.form.AbstractDataBoundFormElementTag.getBindStatus()
org.springframework.web.servlet.tags.form.ErrorsTag.shouldRender()
org.springframework.web.servlet.tags.form.AbstractHtmlElementBodyTag.writeTagContent(TagWriter)
org.springframework.web.servlet.tags.form.AbstractFormTag.doStartTagInternal()
org.springframework.web.servlet.tags.RequestContextAwareTag.doStartTag()
org.apache.jsp.WEB_002dINF.views.home_jsp._jspService(HttpServletRequest, HttpServletResponse)
org.apache.catalina.core.ApplicationDispatcher.forward(ServletRequest, ServletResponse)
org.springframework.web.servlet.view.InternalResourceView.renderMergedOutputModel(Map, HttpServletRequest, HttpServletResponse)
org.springframework.web.servlet.view.AbstractView.render(Map, HttpServletRequest, HttpServletResponse)
org.springframework.web.servlet.DispatcherServlet.render(ModelAndView, HttpServletRequest, HttpServletResponse)
org.springframework.web.servlet.DispatcherServlet.doDispatch(HttpServletRequest, HttpServletResponse)
org.springframework.web.servlet.DispatcherServlet.doService(HttpServletRequest, HttpServletResponse)
org.springframework.web.servlet.FrameworkServlet.processRequest(HttpServletRequest, HttpServletResponse)
org.springframework.web.servlet.FrameworkServlet.doPost(HttpServletRequest, HttpServletResponse)
java.lang.Thread.run()

The first item appears to be similar to what is mentioned here in #13343. The second item appears to be unique.

---

Affects: 3.0.6, 3.1 GA

Attachments:

• BindingSyncTest.zip (26.94 kB)
• Launcher-2012-02-01-shutdown-2.snapshot.zip (1.82 MB)
• threaddump-1326467408882.tdump (812.05 kB)

Referenced from: commits 17bbc62, 9e21d2f

2 votes, 2 watchers

[spring-projects-issues]

Rossen Stoyanchev commented

The title looks like its missing the end ("heavily uses" ..?). The stack traces in the attached threaddump-1326467408882.tdump actually look more like the one below, which is due to a synchronization lock in java.lang.reflect.Proxy on while a converter is being looked up:

"tomcat-http--51" - Thread t@1644
   java.lang.Thread.State: BLOCKED on java.util.Collections$SynchronizedMap@131dca93 owned by: tomcat-http--28
        at java.util.Collections$SynchronizedMap.containsKey(Collections.java:1969)
        at java.lang.reflect.Proxy.isProxyClass(Proxy.java:619)
        at sun.reflect.annotation.AnnotationInvocationHandler.asOneOfUs(AnnotationInvocationHandler.java:197)
        at sun.reflect.annotation.AnnotationInvocationHandler.equalsImpl(AnnotationInvocationHandler.java:173)
        at sun.reflect.annotation.AnnotationInvocationHandler.invoke(AnnotationInvocationHandler.java:40)
        at $Proxy24.equals(Unknown Source)
        at java.util.Arrays.equals(Arrays.java:2392)
        at org.springframework.util.ObjectUtils.nullSafeEquals(ObjectUtils.java:257)
        at org.springframework.core.convert.TypeDescriptor.equals(TypeDescriptor.java:541)
        at org.springframework.core.convert.support.GenericConversionService$ConverterCacheKey.equals(GenericConversionService.java:632)
        at java.util.concurrent.ConcurrentHashMap$Segment.get(ConcurrentHashMap.java:338)
        at java.util.concurrent.ConcurrentHashMap.get(ConcurrentHashMap.java:769)
        at org.springframework.core.convert.support.GenericConversionService.getConverter(GenericConversionService.java:239)
        at org.springframework.core.convert.support.GenericConversionService.canConvert(GenericConversionService.java:145)
        at org.springframework.validation.AbstractPropertyBindingResult.findEditor(AbstractPropertyBindingResult.java:167)
        at org.springframework.web.servlet.support.BindStatus.<init>(BindStatus.java:125)
        at org.springframework.web.servlet.tags.form.AbstractDataBoundFormElementTag.getBindStatus(AbstractDataBoundFormElementTag.java:178)

The effect is probably amplified by heavy use of spring form tags with command objects field with annotations. It all starts with a lookup into the converterCache of GenericConversionService where the key consists of source and target TypeDescriptors with annotated fields.

[spring-projects-issues]

Rossen Stoyanchev commented

The great majority of blocked threads in the attached thread dump are performing a converterCache lookup in GenericConversionService, which involves a key made of a source and a target TypeDescriptor. In turn TypeDescriptor.equals() makes a deep comparison of annotations (on the field or method parameter represented by the TypeDescriptor), which causes the lock in java.lang.reflect.Proxy. It would probably be sufficient to compare the types of annotations instead of the deep comparison (including attributes) in place now.

[spring-projects-issues]

Juergen Hoeller commented

Fixed as discussed, with our TypeDescriptor equals implementation comparing the number and types of annotations only now (instead of the full annotation objects with attributes).

Juergen