Bugs item #623223, was opened at 2002-10-14 13:45
You can respond by visiting:
https://sourceforge.net/tracker/?func=detail&atid=376685&aid=623223&group_id=22866
Category: JBossServer
Group: v2.4 (stable)
Status: Closed
>Resolution: Fixed
Priority: 5
Submitted By: Jerome Lacoste (lacostej)
Assigned to: Scott M Stark (starksm)
Summary: possible deadlock in log4j related code
Initial Comment:
OS: Windows NT 4
JDK 1.4.1
JBoss 2.4.7 binary distribution with Jetty 4.0.4
There is a possible deadlock in log4j related code. We
started experiencing this after adding a new MBean
service to our application. It is 100% reproducible.
The deadlock is due to the fact that the log4j
CategoryStreame uses a hack to log some lost messages.
This hack tries to renter log4j logging by calling
log() on the wrapped category. Upon certain conditions,
this will cause a deadlock.
Details:
Hitting Ctrl-Break on the hung program gives me the
following output:
[...]
Java stack information for the threads listed above:
===================================================
"Thread-23":
at
org.apache.log4j.Category.callAppenders(Category.java:253)
- waiting to lock <0328F228> (a
org.apache.log4j.spi.RootCategory)
at
org.apache.log4j.Category.forcedLog(Category.java:445)
at org.apache.log4j.Category.log(Category.java:864)
at
org.jboss.logging.log4j.CategoryStream.write(CategoryStream.java:91)
- locked <0329D410> (a
org.jboss.logging.log4j.CategoryStream) at
org.jboss.logging.log4j.CategoryStream.println(CategoryStream.java:49)
at
org.hsqldb.Embedded_ServerConnection.run(Embedded_ServerConnection.java:161)
at java.lang.Thread.run(Thread.java:536)
"Thread-2":
at java.io.PrintStream.flush(PrintStream.java:133)
- waiting to lock <0329D410> (a
org.jboss.logging.log4j.CategoryStream)
at
sun.nio.cs.StreamEncoder$CharsetSE.implFlush(StreamEncoder.java:408)
at
sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:150)
- locked <0349E880> (a java.io.OutputStreamWriter)
at
java.io.OutputStreamWriter.flush(OutputStreamWriter.java:213)
at
org.apache.log4j.helpers.QuietWriter.flush(QuietWriter.java:49)
at
org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:309)
at
org.apache.log4j.WriterAppender.append(WriterAppender.java:157)
at
org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
- locked <0349DB48> (a
org.apache.log4j.ConsoleAppender)
at
org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:57)
at
org.apache.log4j.Category.callAppenders(Category.java:255)
- locked <0328F228> (a
org.apache.log4j.spi.RootCategory)
at
org.apache.log4j.Category.forcedLog(Category.java:445)
[...]
Found 1 deadlock.
After having a look at the stack trace, it looks like
the lock is coming from this piece of code, within
org.jboss.logging.util.CategoryStream
// HACK, something is logging exceptions line by
line (including
// blanks), but I can't seem to find it, so for
now just ignore
// empty lines... they aren't very useful.
if (len != 0) {
String msg = new String(b, off, len);
category.log(priority, msg);
}
inWrite = false;
Hacks ain't good :)
Removing the call to category.log() removes the
deadlock in our current tests. But this does not solve
the problem.
I guess there are 2 solutions:
- find which logs were concerned by the hack, and
correct the problem, removing the hack
- try to make log4j reentrant.
The problem may be present in other versions of JBoss
(including the latest) as the current version of
CategoryStream still contains the HACK.
Patch coming.
----------------------------------------------------------------------
>Comment By: Scott M Stark (starksm)
Date: 2002-10-30 15:39
Message:
Logged In: YES
user_id=175228
Ok, I've been convinced that this occurs independent of
applications overriding the server logging setup. The real
issue is the synchronization on the CategoryStream.write
method. Removing this avoids the deadlock.
----------------------------------------------------------------------
Comment By: Scott M Stark (starksm)
Date: 2002-10-28 17:26
Message:
Logged In: YES
user_id=175228
This removes the redirection of the console streams. The real
issue is that applications should not override the server
logging system using BasicConfigurator. Create a seperate
logging repository if using log4j 1.2, or use the server log4j
configuration.
----------------------------------------------------------------------
Comment By: Jerome Lacoste (lacostej)
Date: 2002-10-15 02:03
Message:
Logged In: YES
user_id=81510
If anyone interested, I attach the batch file used to patch
JBoss
----------------------------------------------------------------------
Comment By: Jerome Lacoste (lacostej)
Date: 2002-10-15 01:58
Message:
Logged In: YES
user_id=81510
We first managed to remove the deadlock by patching the
CategoryStream.java file in package org.jboss.logging.log4j
Patch attached. This may be the correct way to fix the problem.
We think we also found out went the deadlock started to appear.
We introduced by mistaked the following code in a static
initializer of one of our classes:
org.apache.log4j....BasicConfigurator.configure();
Removing this line removed the deadlock for us. The deadlock
doesn't appear during execution of this line, but later on,
especially at shutdown time.
I think that the correct solution is to fix CategoryStream.
Especially as there is another bug report for a similar
problem (see bug 619171).
Our patch is perhaps not the correct solution but worked for us.
----------------------------------------------------------------------
You can respond by visiting:
https://sourceforge.net/tracker/?func=detail&atid=376685&aid=623223&group_id=22866
-------------------------------------------------------
This sf.net email is sponsored by: Influence the future
of Java(TM) technology. Join the Java Community
Process(SM) (JCP(SM)) program now.
http://ads.sourceforge.net/cgi-bin/redirect.pl?sunm0004en
_______________________________________________
Jboss-development mailing list
[EMAIL PROTECTED]
https://lists.sourceforge.net/lists/listinfo/jboss-development
