logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Mak, Howard" <h...@vaultus.com>
Subject Avoiding deadlock when remapping System.err
Date Fri, 11 Jan 2008 16:33:10 GMT
Hi,

I'm experiencing some deadlock when remapping System.err using Jim Moore's LoggingOutputStream
w/ log4j v1.2.14.  The deadlock is shown below.  I realized that there are dangers of remapping
System.err, but I'd appreciate any guidance for seasoned Log4j experts.

I tried to address this by trying doing hierarchical locking so that all PrintStream methods
grab Logger lock before PrintStream lock.  i.e., Use a "hierarchical locking" PrintStream
subclass [instead of regular PrintStream] between System.out/err + LoggingOutputStream.  However,
this didn't work because it does not intercept calls from Throwable.printStackTrace() to the
remapped PrintStream.println().

Any comments about the following ideas?

-       Change log4j itself so that it releases Category/Logger lock before writing to appenders.
 Maybe store two appender lists in Logger ... one used by Category.callAppenders() loop and
for Category methods to add/remove appenders?

-       Come up w/ an alternative log4j.properties configuration that avoid such problems
[but still logs Throwable.printStackTrace()/etc to stderr]?

Your help and expertise is greatly appreciated.  Thanks!

- Howard


log4j.properties
----------------

        log4j.rootLogger = ALL, console, F

        # Writes to original System.err
        log4j.appender.console        = org.apache.log4j.ConsoleAppender
        log4j.appender.console.target = System.err

        # uses LoggingOutputStream (routes System.err to Log4j)
        log4j.logger.stderr    = ALL

        log4j.appender.F      = org.apache.log4j.FileAppender
        log4j.appender.F.File = log.txt

Deadlock dump
-------------

i.e.,
        "Thread-5" : RootLogger (0x0acf6af0) -> System.err (0x0ad091e8) [deadlock w/ Thread-1]
        "Thread-1" : System.err (0x0ad091e8) -> RootLogger (0x0acf6af0) [deadlock w/ Thread-5]

"Thread-5":
        at java.io.PrintStream.println(PrintStream.java:739)
        - waiting to lock <0x0ad091e8> (a java.io.PrintStream)
        at org.apache.log4j.helpers.LogLog.error(LogLog.java:142)
        at org.apache.log4j.helpers.OnlyOnceErrorHandler.error(OnlyOnceErrorHandler.java:77)
        at org.apache.log4j.helpers.OnlyOnceErrorHandler.error(OnlyOnceErrorHandler.java:67)
        at org.apache.log4j.helpers.QuietWriter.write(QuietWriter.java:49)
        at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:301)
        at org.apache.log4j.DailyRollingFileAppender.subAppend(DailyRollingFileAppender.java:358)
        at org.apache.log4j.WriterAppender.append(WriterAppender.java:159)
        at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:230)
        - locked <0x0acfb678> (a com.v.server.toolkit.bl.log.Log4jFileAppender)
        at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:65)
        at org.apache.log4j.Category.callAppenders(Category.java:203)
        - locked <0x0acf6af0> (a org.apache.log4j.spi.RootLogger)
        at org.apache.log4j.Category.forcedLog(Category.java:388)
        at org.apache.log4j.Category.log(Category.java:823)
        at com.v.server.core.services.log.ServerLogServiceImpl.println(ServerLogServiceImpl.java:304)
        at com.v.server.core.services.log.ServerLogServiceImpl.println(ServerLogServiceImpl.java:244)
        at com.v.vmsserver.VRPCMessageHandler.log(VRPCMessageHandler.java:116)
        at com.v.oem.e.job.EVRPCMessageHandler.received(EVRPCMessageHandler.java:187)
        at com.v.common.core.bl.comm.CMSessionReceiveEvent.dispatchInternal(CMSessionReceiveEvent.java:34)
        at com.v.common.core.bl.comm.CMSessionDispatchableEvent.dispatch(CMSessionDispatchableEvent.java:91)
        at com.v.server.core.CMMessageTask.runInContext(CMMessageTask.java:58)
        at com.v.server.core.JobTask.run(JobTask.java:61)
        at com.v.server.core.concurrent.Task.run(Task.java:118)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1061)
        at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:575)
        at java.lang.Thread.run(Thread.java:595)

"Thread-1":
        at org.apache.log4j.Category.callAppenders(Category.java:201)
        - waiting to lock <0x0acf6af0> (a org.apache.log4j.spi.RootLogger)
        at org.apache.log4j.Category.forcedLog(Category.java:388)
        at org.apache.log4j.Category.log(Category.java:835)
        at org.apache.log4j.contribs.JimMoore.LoggingOutputStream.flush(LoggingOutputStream.java:204)
        at java.io.PrintStream.write(PrintStream.java:414)
        - locked <0x0ad091e8> (a java.io.PrintStream)
        at sun.nio.cs.StreamEncoder$CharsetSE.writeBytes(StreamEncoder.java:336)
        at sun.nio.cs.StreamEncoder$CharsetSE.implWrite(StreamEncoder.java:395)
        at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:136)
        - locked <0x0ad09728> (a java.io.OutputStreamWriter)
        at java.io.OutputStreamWriter.write(OutputStreamWriter.java:191)
        at java.io.BufferedWriter.flushBuffer(BufferedWriter.java:111)
        - locked <0x0ad09728> (a java.io.OutputStreamWriter)
        at java.io.BufferedWriter.write(BufferedWriter.java:212)
        - locked <0x0ad09728> (a java.io.OutputStreamWriter)
        at java.io.Writer.write(Writer.java:126)
        at java.io.PrintStream.write(PrintStream.java:457)
        - locked <0x0ad091e8> (a java.io.PrintStream)
        at java.io.PrintStream.print(PrintStream.java:602)
        at java.lang.ThreadGroup.uncaughtException(ThreadGroup.java:985)
        at java.lang.ThreadGroup.uncaughtException(ThreadGroup.java:978)
        at java.lang.Thread.dispatchUncaughtException(Thread.java:1778)

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


Mime
View raw message