Log4j2 asynchronous logging and garbage collection

Asynchronous log
The biggest feature of log4j2 is asynchronous logging. Its performance improvement mainly benefits from asynchronous logging. Let's see how to use log4j2 asynchronous logging.

  • Synchronization log

  • Asynchronous log

Log4j2 provides two ways to implement logging, one through AsyncAppender and the other through asyncloger, corresponding to the Appender component and Logger component mentioned above.

Note: you need to add dependencies to configure asynchronous logs

<!--Asynchronous log dependency-->
        <dependency>
            <groupId>com.lmax</groupId>
            <artifactId>disruptor</artifactId>
            <version>3.3.4</version>
        </dependency>
  1. AsyncAppender mode
    Asyncloger is the highlight of log4j2 and the officially recommended asynchronous method. It allows you to call logger Log returns faster. You have two options: Global asynchrony and hybrid asynchrony.
<?xml version="1.0" encoding="UTF-8"?> 
<Configuration status="warn"> 
    <properties> 
        <property name="LOG_HOME">D:/logs</property> 
    </properties> 
    <Appenders> 
        <File name="file" fileName="${LOG_HOME}/myfile.log"> 
            <PatternLayout> 
                <Pattern>%d %p %c{1.} [%t] %m%n</Pattern> 
            </PatternLayout> 
        </File> 
        <Async name="Async"> 
            <AppenderRef ref="file"/> 
        </Async> 
    </Appenders> 
    <Loggers> 
        <Root level="error">
            <AppenderRef ref="Async"/> 
        </Root> 
    </Loggers> 
</Configuration>
  1. AsyncLogger mode
    Asyncloger is the highlight of log4j2 and the officially recommended asynchronous method. It allows you to call logger Log returns faster. You have two options: Global asynchrony and hybrid asynchrony.

Global asynchrony means that all logs are recorded asynchronously. There is no need to make any changes in the configuration file, just add a log4j2 component. Properties configuration;

Log4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerCon textSelector

Hybrid asynchrony means that you can use both synchronous and asynchronous logs in your application, which makes the log configuration more flexible.

<?xml version="1.0" encoding="UTF-8"?> 
<Configuration status="WARN"> 
    <properties> 
        <property name="LOG_HOME">D:/logs</property> 
    </properties> 
    <Appenders> 
        <File name="file" fileName="${LOG_HOME}/myfile.log"> 
            <PatternLayout> 
                <Pattern>%d %p %c{1.} [%t] %m%n</Pattern> 
            </PatternLayout> 
        </File> 
        <Async name="Async"> 
            <AppenderRef ref="file"/> 
        </Async> 
    </Appenders> 
    <Loggers> 
        <AsyncLogger name="com.huan" level="trace" includeLocation="false" additivity="false"> 
            <AppenderRef ref="file"/> 
        </AsyncLogger>
     	<Root level="info" includeLocation="true"> 
        	<AppenderRef ref="file"/> 
    	</Root> 
	</Loggers> 
</Configuration>

Above configuration: com The Huan log is asynchronous and the root log is synchronous.
Issues needing attention when using asynchronous log:

  1. If asynchronous logs are used, AsyncAppender, asyncloger and global logs should not appear at the same time. Performance will be consistent with AsyncAppender and minimized.
  2. If includeLocation=false is set, printing location information will dramatically reduce the performance of asynchronous logs, which is slower than synchronous logs.

Performance of Log4j2

The best thing about Log4j2 is its performance when outputting logs asynchronously. The throughput of Log4j2 in a multi-threaded environment is compared with Log4j and Logback, as shown in the figure below. In the comparison below, Log4j2 has three modes:
1) Asynchronous mode is used globally;
2) Some loggers adopt asynchronous mode;
3) Asynchronous Appender. It can be seen that the performance of 4log and 4j2log has great advantages over the first two modes.

No garbage record

Garbage collection pauses are a common cause of peak latency, and for many systems, a lot of effort is spent on controlling these pauses.

Many log libraries (including previous versions of Log4j) allocate temporary objects during steady-state logging, such as log event objects, strings, character arrays, byte arrays, etc. This puts pressure on the garbage collector and increases the frequency of GC pauses.

Starting with version 2.6, Log4j runs in "garbage free" mode by default, in which objects and buffers are reused and temporary objects are not allocated as much as possible. There is also a "low garbage" mode, which is not completely garbage free, but does not use the ThreadLocal field.

The garbage free logging in Log4j 2.6 is achieved partly by reusing objects in the ThreadLocal field and partly by reusing buffers when converting text to bytes.

Using Log4j 2.5: memory allocation rate 809 MB / s, 141 invalid sets.


Log4j 2.6 does not allocate a temporary object: 0 (zero) garbage collection.


There are two separate system properties that can be used to manually control the mechanism Log4j uses to avoid creating temporary objects:

log4j2.enableThreadlocals - if the "true" (non Web application default) object is stored in the ThreadLocal field and reused, otherwise a new object will be created for each log event.

log4j2.enableDirectEncoders - if the "true" (default) log event is converted to text, this text is converted to bytes without creating a temporary object.

Note: synchronization logging performance for multithreaded applications may be worse in this mode due to synchronization on the shared buffer. If your application is multithreaded and logging performance is important, consider using asynchronous
Recorder.

Keywords: Java

Added by mwaw on Fri, 18 Feb 2022 03:23:17 +0200