How to flush Asynchronous loggers in Log4J2 (with disruptor)

Question

I'm using Log4J2 "Making All Loggers Asynchronous" section by setting:

-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector.

https://logging.apache.org/log4j/2.x/manual/async.html

I process a lot of logs and then stop the appenders before exiting:

org.apache.logging.log4j.core.Logger coreLogger = (org.apache.logging.log4j.core.Logger) logger;
org.apache.logging.log4j.core.LoggerContext context = (org.apache.logging.log4j.core.LoggerContext) coreLogger.getContext();
Map<String, Appender> appenders = context.getConfiguration().getAppenders();
for (Appender appender : appenders.values()) {
  appender.stop();
}

By doing so I'm hoping that it will flush the async appender(s) and write to the disk the remaining logs before I exit the program.

But here is what happens:

2015-05-19 14:09:58,540 ERROR Attempted to append to non-started appender myFileAppender
Exception in thread "AsyncLogger-1" java.lang.RuntimeException: org.apache.logging.log4j.core.appender.AppenderLoggingException: Attempted to append to non-started appender myFileAppender
    at com.lmax.disruptor.FatalExceptionHandler.handleEventException(FatalExceptionHandler.java:45)
    at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:147)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.logging.log4j.core.appender.AppenderLoggingException: Attempted to append to non-started appender myFileAppender
    at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:89)
    at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:430)
    at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:409)
    at org.apache.logging.log4j.core.Logger$PrivateConfig.logEvent(Logger.java:288)
    at org.apache.logging.log4j.core.async.AsyncLogger.actualAsyncLog(AsyncLogger.java:305)
    at org.apache.logging.log4j.core.async.RingBufferLogEvent.execute(RingBufferLogEvent.java:100)
    at org.apache.logging.log4j.core.async.RingBufferLogEventHandler.onEvent(RingBufferLogEventHandler.java:43)
    at org.apache.logging.log4j.core.async.RingBufferLogEventHandler.onEvent(RingBufferLogEventHandler.java:28)
    at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:128)
    ... 3 more

So the close doesn't look like it's actually flushing and the logger ends up failing.

My conf:

<Configuration>
  <Appenders>
    <RollingFile name="myFileAppender" fileName="/tmp/test.log" ignoreExceptions="false" immediateFlush="false">
      <PatternLayout><Pattern>%m%n</Pattern></PatternLayout>
      <Policies>
        <TimeBasedTriggeringPolicy />
      </Policies>
    </RollingFile>
    <Console name="STDOUT">
      <PatternLayout pattern="%C{1.} %m %level MDC%X%n"/>
    </Console>
  </Appenders>

  <Loggers>
    <Logger name="myLogger" level="info" additivity="false">
      <AppenderRef ref="myFileAppender" />
    </Logger>
    <Root level="fatal">
      <AppenderRef ref="STDOUT"/>
    </Root>
  </Loggers>
</Configuration>

How can I flush / synchronize log4j2?

Remko Popma Remko Popma · Accepted Answer · 2015-05-20T13:57:49

Log4j2 has a shutdown hook (for non-web applications) that takes care of waiting for the background thread to process any events still in the queue. So the best thing to do is to not stop the appenders when they are still being used. Let log4j2 take care of the cleanup.

To cleanly stop the async logger, you can call org.apache.logging.log4j.core.async.AsyncLogger.stop(). This blocks until all messages are flushed. Be aware:

This only works when "Making All Loggers Asynchronous" section by setting: -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector.
Are you sure you want to measure this? The disk I/O will dominate your measurements. If you want to include I/O, it may simpler to switch off async logging and measure synchronous logging (which includes the I/O). Most people are interested in the impact of logging on their application, so they only measure how long the calls to the logger take, and don't include the background thread work in their measurements.

How to flush Asynchronous loggers in Log4J2 (with disruptor)

1 Answers