Preliminary understanding log4j2 and use

Posted by webchef on Thu, 09 Dec 2021 17:25:45 +0100

Use of log4j2

Apache Log4j2 is an upgraded version of Log4j. It refers to some excellent designs of logback and fixes some problems, so it comes with
Some major improvements have been made, mainly including:

  • Exception handling. In logback, exceptions in the Appender will not be perceived by the application, but in log4j 2, some exceptions are provided
    Constant processing mechanism.
  • Performance improvement. Compared with log4j and logback, log4j2 has a significant performance improvement. The official test data will be available later.
  • Automatic overload configuration refers to the design of logback. Of course, it will provide automatic refresh parameter configuration. The most practical is that we are in production
    The log level can be dynamically modified on the without restarting the application.
  • No garbage mechanism. log4j2 can use its designed garbage free mechanism in most cases to avoid frequent log collection
    Resulting jvm gc.
    Official website

1. Log4j2 getting started

At present, the most popular log interface in the market is SLF4J. Although Log4j2 is also a log interface, its log implementation function is very powerful and its performance is superior. Therefore, Log4j2 is generally regarded as the implementation bold style of log. Slf4j + Log4j2 should be the general trend in the future.

  1. Add dependency
<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0"
         xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>

    <groupId>com.itheima</groupId>
    <artifactId>log4j2_demo</artifactId>
    <version>1.0-SNAPSHOT</version>


    <dependencies>


        <!--use slf4j As a log facade-->
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>1.7.26</version>
        </dependency>


        <!--use log4j2 Bind to your adapter-->
        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-slf4j-impl</artifactId>
            <version>2.9.1</version>
        </dependency>


        <!--log4j2 Log facade-->
        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-api</artifactId>
            <version>2.11.1</version>
        </dependency>
        <!--log4j2 Log implementation-->
        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-core</artifactId>
            <version>2.11.1</version>
        </dependency>

        <!--Asynchronous log dependency-->
        <dependency>
            <groupId>com.lmax</groupId>
            <artifactId>disruptor</artifactId>
            <version>3.3.4</version>
        </dependency>

        <!--junit unit testing -->
        <dependency>
            <groupId>junit</groupId>
            <artifactId>junit</artifactId>
            <version>4.12</version>
        </dependency>
    </dependencies>
    <build>
        <plugins>
            <!-- Set the compiled version to 1.8 -->
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-compiler-plugin</artifactId>
                <version>3.1</version>
                <configuration>
                    <source>1.8</source>
                    <target>1.8</target>
                    <encoding>UTF-8</encoding>
                </configuration>
            </plugin>
        </plugins>
    </build>
</project>
  1. JAVA code
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.junit.Test;
public class Log4j2Test {
    // Define logger objects
    public static final Logger LOGGER = LogManager.getLogger(Log4j2Test.class);
    // quick get start
    @Test
    public void testQuick()throws Exception{
        // Log message output
        LOGGER.fatal("fatal");
        LOGGER.error("error");
        LOGGER.warn("warn");
        LOGGER.info("inf");
        LOGGER.debug("debug");
        LOGGER.trace("trace");
    }
}

When we run, the following situations occur because there are fewer configuration files. The solution is to create a new log4j2. Config file in the resource directory xml

log4j. The XML is as follows:

<?xml version="1.0" encoding="UTF-8"?>
<!--
    status="warn" The output log level of the log framework itself
    monitorInterval="5" The interval between automatic loading of configuration files shall not be less than 5 seconds
-->
<Configuration status="debug" monitorInterval="5">

    <!--
        Centralized configuration attribute management
        Use through:${name}
    -->
    <properties>
        <property name="LOG_HOME">/logs</property>
    </properties>

    <!--Log processing-->
    <Appenders>
        <!--console output  appender-->
        <Console name="Console" target="SYSTEM_ERR">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] [%-5level] %c{36}:%L --- %m%n" />
        </Console>

        <!--Log file output appender-->
        <File name="file" fileName="${LOG_HOME}/myfile.log">
            <PatternLayout pattern="[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-5level] %l %c{36} - %m%n" />
        </File>

        <!--<Async name="Async">-->
            <!--<AppenderRef ref="file"/>-->
        <!--</Async>-->

        <!--Log file output using random read and write appender,Performance improvement-->
        <RandomAccessFile name="accessFile" fileName="${LOG_HOME}/myAcclog.log">
            <PatternLayout pattern="[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-5level] %l %c{36} - %m%n" />
        </RandomAccessFile>

        <!--Of log files split according to certain rules appender-->
        <RollingFile name="rollingFile" fileName="${LOG_HOME}/myrollog.log"
                     filePattern="/logs/$${date:yyyy-MM-dd}/myrollog-%d{yyyy-MM-dd-HH-mm}-%i.log">
            <!--Log level filter-->
            <ThresholdFilter level="debug" onMatch="ACCEPT" onMismatch="DENY" />
            <!--Log message format-->
            <PatternLayout pattern="[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-5level] %l %c{36} - %msg%n" />
            <Policies>
                <!--When the system starts, start the split rule to produce a new log file-->
                <OnStartupTriggeringPolicy />
                <!--Split by file size, 10 MB -->
                <SizeBasedTriggeringPolicy size="10 MB" />
                <!--Split by time node, rule by filePattern Defined-->
                <TimeBasedTriggeringPolicy />
            </Policies>
            <!--In the same directory, the number of files is limited to 30, exceeding which can be overwritten-->
            <DefaultRolloverStrategy max="30" />
        </RollingFile>
    </Appenders>
    
    <!--logger definition-->
    <Loggers>
        <!--Custom asynchronous logger object
            includeLocation="false" Turn off the line number information of logging
            additivity="false" Not in inheritance rootlogger object
        -->
        <AsyncLogger name="com.itheima" level="trace" includeLocation="false" additivity="false">
            <AppenderRef ref="Console"/>
        </AsyncLogger>
        
        <!--use rootLogger Configure log level level="trace"-->
        <Root level="trace">
            <!--Specifies the processor used by the log-->
            <AppenderRef ref="Console" />
            <!--Use asynchronous appender-->
            <AppenderRef ref="Async" />
        </Root>
    </Loggers>
