<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN">
<HTML><HEAD>
<META http-equiv=Content-Type content="text/html; charset=iso-8859-1">
<META content="MSHTML 6.00.6000.16788" name=GENERATOR></HEAD>
<BODY>
<DIV dir=ltr align=left><SPAN class=453360018-10022009><FONT face=Arial
color=#0000ff size=2>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.</FONT></SPAN></DIV>
<DIV dir=ltr align=left><SPAN class=453360018-10022009><FONT face=Arial
color=#0000ff size=2></FONT></SPAN> </DIV>
<DIV dir=ltr align=left><SPAN class=453360018-10022009><FONT face=Arial
color=#0000ff size=2>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?</FONT></SPAN></DIV>
<DIV dir=ltr align=left><SPAN class=453360018-10022009><FONT face=Arial
color=#0000ff size=2></FONT></SPAN> </DIV>
<DIV dir=ltr align=left><SPAN class=453360018-10022009><FONT face=Arial
color=#0000ff size=2>Cheers</FONT></SPAN></DIV>
<DIV dir=ltr align=left><SPAN class=453360018-10022009><FONT face=Arial
color=#0000ff size=2>Paul</FONT></SPAN></DIV><BR>
<DIV class=OutlookMessageHeader lang=en-us dir=ltr align=left>
<HR tabIndex=-1>
<FONT face=Tahoma size=2><B>From:</B> user-bounces@slf4j.org
[mailto:user-bounces@slf4j.org] <B>On Behalf Of </B>Patrick
Hancke<BR><B>Sent:</B> 10 February 2009 15:58<BR><B>To:</B> User list for the
slf4j project<BR><B>Subject:</B> Re: [slf4j-user] deadlock in slf4j-log4j12
?<BR></FONT><BR></DIV>
<DIV></DIV>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="PADDING-LEFT: 1ex; MARGIN: 0pt 0pt 0pt 0.8ex; BORDER-LEFT: rgb(204,204,204) 1px solid">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="PADDING-LEFT: 1ex; MARGIN: 0pt 0pt 0pt 0.8ex; BORDER-LEFT: rgb(204,204,204) 1px solid">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="PADDING-LEFT: 1ex; MARGIN: 0pt 0pt 0pt 0.8ex; BORDER-LEFT: rgb(204,204,204) 1px solid">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></BODY></HTML>