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.<br>
<br>Thanks for your help,<br>Patrick Hancke<br><br><div class="gmail_quote">2009/2/10 Ceki Gulcu <span dir="ltr"><ceki@qos.ch></span><br><blockquote class="gmail_quote" style="border-left: 1px solid rgb(204, 204, 204); margin: 0pt 0pt 0pt 0.8ex; padding-left: 1ex;">
Hello Patrick,<br>
<br>
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.<br>
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.<br>
<br>
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.<br>
<br>
HTH,<div class="Ih2E3d"><br>
<br>
Patrick Hancke wrote:<br>
<blockquote class="gmail_quote" style="border-left: 1px solid rgb(204, 204, 204); margin: 0pt 0pt 0pt 0.8ex; padding-left: 1ex;">
I'm using slf4j version 1.5.6 in combination with log4j version<br>
1.2.15. Java version is 1.6.0.<br>
<br>
In my unit tests, I'm experiencing a deadlock which seems related to<br>
slf4j / log4j. Below is a thread dump. Anybody experienced similar<br>
problems?<br>
---------------<br>
</blockquote>
<br></div>
[snip]<div><div></div><div class="Wj3C7c"><br>
<br>
<blockquote class="gmail_quote" style="border-left: 1px solid rgb(204, 204, 204); margin: 0pt 0pt 0pt 0.8ex; padding-left: 1ex;">
JNI global references: 973<br>
<br>
<br>
Found one Java-level deadlock:<br>
=============================<br>
"pool-2-thread-2":<br>
waiting to lock monitor 0x09d17be0 (object 0x94d51000, a<br>
sun.misc.Launcher$AppClassLoader),<br>
which is held by "pool-1-thread-3"<br>
"pool-1-thread-3":<br>
waiting to lock monitor 0x09beebac (object 0x94dcf218, a<br>
org.apache.log4j.spi.RootLogger),<br>
which is held by "pool-2-thread-2"<br>
<br>
Java stack information for the threads listed above:<br>
===================================================<br>
"pool-2-thread-2":<br>
at org.jmock.api.ExpectationError.toString(ExpectationError.java:32)<br>
at java.lang.String.valueOf(String.java:2827)<br>
at java.io.PrintWriter.println(PrintWriter.java:710)<br>
at java.lang.Throwable.printStackTrace(Throwable.java:509)<br>
- locked <0xb170f1b0> (a java.io.PrintWriter)<br>
at org.apache.log4j.spi.ThrowableInformation.getThrowableStrRep(ThrowableInformation.java:76)<br>
at org.apache.log4j.spi.LoggingEvent.getThrowableStrRep(LoggingEvent.java:407)<br>
at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:305)<br>
at org.apache.log4j.WriterAppender.append(WriterAppender.java:160)<br>
at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)<br>
- locked <0x94d92c40> (a org.apache.log4j.ConsoleAppender)<br>
at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)<br>
at org.apache.log4j.Category.callAppenders(Category.java:206)<br>
- locked <0x94dcf218> (a org.apache.log4j.spi.RootLogger)<br>
at org.apache.log4j.Category.forcedLog(Category.java:391)<br>
at org.apache.log4j.Category.log(Category.java:856)<br>
at org.slf4j.impl.Log4jLoggerAdapter.error(Log4jLoggerAdapter.java:571)<br>
at com.traficon.tmsng.server.inputgrid.detector.sockettask.RetryConnectingToSocketTask.call(RetryConnectingToSocketTask.java:187)<br>
at com.traficon.tmsng.server.inputgrid.detector.sockettask.RetryConnectingToSocketTask.call(RetryConnectingToSocketTask.java:42)<br>
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)<br>
at java.util.concurrent.FutureTask.run(FutureTask.java:138)<br>
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)<br>
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)<br>
at java.lang.Thread.run(Thread.java:619)<br>
"pool-1-thread-3":<br>
at org.apache.log4j.Category.callAppenders(Category.java:205)<br>
- waiting to lock <0x94dcf218> (a org.apache.log4j.spi.RootLogger)<br>
at org.apache.log4j.Category.forcedLog(Category.java:391)<br>
at org.apache.log4j.Category.debug(Category.java:260)<br>
at com.traficon.util.logging.Log4JMessageHandler.handleMessage(Log4JMessageHandler.java:61)<br>
at org.aspectj.weaver.tools.WeavingAdaptor$WeavingAdaptorMessageHolder.handleMessage(WeavingAdaptor.java:615)<br>
at org.aspectj.bridge.MessageUtil.debug(MessageUtil.java:92)<br>
at org.aspectj.weaver.tools.WeavingAdaptor.debug(WeavingAdaptor.java:459)<br>
at org.aspectj.weaver.tools.WeavingAdaptor.weaveClass(WeavingAdaptor.java:280)<br>
at org.aspectj.weaver.loadtime.Aj.preProcess(Aj.java:95)<br>
- locked <0x94d51000> (a sun.misc.Launcher$AppClassLoader)<br>
at org.aspectj.weaver.loadtime.ClassPreProcessorAgentAdapter.transform(ClassPreProcessorAgentAdapter.java:52)<br>
at sun.instrument.TransformerManager.transform(TransformerManager.java:169)<br>
at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:365)<br>
at java.lang.ClassLoader.defineClass1(Native Method)<br>
at java.lang.ClassLoader.defineClass(ClassLoader.java:621)<br>
at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:124)<br>
at java.net.URLClassLoader.defineClass(URLClassLoader.java:260)<br>
at java.net.URLClassLoader.access$000(URLClassLoader.java:56)<br>
at java.net.URLClassLoader$1.run(URLClassLoader.java:195)<br>
at java.security.AccessController.doPrivileged(Native Method)<br>
at java.net.URLClassLoader.findClass(URLClassLoader.java:188)<br>
at java.lang.ClassLoader.loadClass(ClassLoader.java:307)<br>
- locked <0x94d51000> (a sun.misc.Launcher$AppClassLoader)<br>
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:301)<br>
- locked <0x94d51000> (a sun.misc.Launcher$AppClassLoader)<br>
at java.lang.ClassLoader.loadClass(ClassLoader.java:252)<br>
at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:320)<br>
- locked <0x94d51000> (a sun.misc.Launcher$AppClassLoader)<br>
at com.traficon.domain.message.impl.xml2.event.Xml2EventMessageGenerator.generateEventMessage(Xml2EventMessageGenerator.java:75)<br>
at com.traficon.tmsng.server.inputgrid.detector.sockettask.GridCommunicationStateSendingListener.sendCommError(GridCommunicationStateSendingListener.java:112)<br>
at com.traficon.tmsng.server.inputgrid.detector.sockettask.GridCommunicationStateSendingListener.connectionFailed(GridCommunicationStateSendingListener.java:74)<br>
at com.traficon.tmsng.server.inputgrid.detector.sockettask.RetryConnectingToSocketTask.call(RetryConnectingToSocketTask.java:153)<br>
at com.traficon.tmsng.server.inputgrid.detector.sockettask.RetryConnectingToSocketTask.call(RetryConnectingToSocketTask.java:42)<br>
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)<br>
at java.util.concurrent.FutureTask.run(FutureTask.java:138)<br>
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)<br>
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)<br>
at java.lang.Thread.run(Thread.java:619)<br>
<br>
Found 1 deadlock.<br>
</blockquote>
<br></div></div><font color="#888888">
-- <br>
Ceki Gülcü<br>
Logback: The reliable, generic, fast and flexible logging framework for Java.<br>
<a href="http://logback.qos.ch" target="_blank">http://logback.qos.ch</a><br>
_______________________________________________<br>
user mailing list<br>
<a href="mailto:user@slf4j.org" target="_blank">user@slf4j.org</a><br>
<a href="http://www.slf4j.org/mailman/listinfo/user" target="_blank">http://www.slf4j.org/mailman/listinfo/user</a><br>
</font></blockquote></div><br>