Bug 54113 - Deadlock in CompareUtil class
Summary: Deadlock in CompareUtil class
Status: NEW
Alias: None
Product: Fop - Now in Jira
Classification: Unclassified
Component: general (show other bugs)
Version: trunk
Hardware: PC All
: P2 major
Target Milestone: ---
Assignee: fop-dev
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2012-11-07 14:04 UTC by Matthias Reischenbacher
Modified: 2012-12-03 21:13 UTC (History)
1 user (show)


Attachments
Java Thread Dump (617.68 KB, application/octet-stream)
2012-11-07 14:04 UTC, Matthias Reischenbacher 		Details
Thread dump snippet (26.17 KB, text/plain)
2012-12-03 02:54 UTC, Gareth Bowen 		Details
View All Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.
Description Matthias Reischenbacher 2012-11-07 14:04:45 UTC 
Created attachment 29565 [details]
Java Thread Dump

I'm getting a dead lock in the CompareUtil class, see the attached thread dump. 

Here small fragment of the thread dump

[2012-11-07 14:06:25] [info] Found one Java-level deadlock:
[2012-11-07 14:06:25] [info] =============================
[2012-11-07 14:06:25] [info] 
[2012-11-07 14:06:25] [info] "http-80-exec-58":
[2012-11-07 14:06:25] [info]   waiting to lock monitor 0x0000000006ca9480
[2012-11-07 14:06:25] [info]  (object 0x000000071fe9bd00, a java.util.Vector)
[2012-11-07 14:06:25] [info] ,
  which is held by "http-80-exec-5"
[2012-11-07 14:06:25] [info] 
[2012-11-07 14:06:25] [info] "http-80-exec-5":
[2012-11-07 14:06:25] [info]   waiting to lock monitor 0x00000000116ecfc8
[2012-11-07 14:06:25] [info]  (object 0x000000071fe9a000, a java.util.Vector)
[2012-11-07 14:06:25] [info] ,
  which is held by "http-80-exec-18"
[2012-11-07 14:06:25] [info] 
[2012-11-07 14:06:25] [info] "http-80-exec-18":
[2012-11-07 14:06:25] [info]   waiting to lock monitor 0x0000000006ca9480
[2012-11-07 14:06:25] [info]  (object 0x000000071fe9bd00, a java.util.Vector)
[2012-11-07 14:06:25] [info] ,
  which is held by "http-80-exec-5"
