是时候将日志框架升级到Log4j2了

Posted 2021-04-20 HelloTech

为什么要升级

现在维护的公司项目，在不同的时期使用了不同的日志框架，最早的 Log4j，前两年开始使用 Spring Boot ，日志使用了 Logback，最近看到一些介绍 Log4j2 的文章和官方的性能测试对比。所以计划在未来的新项目中使用 Log4j2，及旧项目的日志升级为 Log4j2 。在实践的过程中也遇到了一些问题，下面做一个简单的记录。

旧项目的日志使用的Log4j

• 一般，在生产环境的日志级别会设置为 INFO （优先级从高到低依次为：FATAL、ERROR、WARN、INFO、DEBUG、TRACE）， 低于这个级别的日志不会输出，但是下面这段代码，即使不输出，也会执行字符串的拼接

 
   
   
 

  
    
    
  
log.debug("param1 = " + param1 + ", param2 = " + param2);
 
   
   
 

所以为了不必要的性能损耗，需要加上判断：

 
   
   
 

  
    
    
  
if (log.isDebugEnable) {
  
    
    
  
    log.debug("param1 = " + param1 + ", param2 = " + param2);
  
    
    
  
}
 
   
   
 

• Log4j的另一个问题是：日志并发输出的时候，发现大量的处理线程blocked 在等待同一个 log4j 的 rootLogger 对象锁，所以会锁等待，在高并发且日志输出频繁的情况下，这个锁等待的情况会很严重，进而影响了应用的性能表现。

Spring Boot 默认日志配置

• 默认日志 Logback

• Logback 是 Log4j 框架的作者开发的新一代日志框架，它效率更高、能够适应诸多的运行环境，同时天然支持 slf4j。

• 定义了日志的切分方式，如：把每一天的日志归档到一个文件中。

• 表示只保留最近30天的日志，以防止日志填满整个磁盘空间。

Log4j2及其优势

直到看到了一篇文章《》，才决定再次对 Logback 进行升级。

升级过程与遇到的问题

先体验一下使用 Lo4j2 的 Demo， 然后再聊升级的问题

添加依赖

 
   
   
 

  
    
    
  
<dependency>
  
    
    
  
    <groupId>org.apache.logging.log4j</groupId>
  
    
    
  
    <artifactId>log4j-api</artifactId>
  
    
    
  
    <version>2.6.2</version>
  
    
    
  
</dependency>
  
    
    
  
<dependency>
  
    
    
  
    <groupId>org.apache.logging.log4j</groupId>
  
    
    
  
    <artifactId>log4j-core</artifactId>
  
    
    
  
    <version>2.6.2</version>
  
    
    
  
</dependency>
 
   
   
 

Log4j2 默认会在 classpath 目录下寻找 log4j.json、log4j.jsn、log4j2.xml 等名称的文件，如果都没有找到，则会按默认配置输出到控制台，并输出如下提示：

 
   
   
 

  
    
    
  
ERROR StatusLogger No log4j2 configuration file found. Using default configuration: logging only errors to the console.
 
   
   
 

最简单的配置

 
   
   
 

  
    
    
  
<?xml version="1.0" encoding="UTF-8"?>
  
    
    
  
<Configuration status="WARN">
  
    
    
  
    <Appenders>
  
    
    
  
        <Console name="Console" target="SYSTEM_OUT">
  
    
    
  
            <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n" />
  
    
    
  
        </Console>
  
    
    
  
    </Appenders>
  
    
    
  
    <Loggers>
  
    
    
  
        <Root level="error">
  
    
    
  
            <AppenderRef ref="Console" />
  
    
    
  
        </Root>
  
    
    
  
    </Loggers>
  
    
    
  
</Configuration>
 
   
   
 

如上面的配置，我们添加的配置文件 log4j2.xml，以 Configuration 为根节点，有一个 status 属性，这个属性表示 log4j2 本身的日志信息打印级别。如果把 status 改为 TRACE 再执行测试代码，可以看到控制台中打印了一些 log4j 加载插件、组装 logger 等调试信息（一般设置为 OFF ）。 日志级别从低到高分为 TRACE < DEBUG < INFO < WARN < ERROR < FATAL，如果设置为 WARN，则低于 WARN 的信息都不会输出。对于Loggers 中 level 的定义同样适用。

