Search code examples
log4jnullpointerexceptionappender

Log4J: AsyncAppender and NullPointerException during stacktrace print

Updated: This is true not only for AsyncAppender. Happens for console one as well.

I faced with wierd behavior of AsyncAppender that occurs rarely but with sufficient harm.

Here is code snippet:

public void testNPE() {
    try {
        try {
            throw new NullPointerException();
        } catch (NullPointerException e) {
            throw new RuntimeException(e);
        }
    } catch (RuntimeException e) {
        logger.error("Catcha!" + e.getLocalizedMessage(), e);
    }
}

Probable result should be:

07.12.12 10:21:34,904 ERROR [main] >> [com.ubs.eqdel.markitfeed.core.RetrieverTest:74]          Catcha! java.lang.NullPointerException
java.lang.RuntimeException: java.lang.NullPointerException
    at com.ubs.eqdel.markitfeed.core.RetrieverTest.testNPE(RetrieverTest.java:71)
...
Caused by: java.lang.NullPointerException
    at com.ubs.eqdel.markitfeed.core.RetrieverTest.testNPE(RetrieverTest.java:69)
    ... 25 more

But for 5 of 20 attempts I see:

Exception in thread "Dispatcher-Thread-0" java.lang.NullPointerException
    at java.io.Writer.write(Writer.java:140)
    at org.apache.log4j.helpers.CountingQuietWriter.write(CountingQuietWriter.java:45)
    at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:309)
    at org.apache.log4j.RollingFileAppender.subAppend(RollingFileAppender.java:263)
    at org.apache.log4j.WriterAppender.append(WriterAppender.java:160)
    at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
    at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)
    at org.apache.log4j.AsyncAppender$Dispatcher.run(AsyncAppender.java:583)
    at java.lang.T07.12.12 10:23:54,972 ERROR [main] >> [com.ubs.eqdel.markitfeed.core.RetrieverTest:74]  Catcha! java.lang.NullPointerException
java.lang.RuntimeException: java.lang.NullPointerException
at com.ubs.eqdel.markitfeed.core.RetrieverTest.testNPE(RetrieverTest.java:71)
...
Caused by: java.lang.NullPointerException
    at com.ubs.eqdel.markitfeed.core.RetrieverTest.testNPE(RetrieverTest.java:69)
    ... 25 more

What's wrong with AsyncAppender? Did anybody face the same? And what is the workaround on this?

Solution

  • Looks like this bug.

    Edit: Based on the release notes, 1.2.16 (released on 2010-04-06) should contain the fix for this.