Is this something to be concerned about? We have legacy code that uses log4j directly and we also have code that uses the slf4j api + slf4jlog4j implementation. I haven't seen any problems to date but we are only in a testing phase. I'm wondering if we have just been lucky so far to miss the problem below? Cheers Paul
_____ From: user-boun...@slf4j.org [mailto:user-boun...@slf4j.org] On Behalf Of Patrick Hancke Sent: 10 February 2009 15:58 To: User list for the slf4j project Subject: Re: [slf4j-user] deadlock in slf4j-log4j12 ? It seems I've found the deadlock issue. Our code base consistently uses slf4j except in a MessageHandler which is registered with AspectJ and takes care of logging AspectJ related messages. That MessageHandler was still using the log4j API directly which most probably caused a deadlock. The solution is quite simple: I've written an slf4j MessageHandler and the deadlock seems gone. Thanks for your help, Patrick Hancke 2009/2/10 Ceki Gulcu <c...@qos.ch> Hello Patrick, Looking at the stack trace, it seems that pool-2-thread-2 after obtaining a lock on the RootLogger tries to obtain a lock on an sun.misc.Launcher$AppClassLoader instance within the org.jmock.api.ExpectationError.toString() method. Another thread namely, pool-1-thread-3, after obtaining a lock on the aforementioned sun.misc.Launcher$AppClassLoader instance tries to obtain a lock on RootLogger, hence the deadlock. Not knowing more about RetryConnectingToSocketTask, I can't suggest a solution, However, I am pretty confident that the problem is not SLF4J related. Log4j's threading model might be at cause although I doubt it. You should try to identify the place where sun.misc.Launcher$AppClassLoader is locked. HTH, Patrick Hancke wrote: I'm using slf4j version 1.5.6 in combination with log4j version 1.2.15. Java version is 1.6.0. In my unit tests, I'm experiencing a deadlock which seems related to slf4j / log4j. Below is a thread dump. Anybody experienced similar problems? --------------- [snip] JNI global references: 973 Found one Java-level deadlock: ============================= "pool-2-thread-2": waiting to lock monitor 0x09d17be0 (object 0x94d51000, a sun.misc.Launcher$AppClassLoader), which is held by "pool-1-thread-3" "pool-1-thread-3": waiting to lock monitor 0x09beebac (object 0x94dcf218, a org.apache.log4j.spi.RootLogger), which is held by "pool-2-thread-2" Java stack information for the threads listed above: =================================================== "pool-2-thread-2": at org.jmock.api.ExpectationError.toString(ExpectationError.java:32) at java.lang.String.valueOf(String.java:2827) at java.io.PrintWriter.println(PrintWriter.java:710) at java.lang.Throwable.printStackTrace(Throwable.java:509) - locked <0xb170f1b0> (a java.io.PrintWriter) at org.apache.log4j.spi.ThrowableInformation.getThrowableStrRep(ThrowableInform ation.java:76) at org.apache.log4j.spi.LoggingEvent.getThrowableStrRep(LoggingEvent.java:407) at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:305) at org.apache.log4j.WriterAppender.append(WriterAppender.java:160) at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251) - locked <0x94d92c40> (a org.apache.log4j.ConsoleAppender) at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(Append erAttachableImpl.java:66) at org.apache.log4j.Category.callAppenders(Category.java:206) - locked <0x94dcf218> (a org.apache.log4j.spi.RootLogger) at org.apache.log4j.Category.forcedLog(Category.java:391) at org.apache.log4j.Category.log(Category.java:856) at org.slf4j.impl.Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:571) at com.traficon.tmsng.server.inputgrid.detector.sockettask.RetryConnectingToSoc ketTask.call(RetryConnectingToSocketTask.java:187) at com.traficon.tmsng.server.inputgrid.detector.sockettask.RetryConnectingToSoc ketTask.call(RetryConnectingToSocketTask.java:42) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.ja va:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:9 08) at java.lang.Thread.run(Thread.java:619) "pool-1-thread-3": at org.apache.log4j.Category.callAppenders(Category.java:205) - waiting to lock <0x94dcf218> (a org.apache.log4j.spi.RootLogger) at org.apache.log4j.Category.forcedLog(Category.java:391) at org.apache.log4j.Category.debug(Category.java:260) at com.traficon.util.logging.Log4JMessageHandler.handleMessage(Log4JMessageHand ler.java:61) at org.aspectj.weaver.tools.WeavingAdaptor$WeavingAdaptorMessageHolder.handleMe ssage(WeavingAdaptor.java:615) at org.aspectj.bridge.MessageUtil.debug(MessageUtil.java:92) at org.aspectj.weaver.tools.WeavingAdaptor.debug(WeavingAdaptor.java:459) at org.aspectj.weaver.tools.WeavingAdaptor.weaveClass(WeavingAdaptor.java:280) at org.aspectj.weaver.loadtime.Aj.preProcess(Aj.java:95) - locked <0x94d51000> (a sun.misc.Launcher$AppClassLoader) at org.aspectj.weaver.loadtime.ClassPreProcessorAgentAdapter.transform(ClassPre ProcessorAgentAdapter.java:52) at sun.instrument.TransformerManager.transform(TransformerManager.java:169) at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:365) at java.lang.ClassLoader.defineClass1(Native Method) at java.lang.ClassLoader.defineClass(ClassLoader.java:621) at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:124) at java.net.URLClassLoader.defineClass(URLClassLoader.java:260) at java.net.URLClassLoader.access$000(URLClassLoader.java:56) at java.net.URLClassLoader$1.run(URLClassLoader.java:195) at java.security.AccessController.doPrivileged(Native Method) at java.net.URLClassLoader.findClass(URLClassLoader.java:188) at java.lang.ClassLoader.loadClass(ClassLoader.java:307) - locked <0x94d51000> (a sun.misc.Launcher$AppClassLoader) at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:301) - locked <0x94d51000> (a sun.misc.Launcher$AppClassLoader) at java.lang.ClassLoader.loadClass(ClassLoader.java:252) at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:320) - locked <0x94d51000> (a sun.misc.Launcher$AppClassLoader) at com.traficon.domain.message.impl.xml2.event.Xml2EventMessageGenerator.genera teEventMessage(Xml2EventMessageGenerator.java:75) at com.traficon.tmsng.server.inputgrid.detector.sockettask.GridCommunicationSta teSendingListener.sendCommError(GridCommunicationStateSendingListener.java:1 12) at com.traficon.tmsng.server.inputgrid.detector.sockettask.GridCommunicationSta teSendingListener.connectionFailed(GridCommunicationStateSendingListener.jav a:74) at com.traficon.tmsng.server.inputgrid.detector.sockettask.RetryConnectingToSoc ketTask.call(RetryConnectingToSocketTask.java:153) at com.traficon.tmsng.server.inputgrid.detector.sockettask.RetryConnectingToSoc ketTask.call(RetryConnectingToSocketTask.java:42) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) at java.util.concurrent.FutureTask.run(FutureTask.java:138) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.ja va:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:9 08) at java.lang.Thread.run(Thread.java:619) Found 1 deadlock. -- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch _______________________________________________ user mailing list user@slf4j.org http://www.slf4j.org/mailman/listinfo/user
_______________________________________________ user mailing list user@slf4j.org http://www.slf4j.org/mailman/listinfo/user