You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cxf.apache.org by Sachin Nikam <sk...@gmail.com> on 2014/02/26 20:15:21 UTC

Possible deadlock in cxf

I have thread dump from the jvm and looks like there is a deadlock. Almost
all the threads are BLOCKED in WSDLGetInterceptor.handleMessage() while
waiting on a lock for an Object whose internal id=0x00000000b0fab6d.  There
is another thread which has acquired this Object's lock but is waiting  for
a lock on Object id=0x00000000ae68d7c0. This Object id does not appear
anywhere else in the thread dump. I will probably need a Heap Dump to
figure out which object is being referred.

Holding a lock on an object and trying to acquire another lock is an
anti-pattern known to cause deadlock issues.

Has anybody else run in to this issue before and identified the root cause
and resolution?

Could this be related to the fact that my current logback configuration did
not set a MaxHistory value with the result that the number of log files
kept on increasing without any trimming? I am going to fix that issue but I
am not sure it will fix the deadlock issue.

Any clues or ideas would be helpful.



*******Example stack trace of threads Blocked***************

INFO   | jvm 1    | 2014/02/25 19:41:45 | "qtp87423451-4981" prio=10
tid=0x00007fed3c331800 nid=0x6766 waiting for monitor entry
[0x00007fece43c2000]

INFO   | jvm 1    | 2014/02/25 19:41:45 |    java.lang.Thread.State:
BLOCKED (on object monitor)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.frontend.WSDLGetInterceptor.handleMessage(WSDLGetInterceptor.java:100)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 - waiting to lock
<0x00000000b0fab6d0> (a org.apache.cxf.jaxws.support.JaxWsEndpointImpl)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:271)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 - locked
<0x00000000a71042c0> (a





************Stack Trace of Thread causing the deadlock***********



INFO   | jvm 1    | 2014/02/25 19:41:45 |    java.lang.Thread.State:
WAITING (parking)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
sun.misc.Unsafe.park(Native Method)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 - parking to wait
for  <0x00000000ae68d7c0> (a java.util.concurrent.Semaphore$NonfairSync)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:994)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1303)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
java.util.concurrent.Semaphore.acquire(Semaphore.java:317)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.eclipse.jetty.util.BlockingCallback.block(BlockingCalbback.java:96)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:662)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:198)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.io.AbstractWrappedOutputStream.write(AbstractWrappedOutputStream.java:51)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
com.ctc.wstx.io.UTF8Writer.write(UTF8Writer.java:143)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
com.ctc.wstx.sw.BufferingXmlWriter.flushBuffer(BufferingXmlWriter.java:1366)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
com.ctc.wstx.sw.BufferingXmlWriter.writeAttrValue(BufferingXmlWriter.java:1055)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
com.ctc.wstx.sw.BufferingXmlWriter.writeAttribute(BufferingXmlWriter.java:883)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
com.ctc.wstx.sw.BaseNsStreamWriter.doWriteAttr(BaseNsStreamWriter.java:516)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
com.ctc.wstx.sw.BaseNsStreamWriter.writeAttribute(BaseNsStreamWriter.java:228)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:915)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:838)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeNode(StaxUtils.java:975)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:940)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:838)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeNode(StaxUtils.java:975)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:940)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:838)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeNode(StaxUtils.java:975)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:940)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:838)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeNode(StaxUtils.java:975)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:940)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:838)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeNode(StaxUtils.java:975)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:940)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:838)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeNode(StaxUtils.java:975)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeDocument(StaxUtils.java:816)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeDocument(StaxUtils.java:804)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.staxutils.StaxUtils.writeNode(StaxUtils.java:994)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
org.apache.cxf.frontend.WSDLGetInterceptor.handleMessage(WSDLGetInterceptor.java:129)

INFO   | jvm 1    | 2014/02/25 19:41:45 |                 - locked <
0x00000000b0fab6d0> (a org.apache.cxf.jaxws.support.JaxWsEndpointImpl)

Re: Possible deadlock in cxf

Posted by Daniel Kulp <dk...@apache.org>.
What version of CXF?   I believe this has been fixed for a while.  Can you retry with 2.7.10?

