JBossDeveloper

Yes, but its the late as possible that is the problem. Its not clear to me why the checks for whether or not the message will be rendered cannot be made safely, while the message rendering could be made without any locks. Maybe that's not possible with the current log4j locking scheme, I don't know.

Since you're talking about my patch...

1.3 is more subtly improved, in that you don't have to synchronize on anything to render safely. The log4j guys still insist on the benefits of reusing string buffers and such, so you may need to clean up some of the message rendering code to be thread safe.

I don't know if you could fix 1.2 so that the rendering worked without locking.

I think the best way out of this mess is to create your own custom appender classes, if you want to go with 1.2. Then patch the renderers and Category class.

If any of you would come by the log4j-dev list and share some thoughts for 1.3, that would be nice. I don't trust any of those developers as much as you two. I don't think App Servers are their target market or something.

And, I know my example was contrived, but in 1.3 they have an idiom:

Object foo, bar;
Logger.debug("Here {} {}", foo, bar);

Which could more readily create deadlocks.

I spent some time hacking the log4j-1.2.8 codebase to relax the synchronization on the category and appenders. Its checked into the jboss-log4j module on the cvs.forge.jboss.com:/cvsroot/jboss repository. It does not seem too hard to get the category and appenders to render the messages without holding a lock and changes for the main layouts and file appenders is checked in. There are a lot of code that is not thread safe that would still need to be validated/updated so I'm not sure how far to go down this path. We could:

1. Update the log4j fork and incorporate it into jboss under a new namespace to effectively create a seperate thread safe version. The jboss default config would be isolated. This actually simplies the existing reuse of log4j in apps.
2. Look to use the jdk logger and build decent appenders. People can still use log4j and the installer could allow for alternate default configurations.
3. We could look at helping with the log4j 1.3 codebase.
4. We could introduce a batched logging sematic where log messages could be queued within unsafe contexts like the point where the class loading layer is holding a lock, and dump the queue after the critical section is released.

A key thing is to develop a recursive logging/class loading stress test that artifically attempts to create the deadlock.

The java.util.logging.StreamHandler which is the base of the default handlers in the jdk is synchronized on its publish method which is going to result in the same type of deadlock potential when the msg arguments are formatted.

Yes, I was going to mention, that the JDK logging framework has the same sort of potential deadlock scenario.

Personally, I'm not in favor of your idea #1, because I would like to have JBoss and my applications log in the same configured environment and append to the same files.

Perhaps you could (via the installer) offer a choice of a log4j patched or log4j only for JBoss. In the latter case, you could go with #1.

Scott, could you please post a message to the log4j dev list or update my bug with your changes at least? It would be good I think for someone like you to bring it up.

I am going to look at better out of the box integration with the jdk logger and see if some of the log4j 1.3 appenders can be ported to jdk handlers. After I have looked at this I'll give some feedback on the log4j bug. The current changes would be very incompleted because I did go through any appenders but the file based ones.

I thought I should let you know that we have completed a series of stress tests on our application with the log4j.xml workaround in place and everything has been fine. Based on that I'm as sure as I can be that this does fix the problem. Thanks for you help.

I have a prototype port of the log4j1.2.12 code to a jdk logging implementation that has no synchronization around the rendering phase. There is a port of the DOMConfigurator which allows use of the existing jboss log4j.xml with only changes for the appender class names:

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration PUBLIC "urn:jboss:jdk:log4j.dtd" "log4j.dtd">

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" debug="false">

 <!-- ================================= -->
 <!-- Preserve messages in a local file -->
 <!-- ================================= -->

 <!-- A time/date based rolling appender -->
 <appender name="FILE" class="org.jboss.logging.jdk.handlers.DailyRollingFileHandler">
 <param name="File" value="${jboss.server.home.dir}/log/server.log"/>
 <param name="Append" value="false"/>

 <!-- Rollover at midnight each day -->
 <param name="DatePattern" value="'.'yyyy-MM-dd"/>

 <layout class="org.jboss.logging.jdk.format.PatternFormatter">
 <!-- The default pattern: Date Priority [Category] Message\n -->
 <param name="ConversionPattern" value="%d %-5p [%c] %m%n"/>

 <!-- The full pattern: Date MS Priority [Category] (Thread:NDC) Message\n
 <param name="ConversionPattern" value="%d %-5r %-5p [%c] (%t:%x) %m%n"/>
 -->
 </layout>
 </appender>

 <!-- ============================== -->
 <!-- Append messages to the console -->
 <!-- ============================== -->

 <appender name="CONSOLE" class="java.util.logging.ConsoleHandler">
 <param name="Level" value="INFO"/>

 <layout class="org.jboss.logging.jdk.format.PatternFormatter">
 <!-- The default pattern: Date Priority [Category] Message\n -->
 <param name="ConversionPattern" value="%d{ABSOLUTE} %-5p [%c{1}] %m%n"/>
 </layout>
 </appender>

 <!-- ================ -->
 <!-- Limit categories -->
 <!-- ================ -->

 <!-- Limit the org.apache category to INFO as its DEBUG is verbose -->
 <category name="org.apache">
 <priority value="INFO"/>
 </category>

 <!-- Limit the org.jgroups category to WARN as its INFO is verbose -->
 <category name="org.jgroups">
 <priority value="WARN"/>
 </category>

 <!-- Limit jboss axis to INFO as its DEBUG is even more verbose -->
 <category name="org.jboss.axis">
 <priority value="INFO"/>
 </category>

 <!-- Limit JBoss categories
 <category name="org.jboss">
 <priority value="INFO"/>
 </category>
 -->

 <!-- Limit the JSR77 categories -->
 <category name="org.jboss.management">
 <priority value="INFO"/>
 </category>

 <!-- Limit JBoss webservice category
 <category name="org.jboss.webservice">
 <priority value="DEBUG"/>
 </category>
 -->

 <!-- ======================= -->
 <!-- Setup the Root category -->
 <!-- ======================= -->

 <root>
 <appender-ref ref="CONSOLE"/>
 <appender-ref ref="FILE"/>
 </root>

</log4j:configuration>

console:
21:34:38,343 INFO [root] An info message from the 'root' logger
21:34:38,343 INFO [apache] An info msg to org.apache
21:34:38,343 WARNING [jgroups] An warning msg to org.jgroups
21:34:38,343 SEVERE [jgroups] An severe msg to org.jgroups

/tmp/jboss/log/server.log:
2005-10-29 21:34:38,343 INFO [root] An info message from the 'root' logger
2005-10-29 21:34:38,343 INFO [org.apache] An info msg to org.apache
2005-10-29 21:34:38,343 WARNING [org.jgroups] An warning msg to org.jgroups
2005-10-29 21:34:38,343 SEVERE [org.jgroups] An severe msg to org.jgroups

The initial prototype has been added to head. See:
http://www.jboss.com/index.html?module=bb&op=viewtopic&p=3904365

I received this from Boris Unckel <boris.unckel.mlg@gmx.net>

I have already done a port of log4j core parts to JDK logging
(java.util.logging in short jul).
It's current draft name is JULI (Java Util Logging Implementation).

You can read the project proposal and download a draft version here:
http://issues.apache.org/bugzilla/show_bug.cgi?id=36805

It is discussed here
http://marc.theaimsgroup.com/?l=apache-logging-general&m=112767268814065&w=2

The original request for incubation
http://marc.theaimsgroup.com/?l=apache-logging-general&m=112765935923729&w=2

Please do not send feedback to log4j-dev but general@logging.apache.org
instead. The discussion should not split up...