</Configuration>

2. Log4j2 configuration

Log4j2 loads log4j2 under classpath by default The configuration in the XML file.

<?xml version="1.0" encoding="UTF-8"?>
<!--
    status="warn" The output log level of the log framework itself
    monitorInterval="5" The interval between automatic loading of configuration files shall not be less than 5 seconds
-->
<Configuration status="debug" monitorInterval="5">

    <!--
        Centralized configuration attribute management
        Use through:${name}
    -->
    <properties>
        <property name="LOG_HOME">/logs</property>
    </properties>

    <!--Log processing-->
    <Appenders>
        <!--console output  appender-->
        <Console name="Console" target="SYSTEM_ERR">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] [%-5level] %c{36}:%L --- %m%n" />
        </Console>

        <!--Log file output appender-->
        <File name="file" fileName="${LOG_HOME}/myfile.log">
            <PatternLayout pattern="[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-5level] %l %c{36} - %m%n" />
        </File>

        <!--<Async name="Async">-->
            <!--<AppenderRef ref="file"/>-->
        <!--</Async>-->

        <!--Log file output using random read / write streams appender,Performance improvement-->
        <RandomAccessFile name="accessFile" fileName="${LOG_HOME}/myAcclog.log">
            <PatternLayout pattern="[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-5level] %l %c{36} - %m%n" />
        </RandomAccessFile>

        <!--Of log files split according to certain rules appender-->
        <RollingFile name="rollingFile" fileName="${LOG_HOME}/myrollog.log"
                     filePattern="/logs/$${date:yyyy-MM-dd}/myrollog-%d{yyyy-MM-dd-HH-mm}-%i.log">
            <!--Log level filter-->
            <ThresholdFilter level="debug" onMatch="ACCEPT" onMismatch="DENY" />
            <!--Log message format-->
            <PatternLayout pattern="[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-5level] %l %c{36} - %msg%n" />
            <Policies>
                <!--When the system starts, the split rule is triggered to produce a new log file-->
                <OnStartupTriggeringPolicy />
                <!--Split by file size, 10 MB -->
                <SizeBasedTriggeringPolicy size="10 MB" />
                <!--Split by time node, rule by filePattern Defined-->
                <TimeBasedTriggeringPolicy />
            </Policies>
            <!--In the same directory, the number of files is limited to 30, exceeding which can be overwritten-->
            <DefaultRolloverStrategy max="30" />
        </RollingFile>

    </Appenders>

    <!--logger definition-->
    <Loggers>


        <!--Custom asynchronous logger object
            includeLocation="false" Turn off the line number information of logging
            additivity="false" Not in inheritance rootlogger object
        -->
        <AsyncLogger name="com.itheima" level="trace" includeLocation="false" additivity="false">
            <AppenderRef ref="Console"/>
        </AsyncLogger>


        <!--use rootLogger Configure log level level="trace"-->
        <Root level="trace">
            <!--Specifies the processor used by the log-->
            <AppenderRef ref="Console" />

            <!--Use asynchronous appender-->
            <AppenderRef ref="Async" />
        </Root>
    </Loggers>
</Configuration>

3. Log4j2 asynchronous log

Asynchronous log
The biggest feature of log4j2 is asynchronous logging, and 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
The Appender component and Logger component we mentioned earlier.

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

<?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>

2. Asyncloger 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 logs 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.itheima" level="trace" includeLocation="false" additivity="false"> 
				<AppenderRef ref="file"/> 
			</AsyncLogger> 
			<Root level="info" includeLocation="true"> 
				<AppenderRef ref="file"/> 
			</Root> 
	</Loggers> 
</Configuration>

Above configuration: com Itheima logs are asynchronous and root logs are synchronous.

  • Issues needing attention when using asynchronous logs:
    1. If asynchronous logging is used, AsyncAppender, AsyncLogger and global logging 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.

4. 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 similar to that of Log4j and Log4j
The comparison of logbacks is shown in the figure below. In the comparison in the following figure, Log4j2 has three modes: 1) asynchronous mode is used globally; 2) Some loggers use different
Step mode; 3) Asynchronous Appender. It can be seen that in the first two modes, the performance of Log4j2 is much better than that of Log4j and Logback
Advantages.

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 logstores (including previous versions of Log4j) allocate temporary objects during steady-state logging, such as log event objects, strings,
Character array, byte array, 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 resources are not allocated as much as possible
Time object. 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 realized by reusing the objects in the ThreadLocal field, and partly by converting text
Reuse the buffer when the byte is.

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 an asynchronous logger.

Topics: Java Apache Maven