Dan



On Feb 26, 2014, at 2:15 PM, Sachin Nikam <sk...@gmail.com> wrote:

> I have thread dump from the jvm and looks like there is a deadlock. Almost
> all the threads are BLOCKED in WSDLGetInterceptor.handleMessage() while
> waiting on a lock for an Object whose internal id=0x00000000b0fab6d.  There
> is another thread which has acquired this Object's lock but is waiting  for
> a lock on Object id=0x00000000ae68d7c0. This Object id does not appear
> anywhere else in the thread dump. I will probably need a Heap Dump to
> figure out which object is being referred.
> 
> Holding a lock on an object and trying to acquire another lock is an
> anti-pattern known to cause deadlock issues.
> 
> Has anybody else run in to this issue before and identified the root cause
> and resolution?
> 
> Could this be related to the fact that my current logback configuration did
> not set a MaxHistory value with the result that the number of log files
> kept on increasing without any trimming? I am going to fix that issue but I
> am not sure it will fix the deadlock issue.
> 
> Any clues or ideas would be helpful.
> 
> 
> 
> *******Example stack trace of threads Blocked***************
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 | "qtp87423451-4981" prio=10
> tid=0x00007fed3c331800 nid=0x6766 waiting for monitor entry
> [0x00007fece43c2000]
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |    java.lang.Thread.State:
> BLOCKED (on object monitor)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.frontend.WSDLGetInterceptor.handleMessage(WSDLGetInterceptor.java:100)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 - waiting to lock
> <0x00000000b0fab6d0> (a org.apache.cxf.jaxws.support.JaxWsEndpointImpl)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:271)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 - locked
> <0x00000000a71042c0> (a
> 
> 
> 
> 
> 
> ************Stack Trace of Thread causing the deadlock***********
> 
> 
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |    java.lang.Thread.State:
> WAITING (parking)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> sun.misc.Unsafe.park(Native Method)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 - parking to wait
> for  <0x00000000ae68d7c0> (a java.util.concurrent.Semaphore$NonfairSync)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:994)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1303)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> java.util.concurrent.Semaphore.acquire(Semaphore.java:317)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.eclipse.jetty.util.BlockingCallback.block(BlockingCalbback.java:96)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:662)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:198)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.io.AbstractWrappedOutputStream.write(AbstractWrappedOutputStream.java:51)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> com.ctc.wstx.io.UTF8Writer.write(UTF8Writer.java:143)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> com.ctc.wstx.sw.BufferingXmlWriter.flushBuffer(BufferingXmlWriter.java:1366)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> com.ctc.wstx.sw.BufferingXmlWriter.writeAttrValue(BufferingXmlWriter.java:1055)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> com.ctc.wstx.sw.BufferingXmlWriter.writeAttribute(BufferingXmlWriter.java:883)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> com.ctc.wstx.sw.BaseNsStreamWriter.doWriteAttr(BaseNsStreamWriter.java:516)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> com.ctc.wstx.sw.BaseNsStreamWriter.writeAttribute(BaseNsStreamWriter.java:228)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:915)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:838)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeNode(StaxUtils.java:975)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:940)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:838)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeNode(StaxUtils.java:975)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:940)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:838)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeNode(StaxUtils.java:975)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:940)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:838)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeNode(StaxUtils.java:975)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:940)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:838)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeNode(StaxUtils.java:975)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:940)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeElement(StaxUtils.java:838)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeNode(StaxUtils.java:975)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeDocument(StaxUtils.java:816)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeDocument(StaxUtils.java:804)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.staxutils.StaxUtils.writeNode(StaxUtils.java:994)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 at
> org.apache.cxf.frontend.WSDLGetInterceptor.handleMessage(WSDLGetInterceptor.java:129)
> 
> INFO   | jvm 1    | 2014/02/25 19:41:45 |                 - locked <
> 0x00000000b0fab6d0> (a org.apache.cxf.jaxws.support.JaxWsEndpointImpl)

-- 
Daniel Kulp
dkulp@apache.org - http://dankulp.com/blog
Talend Community Coder - http://coders.talend.com