[
https://issues.apache.org/jira/browse/FOP-2157?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13713586#comment-13713586
]
Johannes Herr commented on FOP-2157:
------------------------------------
We have had the same problem in our test environment (see the attached
thread-dump).
I have been able to reproduce the problem in the debugger. The following
describes the result of my analysis.
As Gareth explained the deadlock happens when two Vectors V1 and V2 are
compared with each other by two threads at the same time. Moreover the
comparisons have the forms:
V1.equals(V2)
V2.equals(V1)
and not
V1.equals(V2)
V1.equals(V2)
This is important since otherwise there would be lock-ordering and no deadlock.
The Vectors in this case are contained in FontFamilyProperties which are
contained in CommontFonts. (We know this, since line 240 in CommonFont appears
in the traces, which does the comparison 'CompareUtil.equal(fontFamily,
other.fontFamily)'.)
The comparison of the CommonFonts takes place in PropertyCache.fetch(..) in
line 134:
if (eq(cached, obj)) {
The previously cached object is compared with the newly created one. To create
the deadlock we need two threads that execute this line at the same time where
for Thread A the 'cached' object contains V1 and the new 'obj' contains V2 and
for Thread B the 'cached' object contains V2 and the new 'obj' contains V1
(again because if the order was the same there would be no deadlock because of
lock ordering).
So at first glance the problem seems easy to reproduce. It becomes tricky
however because the PropertyCaches seem to ensure that there is always only one
instance of a class (with equal values) in use. If that would be the case we
would always compare the cached version (say V1) with new Version (V2, V3, V4),
which cannot lead to this deadlock. Also when the WeakReference for V1 is
cleared we would expect to compare V2 with V3, V4, ... and not somehow compare
V2 with V1 at the same time that V1 is compared with V2.
The trick is line 151 in the PropertyCache:
map.put(hashCode, new WeakReference<T>(obj));
This line is executed when there was an entry in the cache, but its reference
has already been cleared by the GC.
Because of this line we can have 2 Threads A and B at this line, A with an
object containing V1 and B with an object containing V2. A adds the element to
the cache, while B waits for a while. A number of other threads pick up V1 from
the cache, then Thread B adds V2 to the cache and other threads pick up V2 from
the cache. In this way we have multiple threads with V1 and V2 running at the
same time which can lead to the comparison that produces the deadlock.
That's the rough idea, now the steps to actually reproduce the problem in the
debugger. You need an application which keeps running and repeatedly executes
FOP with a number of threads. Between the runs the weak references to
FontFamilyProperty and CommonFont need to be cleared, so don't keep any strong
references to FOP around between the runs.
1. Trigger the generation
There will be an entry for the FontFamilyProperty in the cache.
2. (Maybe) run Garbage Collection (i.e. through JVisualVM)
This clears the WeakReference to the FontFamilyProperty, but keeps the
WeakReference itself in the cache.
3. Place a breakpoint in line 151 of the PropertyCache and wait for 2
FontFamilyProperties
map.put(hashCode, new WeakReference<T>(obj));
Note that this line is only reached, when there is a cleared WeakReference in
the cache.
(Unfortunately I had weired Eclipse error msgs, with conditional breakpoints
here, so either use a conditional breakpoint or just wait till the breakpoint
is hit by a FontFamilyProperty.)
I would suggest noting the object-ids of these FontFamilyProperties for later
reference. (Btw these contain our vectors V1 and V2 that will later produce the
deadlock.)
4. Place a breakpoint in line 119 of PropertyCache (to stop threads from
putting a CommonFont in the cache).
5. Let one of the Threads with FontFamilyProperties in line 151 execute the put
to place its object in the cache, while still keeping the other Thread stopped.
6. Wait for 2 Threads where obj instanceof CommonFont in line 119 (the
breakpoint set in step 4):
Integer hashCode = Integer.valueOf(obj.hashCode());
These will contain the FontFamilyProperty with V1, because it has been in the
cache at this time.
7. Now place the second FontFamilyProperty in the cache.
8. Wait for 2 more Threads at line 119, which now hold a reference to a
FontFamilyProperty with V2.
9. Let one of the V1 Threads at line 119 execute up to line 151, that is to the
unconditional put of a CommonFont. (Again it is only possible to reach line 151
if there is a cleared WeakReference in the cache, so you must put your
breakpoints accordingly so that no other thread can fill the cache in the
meantime.)
10. Let one of the V2 Threads at line 119 execute up to line 151, that is to
the unconditional put of a CommonFont.
11. Let the V1 Thread put the CommonFont at line 151. That means the cache
contains now CommonFont -> FontFamilyProperty -> V1. And we have another thread
sitting in front of the unconditional put, which can put a CommonFont ->
FontFamilyProperty -> V2 in the cache in the next step.
12. Let one of the V2 Threads at line 119 execute to the the
if (eq(cached, obj)) {
at line 134. This will lead to the first comparison, V1.equals(V2).
14. Let the V2 Thread at line 151 put its object in the cache. The cache now
contains V2.
15. Let the remaining V1 Thread at line 119 execute to line 134
if (eq(cached, obj)) {
since the cache now contains V2 this is the second comparison, V2.equals(V1).
16. Put a breakpoint in line 988 of class Vector
public synchronized int hashCode() {
return super.hashCode();
}
And let the Threads calling eq(..) execute to this line. One Thread will then
have acquired a Lock for V1 the other for V2.
17. Let the Threads execute their equals implementation, they will try to
acquire the respective other lock, which will fail and we have a deadlock.
For completeness sake: In one of the above comments there was a question about
the ordering of attributes blocks. We do not have a mix of orders in our
templates:
$ grep font-family *
template_A.xsl: <fo:page-sequence master-reference="A4"
font-family="Helvetica" font-size="10pt">
template_A.xsl: <fo:page-sequence master-reference="A4"
font-family="Helvetica" font-size="10pt" >
template_A.xsl: <fo:page-sequence master-reference="A4"
font-family="Helvetica" font-size="10pt" >
template_B.xsl: <fo:page-sequence master-reference="A4"
font-family="Helvetica" font-size="10pt">
template_C.xsl: <fo:page-sequence master-reference="A4"
font-family="Helvetica" font-size="10pt">
template_D.xsl: <fo:page-sequence master-reference="A4"
font-family="Helvetica" font-size="10pt">
Sorry for the long text, hope this helps.
> Deadlock in CompareUtil class
> -----------------------------
>
> Key: FOP-2157
> URL: https://issues.apache.org/jira/browse/FOP-2157
> Project: Fop
> Issue Type: Bug
> Components: general
> Affects Versions: trunk
> Environment: Operating System: All
> Platform: PC
> Reporter: Matthias Reischenbacher
> Assignee: Alexios Giotis
> Attachments: FOP DEADLOCK jakarta_service_20121107.log,
> thread-dump.txt
>
>
> 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.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
