[ http://jira.qos.ch/browse/LBCORE-99?page=com.atlassian.jira.plugin.system.is... ] Ralph Goers commented on LBCORE-99: ----------------------------------- Interestingly, I had forgotten that UnsynchronizedAppenderBase already has the guard so the StackOverFlow won't occur. But yes, the threadLocal would be required for your patch to LBCORE-97. But even with your patch in LBCORE-97 this deadlock will still occur. The only way to prevent it is to reduce locking down to the point that it is known that another lock won't be obtained while the Appender is holding a lock.
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 "32900144@qtp0-0 - /cbs2/v1.0/ws/cbs2.wsdl" "32900144@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 "15510444@qtp0-2 - /cbs2/v1.0/ws/cbs2.wsdl" "15510444@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 "32900144@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) "32900144@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) "15510444@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