日志系列-Log4j2简明教程

在大型系统中,日志是一个很重要的部分,线上问题的排查很大程度上依赖日志。记录日志的过程,大体上可以分成三个步骤:

  • 在程序中对原始日志信息进行采集
  • 对采集下来的日志信息进行格式化
  • 将格式化好的日志信息写入目的地

Log4j2 的架构也自然是按照这个来的,Log4j2 中有三个重要的组件分别实现了这些功能,分别是 LoggerLayoutAppender,日志数据流向图如下:

Log4j2 使用

Log4j2 使用很简单,以 Maven 为例,只需要在 pom.xml 中添加:

1
2
3
4
5
6
7
8
9
10
11
12
<dependencies>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-api</artifactId>
<version>2.12.1</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-core</artifactId>
<version>2.12.1</version>
</dependency>
</dependencies>

然后就可以在 Java 代码中直接使用:

1
2
3
4
5
6
7
8
9
10
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
public class Log4j2HelloWorld {

private static final Logger logger = LogManager.getLogger(Log4j2HelloWorld.class);

public static void main(String[] args) {
logger.error("Hello world");
}
}

如果不加配置文件,默认的输出级别是 ERROR

配置详解

Log4j2 有两种配置方式:

  • 通过 ConfigurationFactory 使用编程的方式进行配置
  • 通过配置文件配置,支持 XMLJSONYAMLproperties 等文件类型

通过编程实现的方式如下:

1
2
3
4
5
6
7
8
9
10
11
@Plugin(name = "CustomerConfigurationFactory", category = ConfigurationFactory.CATEGORY)
public class CustomerConfigurationFactory extends ConfigurationFactory {
protected String[] getSupportedTypes() {
return new String[0];
}
public Configuration getConfiguration(LoggerContext loggerContext, ConfigurationSource configurationSource) {
ConfigurationBuilder<BuiltConfiguration> builder = newConfigurationBuilder();
builder.setStatusLevel(Level.INFO);
return builder.build();
}
}

Log4j2 在找不到配置文件的情况下会使用一个默认的配置,默认的配置只会在控制台打印日志,并且默认级别是 Level.ERROR

Log4j2 中,默认实现了四种 ConfigurationFactory,分别用来加载 JSON YAML properties XML 格式的配置文件。

默认的配置文件名称为 log4j2,会根据 log4j2 的文件类型匹配相应的 ConfigurationFactory 的具体实现。比如 log4j2.xml 会使用 XmlConfigurationFactory 来读取配置文件,其它类型的配置文件同理。

假如同时存在 log4j2.properties log4j2.yaml log4j2.json log4j2.xml 四个配置文件,加载的优先级为 properties > yaml > json > xml

四种配置文件的配置方式基本一致,区别在于每种配置文件的语法不一样。下面以 XML 为例进行解析。

XML 有两种配置模式,简约模式严格模式

Configuration

Confirguration 是配置文件根元素,每个配置文件有且仅有一个。如果不使用配置文件使用默认配置,以下配置与默认配置等价:

1
2
3
4
5
6
7
8
9
10
11
12
13
<?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>

每一个配置都至少包含一个 AppenderLoggerstatus 属性用于配置 Log4j2 内部的的日志级别。

Log4j2 可以自动检测配置文件的变化,monitorInterval 属性可以配置自动检测配置文件的时间,这个属性最小的值为 5,代表 5 秒检测一次。

1
2
3
4
<?xml version="1.0" encoding="UTF-8"?>
<Configuration monitorInterval="30">
....
</Configuration>

Logger

Logger 元素用于配置日志记录器。Logger 有两种形式,LoggerRoot,两个区别在于 Root 没有 name 属性并且不支持 additivity 属性。

假如我们要获取一个特定类的的某个级别的日志。调高日志的级别无法完成这样的需求。一种可行的方式是在 Loggers 中添加一个 Logger,配置方式如下:

1
2
3
4
5
6
7
8
<Loggers>
<Logger name="cn.rayjun.Log4j2HelloWorld" level="trace">
<AppenderRef ref="Console"/>
</Logger>
<Root level="error">
<AppenderRef ref="Console"/>
</Root>
</Loggers>

这样配置,除了 cn.rayjun.Log4j2HelloWorld 类会打印出 trace 级别的日志,其他就只会打印出 error 级别的日志,打印结果如下:

