DO NOT REPLY [Bug 41214] Deadlock with RollingFileAppender

[bu...@apache.org]

https://issues.apache.org/bugzilla/show_bug.cgi?id=41214


Robert Andersson <ro...@manamind.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |robert@manamind.com
             Status|NEEDINFO                    |ASSIGNED




--- Comment #24 from Robert Andersson <ro...@manamind.com>  2008-09-10 07:15:17 PST ---
It's somewhat unclear from the above posts if we're talking about a deadlock or
just a lock contention/scalability issue. I can confirm that there does seem to
be a scalability issue. This is with log4j 1.2.5, using it in a webapp that
runs under tomcat, so there will be tens or hundreds of threads calling in to
log4j simultaneosly.

What were seeing is typically myriads of these:
"TP-Processor28" daemon prio=10 tid=0x08449800 nid=0x361 waiting for monitor
ent
ry [0x06c6d000..0x06c6e050]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.apache.log4j.Category.callAppenders(Category.java:204)
        - waiting to lock <0x841e4b10> (a org.apache.log4j.spi.RootLogger)
        at org.apache.log4j.Category.forcedLog(Category.java:391)
        at org.apache.log4j.Category.debug(Category.java:260)
All blocking against one that looks like similar to this:
"TP-Processor120" daemon prio=10 tid=0x0852e400 nid=0x4c6 waiting for monitor
en
try [0x07c81000..0x07c821d0]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.apache.log4j.Category.callAppenders(Category.java:204)
        - locked <0x841e4b10> (a org.apache.log4j.spi.RootLogger)
        at org.apache.log4j.Category.forcedLog(Category.java:391)
        at org.apache.log4j.Category.info(Category.java:666)

This isn't a deadlock, it's just showing that the coding in
Category.callAppenders doesn't scale well, it synchronizes at a too high level:
  public
  void callAppenders(LoggingEvent event) {
    int writes = 0;

    for(Category c = this; c != null; c=c.parent) {
      // Protected against simultaneous call to addAppender, removeAppender,...
      synchronized(c) {
        if(c.aai != null) {
          writes += c.aai.appendLoopOnAppenders(event);
        }
        if(!c.additive) {
          break;
        }
      }
    }

    if(writes == 0) {
      repository.emitNoAppenderWarning(this);
    }
  }

Now, fixing the overeager synchronization here would just expose the next
bottleneck, which is the AppenderSkeleton.doAppend. synchronization should be
moved down to the append method I guess.


-- 
Configure bugmail: https://issues.apache.org/bugzilla/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug.

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