Deadlock in consoleappender using logback in jetty
--------------------------------------------------
Key: LBCORE-99
URL: http://jira.qos.ch/browse/LBCORE-99
Project: logback-core
Issue Type: Bug
Components: Appender
Affects Versions: 0.9.15
Environment: Maven 2.1.0 jetty plugin on ubuntu linux.
maven dependencies list ...
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-ext</artifactId>
<version>1.5.8</version>
<type>jar</type>
</dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>jcl-over-slf4j</artifactId>
<version>1.5.8</version>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-core</artifactId>
<version>0.9.15</version>
<type>jar</type>
</dependency>
<dependency>
<groupId>ch.qos.logback</groupId>
<artifactId>logback-classic</artifactId>
<version>0.9.15</version>
<type>jar</type>
</dependency>
<dependency>
<groupId>commons-logging</groupId>
<artifactId>commons-logging</artifactId>
<version>99.0-does-not-exist</version>
</dependency
Reporter: Sakib Mehasanewala
Assignee: Logback dev list
I came across this deadlock while running jetty via plugin in maven to run
functional tests...
Found one Java-level deadlock:
=============================
"Shutdown":
waiting to lock monitor 0xb52073c0 (object 0x7395a770, a
ch.qos.logback.core.ConsoleAppender),
which is held by "32900...@qtp0-0 - /cbs2/v1.0/ws/cbs2.wsdl"
"32900...@qtp0-0 - /cbs2/v1.0/ws/cbs2.wsdl":
waiting to lock monitor 0xb5209bfc (object 0x7391a760, a
org.mortbay.jetty.webapp.WebAppClassLoader),
which is held by "15510...@qtp0-2 - /cbs2/v1.0/ws/cbs2.wsdl"
"15510...@qtp0-2 - /cbs2/v1.0/ws/cbs2.wsdl":
waiting to lock monitor 0xb52073c0 (object 0x7395a770, a
ch.qos.logback.core.ConsoleAppender),
which is held by "32900...@qtp0-0 - /cbs2/v1.0/ws/cbs2.wsdl"
Java stack information for the threads listed above:
===================================================
"Shutdown":
at ch.qos.logback.core.AppenderBase.doAppend(AppenderBase.java:66)
- waiting to lock <0x7395a770> (a ch.qos.logback.core.ConsoleAppender)
at
ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:60)
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
at
ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:439)
at ch.qos.logback.classic.Logger.filterAndLog_2(Logger.java:430)
at ch.qos.logback.classic.Logger.info(Logger.java:605)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.mortbay.log.Slf4jLog.info(Slf4jLog.java:103)
at org.mortbay.log.Log.info(Log.java:132)
at org.mortbay.jetty.Server$ShutdownHookThread.run(Server.java:550)
"32900...@qtp0-0 - /cbs2/v1.0/ws/cbs2.wsdl":
at
org.mortbay.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:341)
- waiting to lock <0x7391a760> (a
org.mortbay.jetty.webapp.WebAppClassLoader)
at
ch.qos.logback.classic.spi.PackagingDataCalculator.loadClass(PackagingDataCalculator.java:232)
at
ch.qos.logback.classic.spi.PackagingDataCalculator.bestEffortLoadClass(PackagingDataCalculator.java:257)
at
ch.qos.logback.classic.spi.PackagingDataCalculator.computeBySTEP(PackagingDataCalculator.java:166)
at
ch.qos.logback.classic.spi.PackagingDataCalculator.populateFrames(PackagingDataCalculator.java:97)
at
ch.qos.logback.classic.spi.PackagingDataCalculator.calculate(PackagingDataCalculator.java:61)
at
ch.qos.logback.classic.spi.ThrowableProxy.calculatePackagingData(ThrowableProxy.java:50)
at
ch.qos.logback.classic.pattern.ExtendedThrowableProxyConverter.prepareLoggingEvent(ExtendedThrowableProxyConverter.java:35)
at
ch.qos.logback.classic.pattern.ThrowableProxyConverter.convert(ThrowableProxyConverter.java:142)
at
ch.qos.logback.classic.pattern.ThrowableProxyConverter.convert(ThrowableProxyConverter.java:30)
at
ch.qos.logback.core.pattern.FormattingConverter.write(FormattingConverter.java:32)
at
ch.qos.logback.core.pattern.PatternLayoutBase.writeLoopOnConverters(PatternLayoutBase.java:110)
at
ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:132)
at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:51)
at
ch.qos.logback.core.WriterAppender.subAppend(WriterAppender.java:261)
at ch.qos.logback.core.WriterAppender.append(WriterAppender.java:114)
at ch.qos.logback.core.AppenderBase.doAppend(AppenderBase.java:87)
- locked <0x7395a770> (a ch.qos.logback.core.ConsoleAppender)
at
ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:60)
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
at
ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:439)
at
ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:393)
at ch.qos.logback.classic.Logger.warn(Logger.java:710)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.mortbay.log.Slf4jLog.warn(Slf4jLog.java:128)
at org.mortbay.log.Log.warn(Log.java:181)
at org.mortbay.log.Log.unwind(Log.java:216)
at org.mortbay.log.Log.warn(Log.java:182)
at org.mortbay.log.Log.unwind(Log.java:216)
at org.mortbay.log.Log.warn(Log.java:182)
at
org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:414)
at
org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at
org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
at
org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
at
org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:417)
at
org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
at
org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at
org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:320)
at
org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:534)
at
org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:864)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:533)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:207)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:403)
at
org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
at
org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:522)
"15510...@qtp0-2 - /cbs2/v1.0/ws/cbs2.wsdl":
at ch.qos.logback.core.AppenderBase.doAppend(AppenderBase.java:66)
- waiting to lock <0x7395a770> (a ch.qos.logback.core.ConsoleAppender)
at
ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:60)
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
at
ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:439)
at ch.qos.logback.classic.Logger.filterAndLog_2(Logger.java:430)
at ch.qos.logback.classic.Logger.debug(Logger.java:508)
at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.mortbay.log.Slf4jLog.debug(Slf4jLog.java:73)
at org.mortbay.log.Log.debug(Log.java:90)
at
org.mortbay.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:388)
- locked <0x7391a760> (a org.mortbay.jetty.webapp.WebAppClassLoader)
at
org.mortbay.jetty.webapp.WebAppClassLoader.loadClass(WebAppClassLoader.java:341)
- locked <0x7391a760> (a org.mortbay.jetty.webapp.WebAppClassLoader)
at
com.sun.org.apache.xerces.internal.parsers.ObjectFactory.findProviderClass(ObjectFactory.java:393)
at
com.sun.org.apache.xerces.internal.parsers.ObjectFactory.newInstance(ObjectFactory.java:348)
at
com.sun.org.apache.xerces.internal.parsers.ObjectFactory.createObject(ObjectFactory.java:154)
at
com.sun.org.apache.xerces.internal.parsers.ObjectFactory.createObject(ObjectFactory.java:97)
at
com.sun.org.apache.xerces.internal.parsers.DOMParser.<init>(DOMParser.java:125)
at
com.sun.org.apache.xerces.internal.parsers.DOMParser.<init>(DOMParser.java:109)
at
com.sun.org.apache.xerces.internal.jaxp.DocumentBuilderImpl.<init>(DocumentBuilderImpl.java:115)
at
com.sun.org.apache.xerces.internal.jaxp.DocumentBuilderFactoryImpl.newDocumentBuilder(DocumentBuilderFactoryImpl.java:72)
at
com.sun.org.apache.xalan.internal.xsltc.trax.SAX2DOM.<init>(SAX2DOM.java:69)
- locked <0x912b1278> (a java.lang.Class for
com.sun.org.apache.xalan.internal.xsltc.trax.SAX2DOM)
at
com.sun.org.apache.xalan.internal.xsltc.runtime.output.TransletOutputHandlerFactory.getSerializationHandler(TransletOutputHandlerFactory.java:187)
at
com.sun.org.apache.xalan.internal.xsltc.trax.TransformerImpl.getOutputHandler(TransformerImpl.java:392)
at
com.sun.org.apache.xalan.internal.xsltc.trax.TransformerImpl.transform(TransformerImpl.java:298)
at
org.springframework.ws.transport.http.WsdlDefinitionHandlerAdapter.handle(WsdlDefinitionHandlerAdapter.java:125)
at
org.springframework.ws.transport.http.MessageDispatcherServlet.doService(MessageDispatcherServlet.java:222)
at
org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:613)
at
org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:525)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at
org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:502)
at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1124)
at
com.diginsite.services.cbs2.filter.ClearRequestContextFilter.doFilter(ClearRequestContextFilter.java:34)
at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1115)
at
org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:361)
at
org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at
org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
at
org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:417)
at
org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
at
org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at
org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:320)
at
org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:534)
at
org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:864)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:533)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:207)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:403)
at
org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
at
org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:522)
Found 1 deadlock.
Heap
def new generation total 3904K, used 115K [0x70060000, 0x70490000,
0x727c0000)
eden space 3520K, 3% used [0x70060000, 0x7007cda8, 0x703d0000)
from space 384K, 0% used [0x703d0000, 0x703d0000, 0x70430000)
to space 384K, 0% used [0x70430000, 0x70430000, 0x70490000)
tenured generation total 50668K, used 26395K [0x727c0000, 0x7593b000,
0x90060000)
the space 50668K, 52% used [0x727c0000, 0x74186f40, 0x74187000, 0x7593b000)
compacting perm gen total 20736K, used 20517K [0x90060000, 0x914a0000,
0x94060000)
the space 20736K, 98% used [0x90060000, 0x914697a0, 0x91469800, 0x914a0000)
ro space 8192K, 74% used [0x94060000, 0x94658b48, 0x94658c00, 0x94860000)
rw space 12288K, 58% used [0x94860000, 0x94f73df0, 0x94f73e00, 0x95460000)
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://jira.qos.ch/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
_______________________________________________
logback-dev mailing list
[email protected]
http://qos.ch/mailman/listinfo/logback-dev