1
2
3
4
19:59:06.957 [main] TRACE cn.rayjun.Log4j2HelloWorld - Enter
19:59:06.957 [main] TRACE cn.rayjun.Log4j2HelloWorld - Enter
19:59:06.959 [main] ERROR cn.rayjun.Log4j2HelloWorld - Hello world
19:59:06.959 [main] ERROR cn.rayjun.Log4j2HelloWorld - Hello world

但是上面打印的日志有个问题,信息都被打印了两遍,为了解决这个问题,需要添加 additivity 参数并且置为 false,如下配置:

1
2
3
4
5
6
7
8
<Loggers>
<Logger name="cn.rayjun.Log4j2HelloWorld" level="trace" additivity="false">
<AppenderRef ref="Console"/>
</Logger>
<Root level="error">
<AppenderRef ref="Console"/>
</Root>
</Loggers>

默认情况下 Logger 都是同步的,但是也有异步的实现,Root 的异步版本是 AsyncRoot,Logger 的异步版本是 AsyncLogger,异步 Logger 依赖外部队列 LMAX Disruptor

使用异步 Logger 需要加上外部依赖:

1
2
3
4
5
<dependency>
<groupId>com.lmax</groupId>
<artifactId>disruptor</artifactId>
<version>3.4.2</version>
</dependency>

使用异步 Logger:

1
2
3
<AsyncRoot level="error">
<AppenderRef ref="Console"/>
</AsyncRoot>

Logger 在具体使用中需要声明一个 Logger 对象,官方推荐将 Logger 声明为一个静态变量,可以提高日志记录的性能:

1
private static final Logger logger = LogManager.getLogger(Log4j2HelloWorld.class);

Appender 配置

Appender 负责将日志分发到相应的目的地。也就是说 Appender 决定日志以何种方式展示,上面使用到的就是 ConsoleAppender,这个 Appender 会将日志直接打印到控制台。同时还支持将日志输出到文件数据库消息队列

FileAppender 基本配置如下:

1
2
3
4
5
<File name="MyFile" fileName="logs/app.log">
<PatternLayout>
<Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
</PatternLayout>
</File>

如果想要把日志记录到数据库中,那就使用JDBCAppender, 基本配置如下:

1
2
3
4
5
6
7
8
<JDBC name="databaseAppender" tableName="dbo.application_log">
<DataSource jndiName="java:/comp/env/jdbc/LoggingDataSource" />
<Column name="eventDate" isEventTimestamp="true" />
<Column name="level" pattern="%level" />
<Column name="logger" pattern="%logger" />
<Column name="message" pattern="%message" />
<Column name="exception" pattern="%ex{full}" />
</JDBC>

默认情况下 Appender 都是同步的,就是说日志产生的时候就会进行处理。但是有时候会从程序性能的角度进行考虑,生成的日志不会立即进行刷盘或者进行传输,而是在一个合适的时间集中进行处理,配置方式如下,异步 Appender 使用 ArrayBlockingQueue 作为队列,与异步 Logger 不同,异步 Appender 不需要外部依赖,但是官方推荐使用异步 Logger 而不是异步 Appender:

1
2
3
4
5
6
7
8
9
10
<Appenders>
<File name="MyFile" fileName="logs/app.log">
<PatternLayout>
<Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
</PatternLayout>
</File>
<Async name="Async">
<AppenderRef ref="MyFile"/>
</Async>
</Appenders>

把日志保存为文件是一个常用的操作,保存在文件中的日志以追加方式写入,但是单个文件不可能无限增大,也不可能手工来分割日志文件,所以需要通过自动的方式来分割日志。这就需要使用 RollingFileAppender,通过设定日志分割的条件。分割的条件可以从两个方面进行设定,以时间频率或者日志文件的大小来触发日志的分割。

1
2
3
4
5
6
7
8
9
10
<RollingFile name="RollingFile" fileName="logs/app.log"
filePattern="logs/$${date:yyyy-MM}/app-%d{MM-dd-yyyy}-%i.log.gz">
<PatternLayout>
<Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
</PatternLayout>
<Policies>
<TimeBasedTriggeringPolicy />
<SizeBasedTriggeringPolicy size="250 MB"/>
</Policies>
</RollingFile>

TimeBasedTriggeringPolicy 会与 filePattern 的配置相匹配,如果 filePattern 是 {yyyy-MM-dd HH-mm} ,最小的时间粒度是分钟,那么就会每隔一分钟生成一个文件,如果改成 {yy-MM-dd HH},最小时间粒度是小时,那么就会每隔一个小时生成一个文件。SizeBasedTriggeringPolicy 表示设定日志的大小,上面的配置是指日志大小到 250M 后开始生成新的日志文件。