[2012-11-07 14:06:25] [info] 
[2012-11-07 14:06:25] [info] 
[2012-11-07 14:06:25] [info] Java stack information for the threads listed above:
[2012-11-07 14:06:25] [info] ===================================================
[2012-11-07 14:06:25] [info] "http-80-exec-58":
[2012-11-07 14:06:25] [info] 	at java.util.Vector.equals(Vector.java:925)
[2012-11-07 14:06:25] [info] 	- waiting to lock <0x000000071fe9bd00> 
[2012-11-07 14:06:25] [info] (a java.util.Vector)
[2012-11-07 14:06:25] [info] 	at org.apache.fop.util.CompareUtil.equal(CompareUtil.java:38)
[2012-11-07 14:06:25] [info] 	at org.apache.fop.fo.properties.ListProperty.equals(ListProperty.java:123)
[2012-11-07 14:06:25] [info] 	at org.apache.fop.fo.properties.PropertyCache.eq(PropertyCache.java:193)
[2012-11-07 14:06:25] [info] 	at org.apache.fop.fo.properties.PropertyCache.fetch(PropertyCache.java:134)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.properties.FontFamilyProperty$Maker.make(FontFamilyProperty.java:94)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.PropertyList.convertAttributeToProperty(PropertyList.java:413)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.PropertyList.addAttributesToList(PropertyList.java:321)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.FObj.processNode(FObj.java:122)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.FOTreeBuilder$MainFOHandler.startElement(FOTreeBuilder.java:280)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.FOTreeBuilder.startElement(FOTreeBuilder.java:175)
[2012-11-07 14:06:26] [info] 	at org.apache.xalan.transformer.TransformerIdentityImpl.startElement(TransformerIdentityImpl.java:1073)
[2012-11-07 14:06:26] [info] 	at org.apache.xml.serializer.TreeWalker.startNode(TreeWalker.java:359)
[2012-11-07 14:06:26] [info] 	at org.apache.xml.serializer.TreeWalker.traverse(TreeWalker.java:145)
[2012-11-07 14:06:26] [info] 	at org.apache.xalan.transformer.TransformerIdentityImpl.transform(TransformerIdentityImpl.java:390)
[2012-11-07 14:06:26] [info] 	at smc.fop.FopWrapper.transform(FopWrapper.java:150)
[2012-11-07 14:06:26] [info] 	at smc.fop.FopWrapper.transform(FopWrapper.java:125)
[2012-11-07 14:06:26] [info] 	at smc.plugin.Dom2PDF.process(Dom2PDF.java:179)
[2012-11-07 14:06:26] [info] 	at sun.reflect.GeneratedMethodAccessor97.invoke(Unknown Source)
[2012-11-07 14:06:26] [info] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[2012-11-07 14:06:26] [info] 	at java.lang.reflect.Method.invoke(Method.java:597)
[2012-11-07 14:06:26] [info] 	at smc.transform.core.dynacode.DynaCode$MyInvocationHandler.invoke(DynaCode.java:374)
[2012-11-07 14:06:26] [info] 	at $Proxy35.process(Unknown Source)
[2012-11-07 14:06:26] [info] 	at smc.transform.core.TransformerStep.processDocument(TransformerStep.java:211)
[2012-11-07 14:06:26] [info] 	at smc.transform.core.Transformer.process(Transformer.java:491)
[2012-11-07 14:06:26] [info] 	at smc.transform.core.Transformer.process(Transformer.java:442)
[2012-11-07 14:06:26] [info] 	at smc.transform.TransformServlet.doGet(TransformServlet.java:184)
[2012-11-07 14:06:26] [info] 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
[2012-11-07 14:06:26] [info] 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:378)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.intercept.web.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:109)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.intercept.web.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:83)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.ExceptionTranslationFilter.doFilterHttp(ExceptionTranslationFilter.java:101)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.providers.anonymous.AnonymousProcessingFilter.doFilterHttp(AnonymousProcessingFilter.java:105)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.wrapper.SecurityContextHolderAwareRequestFilter.doFilterHttp(SecurityContextHolderAwareRequestFilter.java:91)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.basicauth.BasicProcessingFilter.doFilterHttp(BasicProcessingFilter.java:174)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.AbstractProcessingFilter.doFilterHttp(AbstractProcessingFilter.java:277)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.logout.LogoutFilter.doFilterHttp(LogoutFilter.java:89)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.context.HttpSessionContextIntegrationFilter.doFilterHttp(HttpSessionContextIntegrationFilter.java:235)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy.doFilter(FilterChainProxy.java:175)
[2012-11-07 14:06:26] [info] 	at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:183)
[2012-11-07 14:06:26] [info] 	at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:138)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:286)
[2012-11-07 14:06:26] [info] 	at org.apache.coyote.http11.Http11NioProcessor.process(Http11NioProcessor.java:880)
[2012-11-07 14:06:26] [info] 	at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:719)
[2012-11-07 14:06:26] [info] 	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:2081)
[2012-11-07 14:06:26] [info] 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[2012-11-07 14:06:26] [info] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[2012-11-07 14:06:26] [info] 	at java.lang.Thread.run(Thread.java:662)
[2012-11-07 14:06:26] [info] "http-80-exec-5":
[2012-11-07 14:06:26] [info] 	at java.util.Vector.size(Vector.java:268)
[2012-11-07 14:06:26] [info] 	- waiting to lock <0x000000071fe9a000> 
[2012-11-07 14:06:26] [info] (a java.util.Vector)
[2012-11-07 14:06:26] [info] 	at java.util.AbstractList.listIterator(AbstractList.java:312)
[2012-11-07 14:06:26] [info] 	at java.util.AbstractList.listIterator(AbstractList.java:284)
[2012-11-07 14:06:26] [info] 	at java.util.AbstractList.equals(AbstractList.java:503)
[2012-11-07 14:06:26] [info] 	at java.util.Vector.equals(Vector.java:925)
[2012-11-07 14:06:26] [info] 	- locked <0x000000071fe9bd00> 
[2012-11-07 14:06:26] [info] (a java.util.Vector)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.util.CompareUtil.equal(CompareUtil.java:38)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.properties.ListProperty.equals(ListProperty.java:123)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.util.CompareUtil.equal(CompareUtil.java:38)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.properties.CommonFont.equals(CommonFont.java:240)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.properties.PropertyCache.eq(PropertyCache.java:193)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.properties.PropertyCache.fetch(PropertyCache.java:134)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.properties.CommonFont.getInstance(CommonFont.java:132)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.PropertyList.getFontProps(PropertyList.java:642)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.flow.Block.bind(Block.java:111)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.FObj.processNode(FObj.java:124)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.FOTreeBuilder$MainFOHandler.startElement(FOTreeBuilder.java:280)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.FOTreeBuilder.startElement(FOTreeBuilder.java:175)
[2012-11-07 14:06:26] [info] 	at org.apache.xalan.transformer.TransformerIdentityImpl.startElement(TransformerIdentityImpl.java:1073)
[2012-11-07 14:06:26] [info] 	at org.apache.xml.serializer.TreeWalker.startNode(TreeWalker.java:359)
[2012-11-07 14:06:26] [info] 	at org.apache.xml.serializer.TreeWalker.traverse(TreeWalker.java:145)
[2012-11-07 14:06:26] [info] 	at org.apache.xalan.transformer.TransformerIdentityImpl.transform(TransformerIdentityImpl.java:390)
[2012-11-07 14:06:26] [info] 	at smc.fop.FopWrapper.transform(FopWrapper.java:150)
[2012-11-07 14:06:26] [info] 	at smc.fop.FopWrapper.transform(FopWrapper.java:125)
[2012-11-07 14:06:26] [info] 	at smc.plugin.Dom2PDF.process(Dom2PDF.java:179)
[2012-11-07 14:06:26] [info] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2012-11-07 14:06:26] [info] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[2012-11-07 14:06:26] [info] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[2012-11-07 14:06:26] [info] 	at java.lang.reflect.Method.invoke(Method.java:597)
[2012-11-07 14:06:26] [info] 	at smc.transform.core.dynacode.DynaCode$MyInvocationHandler.invoke(DynaCode.java:374)
[2012-11-07 14:06:26] [info] 	at $Proxy35.process(Unknown Source)
[2012-11-07 14:06:26] [info] 	at smc.transform.core.TransformerStep.processDocument(TransformerStep.java:211)
[2012-11-07 14:06:26] [info] 	at smc.transform.core.Transformer.process(Transformer.java:491)
[2012-11-07 14:06:26] [info] 	at smc.transform.core.Transformer.process(Transformer.java:442)
[2012-11-07 14:06:26] [info] 	at smc.transform.TransformServlet.doGet(TransformServlet.java:184)
[2012-11-07 14:06:26] [info] 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
[2012-11-07 14:06:26] [info] 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:378)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.intercept.web.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:109)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.intercept.web.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:83)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.ExceptionTranslationFilter.doFilterHttp(ExceptionTranslationFilter.java:101)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.providers.anonymous.AnonymousProcessingFilter.doFilterHttp(AnonymousProcessingFilter.java:105)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.wrapper.SecurityContextHolderAwareRequestFilter.doFilterHttp(SecurityContextHolderAwareRequestFilter.java:91)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.basicauth.BasicProcessingFilter.doFilterHttp(BasicProcessingFilter.java:174)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.AbstractProcessingFilter.doFilterHttp(AbstractProcessingFilter.java:277)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.logout.LogoutFilter.doFilterHttp(LogoutFilter.java:89)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.context.HttpSessionContextIntegrationFilter.doFilterHttp(HttpSessionContextIntegrationFilter.java:235)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy.doFilter(FilterChainProxy.java:175)
[2012-11-07 14:06:26] [info] 	at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:183)
[2012-11-07 14:06:26] [info] 	at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:138)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:286)
[2012-11-07 14:06:26] [info] 	at org.apache.coyote.http11.Http11NioProcessor.process(Http11NioProcessor.java:880)
[2012-11-07 14:06:26] [info] 	at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:719)
[2012-11-07 14:06:26] [info] 	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:2081)
[2012-11-07 14:06:26] [info] 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[2012-11-07 14:06:26] [info] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[2012-11-07 14:06:26] [info] 	at java.lang.Thread.run(Thread.java:662)
[2012-11-07 14:06:26] [info] "http-80-exec-18":
[2012-11-07 14:06:26] [info] 	at java.util.Vector.get(Vector.java:693)
[2012-11-07 14:06:26] [info] 	- waiting to lock <0x000000071fe9bd00> 
[2012-11-07 14:06:26] [info] (a java.util.Vector)
[2012-11-07 14:06:26] [info] 	at java.util.AbstractList$Itr.next(AbstractList.java:345)
[2012-11-07 14:06:26] [info] 	at java.util.AbstractList.equals(AbstractList.java:506)
[2012-11-07 14:06:26] [info] 	at java.util.Vector.equals(Vector.java:925)
[2012-11-07 14:06:26] [info] 	- locked <0x000000071fe9a000> 
[2012-11-07 14:06:26] [info] (a java.util.Vector)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.util.CompareUtil.equal(CompareUtil.java:38)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.properties.ListProperty.equals(ListProperty.java:123)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.util.CompareUtil.equal(CompareUtil.java:38)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.properties.CommonFont.equals(CommonFont.java:240)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.properties.PropertyCache.eq(PropertyCache.java:193)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.properties.PropertyCache.fetch(PropertyCache.java:134)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.properties.CommonFont.getInstance(CommonFont.java:132)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.PropertyList.getFontProps(PropertyList.java:642)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.flow.Block.bind(Block.java:111)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.FObj.processNode(FObj.java:124)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.FOTreeBuilder$MainFOHandler.startElement(FOTreeBuilder.java:280)
[2012-11-07 14:06:26] [info] 	at org.apache.fop.fo.FOTreeBuilder.startElement(FOTreeBuilder.java:175)
[2012-11-07 14:06:26] [info] 	at org.apache.xalan.transformer.TransformerIdentityImpl.startElement(TransformerIdentityImpl.java:1073)
[2012-11-07 14:06:26] [info] 	at org.apache.xml.serializer.TreeWalker.startNode(TreeWalker.java:359)
[2012-11-07 14:06:26] [info] 	at org.apache.xml.serializer.TreeWalker.traverse(TreeWalker.java:145)
[2012-11-07 14:06:26] [info] 	at org.apache.xalan.transformer.TransformerIdentityImpl.transform(TransformerIdentityImpl.java:390)
[2012-11-07 14:06:26] [info] 	at smc.fop.FopWrapper.transform(FopWrapper.java:150)
[2012-11-07 14:06:26] [info] 	at smc.fop.FopWrapper.transform(FopWrapper.java:125)
[2012-11-07 14:06:26] [info] 	at smc.plugin.Dom2PDF.process(Dom2PDF.java:179)
[2012-11-07 14:06:26] [info] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2012-11-07 14:06:26] [info] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[2012-11-07 14:06:26] [info] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[2012-11-07 14:06:26] [info] 	at java.lang.reflect.Method.invoke(Method.java:597)
[2012-11-07 14:06:26] [info] 	at smc.transform.core.dynacode.DynaCode$MyInvocationHandler.invoke(DynaCode.java:374)
[2012-11-07 14:06:26] [info] 	at $Proxy35.process(Unknown Source)
[2012-11-07 14:06:26] [info] 	at smc.transform.core.TransformerStep.processDocument(TransformerStep.java:211)
[2012-11-07 14:06:26] [info] 	at smc.transform.core.Transformer.process(Transformer.java:491)
[2012-11-07 14:06:26] [info] 	at smc.transform.core.Transformer.process(Transformer.java:442)
[2012-11-07 14:06:26] [info] 	at smc.transform.TransformServlet.doGet(TransformServlet.java:184)
[2012-11-07 14:06:26] [info] 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
[2012-11-07 14:06:26] [info] 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
[2012-11-07 14:06:26] [info] 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:378)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.intercept.web.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:109)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.intercept.web.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:83)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.ExceptionTranslationFilter.doFilterHttp(ExceptionTranslationFilter.java:101)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.providers.anonymous.AnonymousProcessingFilter.doFilterHttp(AnonymousProcessingFilter.java:105)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.wrapper.SecurityContextHolderAwareRequestFilter.doFilterHttp(SecurityContextHolderAwareRequestFilter.java:91)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:26] [info] 	at org.springframework.security.ui.basicauth.BasicProcessingFilter.doFilterHttp(BasicProcessingFilter.java:174)
[2012-11-07 14:06:27] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:27] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:27] [info] 	at org.springframework.security.ui.AbstractProcessingFilter.doFilterHttp(AbstractProcessingFilter.java:277)
[2012-11-07 14:06:27] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:27] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:27] [info] 	at org.springframework.security.ui.logout.LogoutFilter.doFilterHttp(LogoutFilter.java:89)
[2012-11-07 14:06:27] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:27] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:27] [info] 	at org.springframework.security.context.HttpSessionContextIntegrationFilter.doFilterHttp(HttpSessionContextIntegrationFilter.java:235)
[2012-11-07 14:06:27] [info] 	at org.springframework.security.ui.SpringSecurityFilter.doFilter(SpringSecurityFilter.java:53)
[2012-11-07 14:06:27] [info] 	at org.springframework.security.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:390)
[2012-11-07 14:06:27] [info] 	at org.springframework.security.util.FilterChainProxy.doFilter(FilterChainProxy.java:175)
[2012-11-07 14:06:27] [info] 	at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:183)
[2012-11-07 14:06:27] [info] 	at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:138)
[2012-11-07 14:06:27] [info] 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
[2012-11-07 14:06:27] [info] 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
[2012-11-07 14:06:27] [info] 	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
[2012-11-07 14:06:27] [info] 	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
[2012-11-07 14:06:27] [info] 	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
[2012-11-07 14:06:27] [info] 	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
[2012-11-07 14:06:27] [info] 	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
[2012-11-07 14:06:27] [info] 	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:286)
[2012-11-07 14:06:27] [info] 	at org.apache.coyote.http11.Http11NioProcessor.process(Http11NioProcessor.java:880)
[2012-11-07 14:06:27] [info] 	at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:719)
[2012-11-07 14:06:27] [info] 	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:2081)
[2012-11-07 14:06:27] [info] 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[2012-11-07 14:06:27] [info] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[2012-11-07 14:06:27] [info] 	at java.lang.Thread.run(Thread.java:662)
[2012-11-07 14:06:27] [info] 
Found 1 deadlock.
Comment 1 Alex Giotis 2012-11-08 08:33:30 UTC 
Please attach an XSL-FO that any of Tomcat's "http-80-exec-*" were rendering so that this can be reproduced and then verify that it is resolved.
Comment 2 Gareth Bowen 2012-12-03 02:54:01 UTC 
Created attachment 29665 [details]
Thread dump snippet
Comment 3 Gareth Bowen 2012-12-03 03:07:39 UTC 
I've just hit this deadlock with FOP 1.1 in our production system (thread dump snippet attached). It ran fine for a couple of weeks and then locked up. Given this it would appear to be a race condition, and could not be reproduced by running the same XSL-FO as requested by Alex Giotis.

