Log4J 2 Async Logger and Threads

Question

I am trying to make all Log4J 2 loggers asynchronous with IMAP Disruptor. I have the disruptor dependencies correctly set, and in IntelliJ, I have set the following system property under VM options.

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

My log4j2.xml file is this.

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="trace">
<Appenders>
    <Console name="Console-Appender" target="SYSTEM_OUT">
        <PatternLayout>
            <pattern>
                [%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} - %msg%n
            </pattern>>
        </PatternLayout>
    </Console>
    <File name="File-Appender" fileName="logs/xmlfilelog.log" >
        <PatternLayout>
            <pattern>
                [%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} - %msg%n
            </pattern>
        </PatternLayout>
    </File>
</Appenders>
<Loggers>
    <Logger name="guru.springframework.blog.log4j2async" level="debug">
        <AppenderRef ref="File-Appender"/>
    </Logger>
    <Root level="debug">
        <AppenderRef ref="Console-Appender"/>
    </Root>
</Loggers>
</Configuration>

My logger class have this code.

package guru.springframework.blog.log4j2async;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class Log4J2AsyncLogger {

private static Logger logger = LogManager.getLogger();
public Log4J2AsyncLogger(){
    logger.info("Logger created by Thread Id:"+Thread.currentThread().getId());
}
public void performSomeTask(){
        logger.debug("This is a debug message sent by Thread Id:" + Thread.currentThread().getId());
        logger.info("This is a info message sent by Thread Id:" + Thread.currentThread().getId());
        logger.warn("This is a warn message sent by Thread Id:" + Thread.currentThread().getId());
        logger.error("This is a error message sent by Thread Id:" + Thread.currentThread().getId());
        logger.fatal("This is a fatal message sent by Thread Id:" + Thread.currentThread().getId());
 }
}

I expected the output of log messages with different thread IDs. But, both the console and file outputs are:

[INFO ] 2016-03-25 11:41:01.189 [main] Log4J2AsyncLogger - System property Log4jContextSelector: org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
[INFO ] 2016-03-25 11:41:01.189 [main] Log4J2AsyncLogger - Logger created by Thread Id:1
[DEBUG] 2016-03-25 11:41:01.189 [main] Log4J2AsyncLogger - This is a debug message sent by Thread Id:1
[INFO ] 2016-03-25 11:41:01.189 [main] Log4J2AsyncLogger - This is a info message sent by Thread Id:1
[WARN ] 2016-03-25 11:41:01.189 [main] Log4J2AsyncLogger - This is a warn message sent by Thread Id:1
[ERROR] 2016-03-25 11:41:01.189 [main] Log4J2AsyncLogger - This is a error message sent by Thread Id:1
[FATAL] 2016-03-25 11:41:01.189 [main] Log4J2AsyncLogger - This is a fatal message sent by Thread Id:1

In the logger class, I tried using a for loop with 1000 loops to log the messages, but still the same main thread is doing all the work. What am I doing wrong?

You can add -Dlog4j2.debug=true to your VM options and then you should see the async logger being used by Log4J2. — dutoitns
– dutoitns, Commented Jun 17, 2024 at 10:09

Remko Popma · Accepted Answer · 2016-03-27 00:53:11Z

5

Log4j creates a snapshot of the message in the calling thread (your application thread). It will be written to disk in a separate background thread, but that will not affect the message content.

The thread name or ID of the background thread is never shown in the log. This is by design.

edited Mar 27, 2016 at 0:53

answered Mar 26, 2016 at 0:57

Remko Popma

37.2k11 gold badges98 silver badges122 bronze badges

Sign up to request clarification or add additional context in comments.

3 Comments

mcacorner Over a year ago

As per my understanding in case of async logger in log file log statement's datetime will be same as when log statement was executed.

barneypitt Over a year ago

Takes a "snapshot" how? Deep-copying objects not designed for deep copy is always problematic in Java.

dutoitns Over a year ago

I would assume it just snapshots \ copies the String values that are required for the logging statement. In other words, it doesn't have to perform a "deep copy" of your object.

Collectives™ on Stack Overflow

Log4J 2 Async Logger and Threads

1 Answer 1

3 Comments

Your Answer

Hot Network Questions

Collectives™ on Stack Overflow

1 Answer 1

3 Comments

Your Answer

Sign up or log in

Post as a guest

Related