下面是 Appender 配置，Appender 可以理解为日志的输出目的地，这里配置了一个类型为 Console 的 Appender，也就是输出到控制台。Console 节点中的 PatternLayout 定义了输出日志时的格式：

• %d{HH:mm:ss.SSS} 表示输出到毫秒的时间

• %t 输出当前线程名称

• %-5level 输出日志级别，-5表示左对齐并且固定输出5个字符，如果不足在右边补0

• %logger 输出 logger 名称，因为 Root Logger 没有名称，所以没有输出

• %msg 日志文本

• %n 换行

• %F 输出所在的类文件名，如 Demo.java

• %L 输出行号

• %M 输出所在方法名

• %l  输出语句所在的行数, 包括类名、方法名、文件名、行数

自定义 Logger 与 Appender

 
   
   
 

  
    
    
  
<?xml version="1.0" encoding="UTF-8"?>
  
    
    
  
<configuration status="OFF">
  
    
    
  
    <properties>
  
    
    
  
        <property name="LOG_HOME">/data/phone-schedule-server/logs/</property>
  
    
    
  
        <property name="FILE_NAME">stdout</property>
  
    
    
  
        <property name="TRAFFIC_FILE_NAME">traffic</property>
  
    
    
  
        <property name="TIME_FILE_NAME">time-log</property>
  
    
    
  
    </properties>
  
    
    
  
    <appenders>
  
    
    
  
        ...
  
    
    
  
        <RollingRandomAccessFile name="stdout" fileName="${LOG_HOME}/${FILE_NAME}.log"
  
    
    
  
                                 filePattern="${LOG_HOME}/$${date:yyyy-MM}/${FILE_NAME}-%d{yyyy-MM-dd}-%i.log.gz" append="true">
  
    
    
  
            <PatternLayout pattern="%date{yyyy-MM-dd HH:mm:ss.SSS} %level [%thread][%file:%line] - %msg%n" />
  
    
    
  
            <Policies>
  
    
    
  
                <TimeBasedTriggeringPolicy />
  
    
    
  
                <SizeBasedTriggeringPolicy size="100 MB" />
  
    
    
  
            </Policies>
  
    
    
  
            <DefaultRolloverStrategy max="20" />
  
    
    
  
        </RollingRandomAccessFile>
  
    
    
  
        ...
  
    
    
  
    </appenders>
  
    
    
  
    <loggers>
  
    
    
  

  
    
    
  
        <logger name="io.netty" level="error"/>
  
    
    
  
        <logger name="com.baidu.aip" level="error" />
  
    
    
  

  
    
    
  
        <logger name="service" level="info" additivity="false">
  
    
    
  
            <AppenderRef ref = "stdout" />
  
    
    
  
            <!--<AppenderRef ref="Console" />-->
  
    
    
  
        </logger>
  
    
    
  
        ...
  
    
    
  

  
    
    
  
        <root level="info">
  
    
    
  
            <AppenderRef ref="stdout" />
  
    
    
  
            <AppenderRef ref="Console" />
  
    
    
  
        </root>
  
    
    
  
    </loggers>
  
    
    
  
</configuration>
 
   
   
 

实践配置

<properties> 定义了常量方便后面复用

RollingRandomAccessFile 的属性：

• fileName  指定当前日志文件的位置和文件名称

• filePattern  指定当发生 Rolling 时，文件的转移和重命名规则

• SizeBasedTriggeringPolicy  指定当文件体积大于 size 指定的值时，触发 Rolling

• DefaultRolloverStrategy  指定最多保存的文件个数

• TimeBasedTriggeringPolicy  这个配置需要和 filePattern 结合使用，注意 filePattern 中配置的文件重命名规则是${FILE_NAME}-%d{yyyy-MM-dd HH-mm}-%i，最小的时间粒度是mm，即分钟，TimeBasedTriggeringPolicy 指定的 size 是1，结合起来就是每一分钟生成一个新文件。如果改成%d{yyyy-MM-dd HH}，最小粒度为小时，则每一个小时生成一个文件。

异步配置

Async：异步，需要通过 AppenderRef 来指定要对哪种输出源进行异步（一般用于配置RollingRandomAccessFile）

 
   
   
 

  
    
    
  
<Async name="AsyncAppender">
  
    
    
  
     <AppenderRef ref="RollingRandomAccessFile"/>
  
    
    
  