It looks like this may have been exposed by the refactoring of PropertyCache for 1.1, but my initial investigation suggests the root of the cause is putting a Vector in the PropertyCache. When two threads are fetching from the cache they compare two Vectors to each other and deadlock on the synchronized equals and listIterator methods.

It would be better to use some other List implementation, or failing that, synchronizing the cache fetch method.
Comment 4 Alex Giotis 2012-12-03 11:25:33 UTC 
Gareth, I believe that this is a bug exposed by fixing some equals/hashcode implementations. Those changes were introduced during the refactoring of PropertyCache (as you wrote) and I also believe that the usage of Vectors is problematic. I would prefer to have UnmodifiableLists (or some other immutable structure) containing trimToSize() ArrayLists to minimise memory requirements.


With my previous comment, I was asking for an XSL:FO that has the potential of triggering this deadlock. To reproduce it, one would need to render it concurrently by different threads, probably connect a debugger and put some breakpoints or change code to add some delays.

I understand that this is not always easy as one may need to anonymise the input. I guess I would see blocks like:

<fo:block font-family="Arial" font-size="12pt">
and 
<fo:block font-size="12pt" font-family="Arial">

but the effort to fix it would be wasted if this is wrong.
Comment 5 Gareth Bowen 2012-12-03 21:13:14 UTC 
(In reply to comment #4)

Right, that makes sense. Unfortunately it's not possible to determine from our stack trace which fo was being used, but it's quite likely somewhere in our codebase we have defined the parameters in a different order.