为什么要升级
现在维护的公司项目,在不同的时期使用了不同的日志框架,最早的 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及其优势
直到看到了一篇文章《詹嵩:性能牛逼的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 的官方文件,找到 Log4j 1.x Migrating
发现:
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>
最后,日志的输出也预期一致。