I'm observing a rare deadlock when writing to System.err, which I set in
the following:
System.setErr(new PrintStream(new LoggerOutputStream(err), true));
I define this class as:
private static class LoggerOutputStream extends OutputStream {
public void write(int b) throws IOException {
... // fills buffer_
}
public void flush() throws IOException {
if (index_ == 0) {
return;
}
super.flush(); // Make sure everything is flushed into buffer
String s = new String(buffer_, 0, index_);
logger_.warning(s);
index_ = 0;
}
// this is pretty much created with:
// Log4jFactory.getLog4jLogger(context, LOGFILE);
//
public LoggerOutputStream(com.xyzzy.logger.Logger logger) {
logger_ = logger;
}
Note that flush calls back into the logger. The problem is that a direct
call to System.err.println() will lock the PrintStream object before heading
off into log4j.callAppenders(). In my stack trace, callAppenders may
call printStackTrace, which also tries to lock the same PrintStream,
_after_ locking the Category.
Am I doing something wrong? Is there a work-around?
I can't avoid writing to err, as this is done in 3rd party software - and
I'd prefer to log it, if I can. Should I buffer up my err.println's and write
them outside of the PrintStream lock?
I'm using log4j 1.2.4. The deadlock was found on SunOS 5.8, using
jdk 1.4.2-b28. We've seen this on earlier versions of all of the above
as well.
Thanks for any help,
Girard Chandler
p.s.
some thread traces (from jdb):
Monitor information for thread SSH2TransportRX:
Owned monitor: instance of java.io.PrintStream(id=2771)
Waiting for monitor: instance of org.apache.log4j.spi.RootCategory(id=2751)
SSH2TransportTX:
[1] org.apache.log4j.Category.callAppenders (Category.java:185)
[2] org.apache.log4j.Category.forcedLog (Category.java:372)
[3] org.apache.log4j.Category.warn (Category.java:1,019)
[4] com.xyzzy.platform.logger.Log4jLogger.warning (Log4jLogger.java:39)
[5] com.xyzzy.platform.logger.LogFactory$LoggerOutputStream.flush (LogFactory
.java:122)
[6] java.io.PrintStream.write (PrintStream.java:260)
[7] com.mindbright.ssh2.SSH2SessionChannel.extData
(SSH2SessionChannel.java:295)^
Monitor information for thread SSH1 timeout:
Owned monitor: instance of org.apache.log4j.RollingFileAppender(id=2770)
Owned monitor: instance of org.apache.log4j.spi.RootCategory(id=2751)
Waiting for monitor: instance of java.io.PrintStream(id=2771)
SSH1 timeout:
[1] java.lang.Throwable.printStackTrace (Throwable.java:461)
[2] java.lang.Throwable.printStackTrace (Throwable.java:451)
[3] org.apache.log4j.helpers.LogLog.error (LogLog.java:136)
[4] org.apache.log4j.helpers.OnlyOnceErrorHandler.error
(OnlyOnceErrorHandler.jav
a:69)
[5] org.apache.log4j.helpers.OnlyOnceErrorHandler.error
(OnlyOnceErrorHandler.jav
a:59)
[6] org.apache.log4j.helpers.QuietWriter.flush (QuietWriter.java:51)
[7] org.apache.log4j.WriterAppender.subAppend (WriterAppender.java:306)
[8] org.apache.log4j.RollingFileAppender.subAppend
(RollingFileAppender.java:225)
[9] org.apache.log4j.WriterAppender.append (WriterAppender.java:150)
[10] org.apache.log4j.AppenderSkeleton.doAppend (AppenderSkeleton.java:221)
[11] org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders
(Appen
derAttachableImpl.java:57)
[12] org.apache.log4j.Category.callAppenders (Category.java:187)
[13] org.apache.log4j.Category.forcedLog (Category.java:372)
[14] org.apache.log4j.Category.debug (Category.java:241)
[15] com.xyzzy.platform.logger.Log4jLogger.debug (Log4jLogger.java:23)
[16] com.xyzzy.platform.session.Ssh1SessionClient.cleanupSession
(Ssh1SessionClient.java:214)
---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]
