DO NOT REPLY [Bug 24159] New: - Log4J can create deadlock conditions

[bu...@apache.org]

DO NOT REPLY TO THIS EMAIL, BUT PLEASE POST YOUR BUG 
RELATED COMMENTS THROUGH THE WEB INTERFACE AVAILABLE AT
<http://nagoya.apache.org/bugzilla/show_bug.cgi?id=24159>.
ANY REPLY MADE TO THIS MESSAGE WILL NOT BE COLLECTED AND 
INSERTED IN THE BUG DATABASE.

http://nagoya.apache.org/bugzilla/show_bug.cgi?id=24159

Log4J can create deadlock conditions

           Summary: Log4J can create deadlock conditions
           Product: Log4j
           Version: 1.2
          Platform: Sun
        OS/Version: Solaris
            Status: NEW
          Severity: Normal
          Priority: Other
         Component: Other
        AssignedTo: log4j-dev@jakarta.apache.org
        ReportedBy: eross@m-qube.com


I posted this to the user list:


I just came across a deadlock condition in my code brought out by
Log4J.  Here is a simplified view of the objects in play:

class State {
   Logger log1;
  
   synchronized void setState() {
     // Something takes a long time here
     log.debug("hello world");
   }

   synchronized Object getState() {
   }

   public String toString() {
      return "state=" + getState();
   }
}

So, imagine that I call in thread (1)

Logger log2;
State s = new State();
log.debug(s);

And then, in another thread (2), I called setState().  It is in the
middle of setState when this debug statement is fired.

In thread (1), the logger holds a lock on
'org.apache.log4j.spi.RootCategory'.  The renderer attempts construct
the message by calling s.toString(), and toString calls getState().

Thread (1) has to wait for setState in thread (2) to exit.  But setState
can't exit until it has finished logging.



On Fri, 2003-10-24 at 15:26, Elias Ross wrote:
> 
> Here is the stack trace:

org.apache.log4j.WriterAppender.append(WriterAppender.java:150)
org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:221)
        - locked <d6655dd0> (a
org.jboss.logging.appender.DailyRollingFileAppender)
org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:57)
        org.apache.log4j.Category.callAppenders(Category.java:187)
        - locked <d52e5db0> (a org.apache.log4j.spi.RootCategory)

I suggest what needs to happen is that the rendering stage has to take
place without holding any locks.  But that would mean that
AppenderSkeleton would have to be re-written (but only slightly):

1.  Holding locks, all major pre-conditions are checked.  (Is the event
filterable?  Is the threshold set too low?)
2.  The message is rendered.
3.  Holding any final locks necessary to actually write/output the
message, the rendered message is then sent to disk/the network/wherever.

I've run into this problem two times:  One time while using JBoss,
another time using a third-party library that uses log4j.  Since more
and more libraries and platforms use log4j (or commons-logging), this
sort of "rendering-interference"--especially on multiple-CPU
machines--is very worrisome.

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@jakarta.apache.org
For additional commands, e-mail: log4j-dev-help@jakarta.apache.org