RollingRandomAccessFileAppenderRollingFileAppender 在功能上基本一致,但是底层的实现有所区别,RollingFileAppender 底层是 BufferedOutputStream,RollingRandomAccessFileAppender 底层是使用 ByteBuffer + RandomAccessFile ,性能上有了很大的提升。

Layouts

Appender 会使用 Layout 来对日志进行格式化。Lo4j1 和 Logback 中的 Layout 会把日志转成 String,而在 Log4j2 中使用的则是 byte 数组,这是从性能的角度进行的优化。

Layout 配置支持多种方式。用的最多的方式就是 PatternLayout,就是通过正则表达式来格式化日志,应用的也最多,基本配置如下:

1
2
3
<PatternLayout>
<Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
</PatternLayout>

  • %d 表示时间,默认情况下表示打印完整时间戳 2012-11-02 14:34:02,123,可以调整 %d 后面的参数来调整输出的时间格式
  • %p 表示输出日志的等级,可以使用 %highlight 来高亮显示日志级别
  • %c 用来输出类名,默认输出的是完整的包名和类名,%c{1.} 输出包名的首字母和完整类名
  • %t 表示线程名称
  • %m 表示日志内容,%M 表示方法名称
  • %n 表示换行符
  • %L 表示打印日志的代码行数

Filter

Filter 用于过滤一些日志信息,Filter 在过滤每一条日志时都会返回一个值 ACCEPTDENY 或者NEUTRAL

不同的 Filter 的有不同的用处,BrustFilter 用于防止日志流量过大,还可以使用 DynamicThresholdFilter 根据属性来过滤特定级别的日志。可以根据具体的需要选择相应的 Filter

完整配置示例

假设现在有一个日志需求:日志以文件的形式进行保存,需要保存完整的日志信息,包括日志对应的类代码行数等,并且需要根据时间和日志文件的大小生成新的日志文件。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
<Configuration status="warn">
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="[%-5p %d{yyyy-MM-dd HH:mm:ss.SSS}] [%t] [%C.%M] [%m]%n"/>
</Console>
<RollingRandomAccessFile name="${service_name}-log"
fileName="~/${service_name}/${service_name}.log"
filePattern="~/${service_name}/${service_name}.log.%d{yyyyMMddHH}"
append="true" immediateFlush="false">
<PatternLayout
pattern="[%-5p %d{yyyy-MM-dd HH:mm:ss.SSS}] [%t] [%C.%M] [%m]%n"/>
<Policies>
<TimeBasedTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="250 MB"/>
</Policies>
</RollingRandomAccessFile>
</Appenders>
<Loggers>
<AsyncRoot level="${log_level}" includeLocation="true">
<AppenderRef ref="Console"/>
<AppenderRef ref="${service_name}-log" />
</AsyncRoot>
</Loggers>
</Configuration>

Logger 上如果加上了 includeLocation 后,日志性能会下降的很厉害,如果日志的位置信息不是必要的,就不需要加上

自定义日志级别

Log4j2 中内置的日志级别有:

级别
OFF 0
FATAL 100
ERROR 200
WARN 300
INFO 400
DEBUG 500
TRACE 600
ALL Integer.MAX_VALUE

如果这些日志还不满足需求,可以自定义日志的级别,可以在配置文件当中定义,也可以在代码中直接定义。每一个自定义的日志都由两部分组成,级别名称级别的值,可以根据自己的需要进行定义。

Confguration 节点下加上以下自定义级别,就可以在 Logger 中使用

1
2
3
4
5
6
7
8
9
10
11
<CustomLevels>
<CustomLevel name="DIAG" intLevel="350" />
<CustomLevel name="NOTICE" intLevel="450" />
<CustomLevel name="VERBOSE" intLevel="550" />
</CustomLevels>

<Loggers>
<Root level="trace">
<AppenderRef ref="Console" level="diag" />
</Root>
</Loggers>

在代码中使用就更加方便:

1
logger.log(Level.forName("CUSTOMER_LEVEL", 350), "customer level");

配合 Slf4j 使用

使用 Slf4j 非常简单,只需要在项目中加入以下依赖:

1
2
3
4
5
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-slf4j-impl</artifactId>
<version>2.12.1</version>
</dependency>

然后就可以在代码中使用了:

1
2
3
4
5
6
7
8
9
10
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class Slf4jDemo {

public static void main(String[] args) {
Logger logger = LoggerFactory.getLogger(Slf4jDemo.class);

logger.info("Slf4j log info");
}
}

(完)

  • https://logging.apache.org/log4j/2.x/manual/index.html
@2020 rayjun