log4j2 : Async logger is NOT starting

Question

I have recently upgraded my application to use log4j2. I am trying to make use of its async logger feature. However looks like its not creating one. As per Log4j Async config, it says,

1. To make all loggers asynchronous, add the disruptor jar to the classpath and set the system property Log4jContextSelector to org.apache.logging.log4j.core.async.AsyncLoggerContextSelector. I also set the status="trace" in log4j.xml to see if it configures and instantiate async logger. But looks like it failing.

2017-01-25 01:58:30,799 main TRACE Reregistering context (1/1): 'AsyncContext@18b4aac2' org.apache.logging.log4j.core.async.AsyncLoggerContext@6bf08014 2017-01-25 01:58:30,800 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=AsyncContext@18b4aac2' 2017-01-25 01:58:30,800 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=AsyncContext@18b4aac2,component=StatusLogger' 2017-01-25 01:58:30,800 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=AsyncContext@18b4aac2,component=ContextSelector' 2017-01-25 01:58:30,801 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=AsyncContext@18b4aac2,component=Loggers,name=' 2017-01-25 01:58:30,801 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=AsyncContext@18b4aac2,component=Appenders,name=' 2017-01-25 01:58:30,801 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=AsyncContext@18b4aac2,component=AsyncAppenders,name=' 2017-01-25 01:58:30,801 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=AsyncContext@18b4aac2,component=AsyncLoggerRingBuffer' 2017-01-25 01:58:30,802 main TRACE Unregistering but no MBeans found matching 'org.apache.logging.log4j2:type=AsyncContext@18b4aac2,component=Loggers,name=,subtype=RingBuffer' 2017-01-25 01:58:30,803 main DEBUG Registering MBean org.apache.logging.log4j2:type=AsyncContext@18b4aac2 2017-01-25 01:58:30,805 main DEBUG Registering MBean org.apache.logging.log4j2:type=AsyncContext@18b4aac2,component=AsyncLoggerRingBuffer 2017-01-25 01:58:30,806 main DEBUG Registering MBean org.apache.logging.log4j2:type=AsyncContext@18b4aac2,component=StatusLogger 2017-01-25 01:58:30,807 main DEBUG Registering MBean org.apache.logging.log4j2:type=AsyncContext@18b4aac2,component=ContextSelector 2017-01-25 01:58:30,816 main TRACE Using default SystemClock for timestamps. 2017-01-25 01:58:30,816 main TRACE Using DummyNanoClock for nanosecond timestamps. 2017-01-25 01:58:30,817 main DEBUG Reconfiguration complete for context[name=AsyncContext@18b4aac2] at URI /etc/opt/sun/im/default/config/log4j2.xml (org.apache.logging.log4j.core.async.AsyncLoggerContext@6bf08014) with optional ClassLoader: null 2017-01-25 01:58:30,817 main DEBUG Shutdown hook enabled. Registering a new one. 2017-01-25 01:58:30,818 main DEBUG LoggerContext[name=AsyncContext@18b4aac2, org.apache.logging.log4j.core.async.AsyncLoggerContext@6bf08014] started OK.

As I don't see anything like "Starting AsyncLogger disruptor".

2. Then as suggested, I tried using asyncLogger tag, I could see it printing,

   2017-01-25 00:27:26,970 main TRACE AsyncLoggerConfigDisruptor creating new disruptor for this configuration. 2017-01-25 00:27:26,971 main TRACE property AsyncLoggerConfig.WaitStrategy=TIMEOUT 2017-01-25 00:27:26,987 main DEBUG Starting AsyncLoggerConfig disruptor for this configuration with ringbufferSize=4096, waitStrategy=TimeoutBlockingWaitStrategy, exceptionHandler=org.apache.logging.log4j.core.async.AsyncLoggerConfigDefaultExceptionHandler@7f284218... 2017-01-25 00:27:26,988 main TRACE AsyncLoggerConfig[xmppd] starting...

   But again at later stage it throws exception for class not found,

   2017-01-25 00:27:31,658 main ERROR Unable to invoke factory method in class class org.apache.logging.log4j.core.async.AsyncLoggerConfig for element AsyncLogger. java.lang.reflect.InvocationTargetException at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:132) at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:942) at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:882) at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:874) at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:498) at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:227) at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:239) at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:530) at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:603) at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:620) at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:226) at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:242) at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:45) at org.apache.logging.log4j.LogManager.getContext(LogManager.java:174) at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:618) at org.apache.logging.log4j.LogManager.getRootLogger(LogManager.java:652) Caused by: java.lang.NoClassDefFoundError: com/lmax/disruptor/EventFactory at org.apache.logging.log4j.core.config.AbstractConfiguration.getAsyncLoggerConfigDelegate(AbstractConfiguration.java:197) at org.apache.logging.log4j.core.async.AsyncLoggerConfig.(AsyncLoggerConfig.java:81) at org.apache.logging.log4j.core.async.AsyncLoggerConfig.createLogger(AsyncLoggerConfig.java:188) ... 23 more Caused by: java.lang.ClassNotFoundException: com.lmax.disruptor.EventFactory at java.net.URLClassLoader.findClass(URLClassLoader.java:381) at java.lang.ClassLoader.loadClass(ClassLoader.java:424) at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331) at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ... 26 more

I have verified, the disruptor jar which I included has this class. I am using disruptor-3.3.6.jar.

Also How to verify that the async logger has started ?

Any help would be appreciated.

Answer 1

Add the LMAX Disruptor dependency.To use AsyncLogger, your pom.xml should be like this

    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter</artifactId>
        <exclusions>
            <exclusion>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-starter-logging</artifactId>
            </exclusion>
        </exclusions>
    </dependency>
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-log4j2</artifactId>
    </dependency>
    <dependency> 
        <groupId>com.lmax</groupId>
        <artifactId>disruptor</artifactId>
        <version>3.3.7</version>
    </dependency>

Further reading : Performance of log4j2 compared to log4j1