</Async>
 
   
   
 

定义日志输出的地方

Appenders：输出源，用于定义日志输出的地方 log4j2 支持的输出源有很多，有控制台 Console、文件 File、RollingRandomAccessFile、MongoDB、Flume 等

• Console：控制台输出源是将日志打印到控制台上，开发的时候一般都会配置，以便调试

• File：文件输出源，用于将日志写入到指定的文件，需要配置输入到哪个位置（例如：D:/logs/mylog.log）

• RollingRandomAccessFile: 该输出源也是写入到文件，不同的是比 File 更加强大，可以指定当文件达到一定大小（如20MB）时，另起一个文件继续写入日志，另起一个文件就涉及到新文件的名字命名规则，因此需要配置文件命名规则，因为不可能一直往一个文件中写，如果一直写，文件过大，打开就会卡死，也不便于查找日志。

• NoSql：MongoDb, 输出到 MongDb 数据库中

• Flume：输出到 Apache Flume，Flume 是 Cloudera提供的一个高可用的，高可靠的，分布式的海量日志采集、聚合和传输的系统，Flume 支持在日志系统中定制各类数据发送方，用于收集数据；同时，Flume 提供对数据进行简单处理，并写到各种数据接受方（可定制）的能力。

升级的过程

由于在项目中使用了百度的语音识别的 Java SDK，在测试的过程中发现有很多 com.baidu.ai 包下 Debug 的日志输入，本以为只要配置了 Log4j2.xml 文件及在 Maven 中引入相应的依赖就可以正常使用了，一直以为出现 Debug 级别的日志在我配置的文件，配置如下：

maven:

 
   
   
 

  
    
    
  
<dependency>
  
    
    
  
    <groupId>com.baidu.aip</groupId>
  
    
    
  
    <artifactId>java-sdk</artifactId>
  
    
    
  
    <version>${baiduai.version}</version>
  
    
    
  
</dependency>
 
   
   
 

log4j2.xml

 
   
   
 

  
    
    
  
<loggers>
  
    
    
  
    <logger name="io.netty" level="error"/>
  
    
    
  
    <logger name="com.baidu.aip" level="error" />
  
    
    
  
</loggers>
 
   
   
 

后来，仔细看了一下百度的文档，日志使用的 Log4j，所以就顺着思路看了一下 maven 的依赖关系，

然后增加了 exclusions ，如下：

 
   
   
 

  
    
    
  
<dependency>
  
    
    
  
    <groupId>com.baidu.aip</groupId>
  
    
    
  
    <artifactId>java-sdk</artifactId>
  
    
    
  
    <version>${baiduai.version}</version>
  
    
    
  
    <exclusions>
  
    
    
  
        <exclusion>
  
    
    
  
            <artifactId>log4j</artifactId>
  
    
    
  
            <groupId>log4j</groupId>
  
    
    
  
        </exclusion>
  
    
    
  
    </exclusions>
  
    
    
  
</dependency>
 
   
   
 

然后再测试，结果还是不达预期！

下一步查阅了一下 Lo4j2 的官方文件，找到 Log4j1.xMigrating 发现：

Perhaps the simplest way to convert to using Log4j 2 is to replace the log4j 1.x jar file with Log4j 2's log4j-1.2-api.jar. However, to use this successfully applications must meet the following requirements: ......

于是，在 maven 的依赖中增加 log4j-1.2-api.jar ，如下：

 
   
   
 

  
    
    
  
<dependency>
  
    
    
  
    <groupId>org.apache.logging.log4j</groupId>
  
    
    
  
    <artifactId>log4j-api</artifactId>
  
    
    
  
    <version>2.6.2</version>
  
    
    
  
</dependency>
  
    
    
  
<dependency>
  
    
    
  
    <groupId>org.apache.logging.log4j</groupId>
  
    
    
  
    <artifactId>log4j-core</artifactId>
  
    
    
  
    <version>2.6.2</version>
  
    
    
  
</dependency>
  
    
    
  
<dependency>
  
    
    
  
    <groupId>org.apache.logging.log4j</groupId>
  
    
    
  
    <artifactId>log4j-1.2-api</artifactId>
  
    
    
  
    <version>2.6.2</version>
  
    
    
  
</dependency>
 
   
   
 

最后，日志的输出也预期一致。