Log4j 的架构设计

Log4jClasses.jpg

http://www.cnblogs.com/Fskjb/archive/2011/01/29/1947592.html
https://blog.csdn.net/qq_35246620/article/details/53790350
https://blog.csdn.net/liuxiao723846/article/details/52126936

依赖

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.13.3</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-core</artifactId>
<version>2.13.3</version>
</dependency>
</dependencies>

如果要接入其他日志库、Servlet、JPA,docker,可以使用《Optional Components》。 使用了可选的组件以后,第一可以自动地在某些 api 里打点,其次可以自动理解这些 api 里的环境(如 docker api 可以自动理解 docker 的容器名称)。

Logger、Appender

对于常见的 log4j.xml/slf4j.xml 而言:

Logger:日志记录器,负责收集处理日志记录。有 name,这个 name 可以被 java class 定义,也可以被引用。它本身没什么用,真正的配置被包在 LoggerConfig 里面。基本的实现在 AbstractLogger 里。

LoggerConfig 里面包含了一系列 Filter 的配置,会在 LogEvent 发送到 Appender 以前进行处理。

Appender:日志追加器,输出目的地(output destination),负责日志的输出(输出到什么地方)。有 name,这个 name 可以被引用。是一个很重要的功能接口。Logger ref appender。

Layout:日志布局。日志格式化,负责对输出的日志格式化(以什么形式展现)。复杂的布局性能会更差-复杂的任何处理器的性能都应该更差,无关紧要。

一个 logger 可以对应多个 appender,一个 appender 只能对应一个 layout。

rootlogger 总是 DEBUG 的 LEVEL。

默认其他 logger 都是从 root logger 里面派生出来的,主要继承了全局的 log level(<root level="warn">会直接导致全局的 log level 提升到 warn),而它的additivity 的配置可以禁掉日志在父 logger 里面的重复输出(Once an event reaches a logger with its additivity set to false the event will not be passed to any of its parent loggers, regardless of their additivity setting.日志会在当前的 logger 引用的 appender 里输出,而不会输出到 parent 上)。一套 logger 的例子是:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
<loggers>
<!--单独配置 logger,如果一个类的包路径很特别,需要单独定制 logger 的配置,可以这样做,配置单独的 level。单一的 logger 本身只是对 root level 的一个覆盖。-->
<logger name="com.some_company" level="info"/>
<logger name="org.springframework" level="info"/>

<!-- 只规定了全局的 log level,所有没有被单独配置的 logger 都会受这个 logger 的影响,包括对 appender 的引用 -->
<root level="info">
<appender-ref ref="requestLog"/>
<appender-ref ref="warnLog"/>
<appender-ref ref="errorLog"/>
<appender-ref ref="customAppender1"/>
<appender-ref ref="customAppender2"/>
</root>
</loggers>

假设定义一个 APPENDER 是这样的。它与某个 log file 就联系起来了。

1
2
3
4
5
6
7
8
9
10
<appender name="A-APPENDER"
class="class">
<param name="file" value="${loggingRoot}/${sys_host_name}/common-default.log"/>
<param name="append" value="true"/>
<param name="encoding" value="GBK"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern"
value="%d [%X{loginUserEmail}/%X{loginUserID}/%X{remoteAddr}/%X{clientId} - %X{requestURIWithQueryString}] %-5p %c{2} - %m%n"/>
</layout>
</appender>

其中 ConversionPattern 可用的内容有(这里的 % 不是类型前缀,而是上下文变量前缀。):

  • %d 意味着当前时间
  • %m 意味着日志内容
  • %n 意味着换行符

然后可以定义一个 logger:

1
2
3
4
5
6
<!-- 用appender 的名字或者日志文件名来命名 logger -->
<logger name="LOGGING_FILE_NAME" additivity="false">
<level value="INFO"/>
<appender-ref ref="A-APPENDER"/>
<appender-ref ref="B-APPENDER" />
</logger>

然后可以用名字来引用 logger:

1
private static final Logger LOGGING_FILE_NAME_LOGGER = LoggerFactory.getLogger(LOGGING_FILE_NAME);

我们也可以定义一个到达某个包名的 logger:

1
2
3
4
5
6
7
<!-- 用包名来命名 logger,本包内的 class 自动获得这个 logger -->
<logger name="com.a.b" additivity="false">
<!-- 可以覆盖继承下来的 level -->
<level value="${abc_loggingLevel}"/>
<appender-ref ref="A-APPENDER"/>
<appender-ref ref="B-APPENDER" />
</logger>

然后可以用类名来引用 logger:

1
private static final Logger logger = LoggerFactory.getLogger(A.class);

一个典型的 log4j2.xml:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn" name="MyApp" packages="">
<Appenders>
<!-- 可以直接用 type 来决定特殊的 console -->
<Console name="STDOUT" target="SYSTEM_OUT">
<PatternLayout pattern="%m%n"/>
</Console>
<File name="MyFile" fileName="logs/app.log">
<PatternLayout>
<Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
</PatternLayout>
</File>
</Appenders>
<Loggers>
<Root level="error">
<AppenderRef ref="STDOUT"/>
</Root>
</Loggers>
</Configuration>

一个典型的logback.xml:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
<appender name="console" class="ch.qos.logback.core.ConsoleAppender">
<!-- 注意这个 target -->
<target>System.out</target>
<encoder>
<pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} %msg%n</pattern>
</encoder>
</appender>

<root level="error">
<appender-ref ref="console"/>
</root>


<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="true">
<!-- 应用名称 -->
<property name="APP_NAME" value="logtest" />
<!--日志文件的保存路径,首先查找系统属性-Dlog.dir,如果存在就使用其;否则,在当前目录下创建名为logs目录做日志存放的目录 -->
<property name="LOG_HOME" value="${log.dir:-logs}/${APP_NAME}" />
<!-- 日志输出格式 -->
<property name="ENCODER_PATTERN"
value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{80} - %msg%n" />
<contextName>${APP_NAME}</contextName>

<!-- 控制台日志:输出全部日志到控制台 -->
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<Pattern>${ENCODER_PATTERN}</Pattern>
</encoder>
</appender>

<!-- 文件日志:输出全部日志到文件 -->
<appender name="FILE"
class="ch.qos.logback.core.rolling.RollingFileAppender">
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>${LOG_HOME}/output.%d{yyyy-MM-dd}.log</fileNamePattern>
<maxHistory>7</maxHistory>
</rollingPolicy>
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<pattern>${ENCODER_PATTERN}</pattern>
</encoder>
</appender>

<!-- 错误日志:用于将错误日志输出到独立文件 -->
<appender name="ERROR_FILE"
class="ch.qos.logback.core.rolling.RollingFileAppender">
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>${LOG_HOME}/error.%d{yyyy-MM-dd}.log</fileNamePattern>
<maxHistory>7</maxHistory>
</rollingPolicy>
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<pattern>${ENCODER_PATTERN}</pattern>
</encoder>
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>WARN</level>
</filter>
</appender>

<!-- 独立输出的同步日志 -->
<appender name="SYNC_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>${LOG_HOME}/sync.%d{yyyy-MM-dd}.log</fileNamePattern>
<maxHistory>7</maxHistory>
</rollingPolicy>
<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
<pattern>${ENCODER_PATTERN}</pattern>
</encoder>
</appender>

<logger name="log.sync" level="DEBUG" addtivity="true">
<appender-ref ref="SYNC_FILE" />
</logger>

<root>
<level value="DEBUG" />
<appender-ref ref="STDOUT" />
<appender-ref ref="FILE" />
<appender-ref ref="ERROR_FILE" />
</root>

配置文件的内容格式

log4j.appender.appenderName=

appenderName org.apache.log4j.ConsoleAppender(控制台)
org.apache.log4j.FileAppender(文件)
org.apache.log4j.DailyRollingFileAppender(每天产生一个日志文件)
org.apache.log4j.RollingFileAppender(文件大小到达指定尺寸的时候产生一个新的文件)
org.apache.log4j.WriterAppender(将日志信息以流格式发送到任意指定的地方)

log4j.appender.appenderName.layout = ??

org.apache.log4j.HTMLLayout(以HTML表格形式布局)
org.apache.log4j.PatternLayout(可以灵活地指定布局模式)
org.apache.log4j.SimpleLayout(包含日志信息的级别和信息字符串)
org.apache.log4j.TTCCLayout(包含日志产生的时间、线程、类别等等信息)

ConsoleAppender选项

Threshold=DEBUG:指定日志消息的输出最低层次。
ImmediateFlush=true:默认值是true,意谓着所有的消息都会被立即输出。
Target=System.err:默认情况下是System.out,指定输出控制台

FileAppender 选项

Threshold=DEBUG:指定日志消息的输出最低层次。
ImmediateFlush=true:默认值是true,意谓着所有的消息都会被立即输出。
File=mylog.txt:指定消息输出到mylog.txt文件。
Append=false:默认值是true,即将消息增加到指定文件中,false指将消息覆盖指定的文件内容。

RollingFileAppender 选项

Threshold=DEBUG:指定日志消息的输出最低层次。
ImmediateFlush=true:默认值是true,意谓着所有的消息都会被立即输出。
File=mylog.txt:指定消息输出到mylog.txt文件。
Append=false:默认值是true,即将消息增加到指定文件中,false指将消息覆盖指定的文件内容。
MaxFileSize=100KB: 后缀可以是KB, MB 或者是 GB.
在日志文件到达该大小时,将会自动滚动,即将原来的内容移到mylog.log.1文件。
MaxBackupIndex=2:指定可以产生的滚动文件的最大数。

日志信息格式中几个符号所代表的含义

-X号: X信息输出时左对齐;
%p: 输出日志信息优先级,即DEBUG,INFO,WARN,ERROR,FATAL,
%c: 输出日志信息所属的类目,通常就是所在类的全名 %t: 输出产生该日志事件的线程名
%x: 输出和当前线程相关联的NDC(嵌套诊断环境),尤其用到像java
servlets这样的多客户多线程的应用中。 %%: 输出一个”%”字符
%F: 输出日志消息产生时所在的文件名称
%L: 输出代码中的行号
%m 输出代码中指定的消息%p 输出优先级,即DEBUG,INFO,WARN,ERROR,FATAL
%r 输出自应用启动到输出该log信息耗费的毫秒数
%t 输出产生该日志事件的线程名
%n 输出一个回车换行符,Windows平台为“\r\n”,Unix平台为“\n”
%d 输出日志时间点的日期或时间,默认格式为ISO8601,也可以在其后指定格式,比如:%d{yyy MMM dd HH:mm:ss , SSS},输出类似:2002年10月18日 22 : 10 : 28 , 921
%l 输出日志事件的发生位置,包括类目名、发生的线程,以及在代码中的行数。举例:test.main(test.java: 10 )

Level

SLF4J

level 值和严重程度正相反。

level 值越高,能越把低 level 的日志打出来 - 低严重程度的日志级别能把高严重级别(more specific,log4j 的文档这样叫很怪)的日志打出来。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
/**
* No events will be logged.
*/
OFF(0),

/**
* A severe error that will prevent the application from continuing.
*/
FATAL(100),

/**
* An error in the application, possibly recoverable.
*/
ERROR(200),

/**
* An event that might possible lead to an error.
*/
WARN(300),

/**
* An event for informational purposes.
*/
INFO(400),

/**
* A general debugging event.
*/
DEBUG(500),

/**
* A fine-grained debug message, typically capturing the flow through the application.
*/
TRACE(600),

/**
* All events should be logged.
*/
ALL(Integer.MAX_VALUE);

Log4j

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
/**
* No events will be logged.
*/
OFF(0),

/**
* A severe error that will prevent the application from continuing.
*/
FATAL(100),

/**
* An error in the application, possibly recoverable.
*/
ERROR(200),

/**
* An event that might possible lead to an error.
*/
WARN(300),

/**
* An event for informational purposes.
*/
INFO(400),

/**
* A general debugging event.
*/
DEBUG(500),

/**
* A fine-grained debug message, typically capturing the flow through the application.
*/
TRACE(600),

/**
* All events should be logged.
*/
ALL(Integer.MAX_VALUE);

基础的 log4j 2 配置全解析

本文来自于《Configuration》

因为安全原因,log4j 的配置文件不按照 dtd 来定义各种 element(和 spring、mybatis 通过名字空间定义 element 不同)。

Attribute Name Description
advertiser (Optional) The Advertiser plugin name which will be used to advertise individual FileAppender or SocketAppender configurations. The only Advertiser plugin provided is ‘multicastdns”.
dest
monitorInterval The minimum amount of time, in seconds, that must elapse before the file configuration is checked for changes.
name The name of the configuration.
packages A comma separated list of package names to search for plugins. Plugins are only loaded once per classloader so changing this value may not have any effect upon reconfiguration.
schema Identifies the location for the classloader to located the XML Schema to use to validate the configuration. Only valid when strict is set to true. If not set no schema validation will take place.
shutdownHook Specifies whether or not Log4j should automatically shutdown when the JVM shuts down. The shutdown hook is enabled by default but may be disabled by setting this attribute to “disable”
shutdownTimeout Specifies how many milliseconds appenders and background tasks will get to shutdown when the JVM shuts down. Default is zero which mean that each appender uses its default timeout, and don’t wait for background tasks. Not all appenders will honor this, it is a hint and not an absolute guarantee that the shutdown procedure will not take longer. Setting this too low increase the risk of losing outstanding log events not yet written to the final destination. See LoggerContext.stop(long, java.util.concurrent.TimeUnit). (Not used if shutdownHook is set to “disable”.)
status The level of internal Log4j events that should be logged to the console. Valid values for this attribute are “trace”, “debug”, “info”, “warn”, “error” and “fatal”. Log4j will log details about initialization, rollover and other internal actions to the status logger. Setting status=”trace” is one of the first tools available to you if you need to troubleshoot log4j.

(Alternatively, setting system property log4j2.debug will also print internal Log4j2 logging to the console, including internal logging that took place before the configuration file was found.)
strict Enables the use of the strict XML format. Not supported in JSON configurations.
verbose Enables diagnostic information while loading plugins.

配置可以要么指定在 attribute、要么指定在 element。

1
2
3
4
5
<PatternLayout pattern="%m%n"/>

<PatternLayout>
<Pattern>%m%n</Pattern>
</PatternLayout>

配置 logger 日志器

每一个<logger>元素对应一个 LoggerConfig,通常指定 name、level 和 additivity:

  • level 默认值是 error -大部分日志都不会打印出来。
  • additivity 默认值是 true

root 本身也是一个 LoggerConfig。

每一个 configuration 一定要有一个 root - 没有 root 就会使用默认的 error level 使用的 console apender root - 这不是什么好事。

root 不能有名字,也没有 additivity,因为它没有 parent。

有名字和 id 的设计,易于设计 entity。

配置 Appender(附加器)

appender 本身可以引用插件作为实现,它可以引用 layout(这也是用插件实现的) - 一个 element 的背后是一个插件。

配置多级过滤器

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="debug" name="XMLConfigTest" packages="org.apache.logging.log4j.test">
<Properties>
<Property name="filename">target/test.log</Property>
</Properties>
<ThresholdFilter level="trace"/>

<Appenders>
<Console name="STDOUT">
<PatternLayout pattern="%m MDC%X%n"/>
</Console>
<Console name="FLOW">
<!-- this pattern outputs class name and line number -->
<PatternLayout pattern="%C{1}.%M %m %ex%n"/>
<filters>
<MarkerFilter marker="FLOW" onMatch="ACCEPT" onMismatch="NEUTRAL"/>
<MarkerFilter marker="EXCEPTION" onMatch="ACCEPT" onMismatch="DENY"/>
</filters>
</Console>
<File name="File" fileName="${filename}">
<PatternLayout>
<pattern>%d %p %C{1.} [%t] %m%n</pattern>
</PatternLayout>
</File>
</Appenders>

<Loggers>
<Logger name="org.apache.logging.log4j.test1" level="debug" additivity="false">
<ThreadContextMapFilter>
<KeyValuePair key="test" value="123"/>
</ThreadContextMapFilter>
<AppenderRef ref="STDOUT"/>
</Logger>

<Logger name="org.apache.logging.log4j.test2" level="debug" additivity="false">
<Property name="user">${sys:user.name}</Property>
<AppenderRef ref="File">
<ThreadContextMapFilter>
<KeyValuePair key="test" value="123"/>
</ThreadContextMapFilter>
</AppenderRef>
<AppenderRef ref="STDOUT" level="error"/>
</Logger>

<Root level="trace">
<AppenderRef ref="STDOUT"/>
</Root>
</Loggers>

</Configuration>

字符串替换

模仿 apache 的 StrSubstitutor 和 StrLookup 是个好东西。
我们经常可以用到的根对象包括 base64、bundle、ctx、date、env、jndi、jvmrunargs(从 RuntimeMXBean.getInputArguments() 可以取出来)、log4j、main、map、sd、sys。

这些表达式都支持缺省值模式,如${lookupName:key:-defaultValue}.

脚本编程

log4j2 支持 javascript 脚本编程 - 类似 logstash 对 ruby 的支持:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="debug" name="RoutingTest">
<Scripts>
<Script name="selector" language="javascript"><![CDATA[
var result;
if (logEvent.getLoggerName().equals("JavascriptNoLocation")) {
result = "NoLocation";
} else if (logEvent.getMarker() != null && logEvent.getMarker().isInstanceOf("FLOW")) {
result = "Flow";
}
result;
]]></Script>
<ScriptFile name="groovy.filter" path="scripts/filter.groovy"/>
</Scripts>

<Appenders>
<Console name="STDOUT">
<ScriptPatternSelector defaultPattern="%d %p %m%n">
<ScriptRef ref="selector"/>
<PatternMatch key="NoLocation" pattern="[%-5level] %c{1.} %msg%n"/>
<PatternMatch key="Flow" pattern="[%-5level] %c{1.} ====== %C{1.}.%M:%L %msg ======%n"/>
</ScriptPatternSelector>
<PatternLayout pattern="%m%n"/>
</Console>
</Appenders>

<Loggers>
<Logger name="EventLogger" level="info" additivity="false">
<ScriptFilter onMatch="ACCEPT" onMisMatch="DENY">
<Script name="GroovyFilter" language="groovy"><![CDATA[
if (logEvent.getMarker() != null && logEvent.getMarker().isInstanceOf("FLOW")) {
return true;
} else if (logEvent.getContextMap().containsKey("UserId")) {
return true;
}
return false;
]]>
</Script>
</ScriptFilter>
<AppenderRef ref="STDOUT"/>
</Logger>

<Root level="error">
<ScriptFilter onMatch="ACCEPT" onMisMatch="DENY">
<ScriptRef ref="groovy.filter"/>
</ScriptFilter>
<AppenderRef ref="STDOUT"/>
</Root>
</Loggers>

</Configuration>

配置 log4j2 的方法

  1. 通过各种配置文件:properties、xml、json、yaml。
  2. 程序化地通过 ConfigurationFactory(上面每一种格式都配有一种 factory)。
  3. 通过 Configuration 接口的方法。
  4. 通过 Logger Class - 动态改变配置和行为。

用 XInclude 来引入其他配置文件

1
2
3
4
5
6
7
8
9
10
<?xml version="1.0" encoding="UTF-8"?>
<configuration xmlns:xi="http://www.w3.org/2001/XInclude"
status="warn" name="XIncludeDemo">
<properties>
<property name="filename">xinclude-demo.log</property>
</properties>
<ThresholdFilter level="debug"/>
<xi:include href="log4j-xinclude-appenders.xml" />
<xi:include href="log4j-xinclude-loggers.xml" />
</configuration>

使用 CompositeConfiguration 组合配置

用一串逗号分隔的配置文件列表填充 log4j.configurationFile。

程序化地直接使用 log4j2

这段还是很复杂,应该直接看《Programmatic Configuration》

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
@Plugin(name = "CustomConfigurationFactory", category = ConfigurationFactory.CATEGORY)
@Order(50)
public class CustomConfigurationFactory extends ConfigurationFactory {

static Configuration createConfiguration(final String name, ConfigurationBuilder<BuiltConfiguration> builder) {
builder.setConfigurationName(name);
builder.setStatusLevel(Level.ERROR);
builder.add(builder.newFilter("ThresholdFilter", Filter.Result.ACCEPT, Filter.Result.NEUTRAL).
addAttribute("level", Level.DEBUG));
AppenderComponentBuilder appenderBuilder = builder.newAppender("Stdout", "CONSOLE").
addAttribute("target", ConsoleAppender.Target.SYSTEM_OUT);
appenderBuilder.add(builder.newLayout("PatternLayout").
addAttribute("pattern", "%d [%t] %-5level: %msg%n%throwable"));
appenderBuilder.add(builder.newFilter("MarkerFilter", Filter.Result.DENY,
Filter.Result.NEUTRAL).addAttribute("marker", "FLOW"));
builder.add(appenderBuilder);
builder.add(builder.newLogger("org.apache.logging.log4j", Level.DEBUG).
add(builder.newAppenderRef("Stdout")).
addAttribute("additivity", false));
builder.add(builder.newRootLogger(Level.ERROR).add(builder.newAppenderRef("Stdout")));
return builder.build();
}

@Override
public Configuration getConfiguration(final LoggerContext loggerContext, final ConfigurationSource source) {
return getConfiguration(loggerContext, source.toString(), null);
}

@Override
public Configuration getConfiguration(final LoggerContext loggerContext, final String name, final URI configLocation) {
ConfigurationBuilder<BuiltConfiguration> builder = newConfigurationBuilder();
return createConfiguration(name, builder);
}

@Override
protected String[] getSupportedTypes() {
return new String[] {"*"};
}
}

如果没有定位到任何配置文件,log4j2 的行为是

  • A ConsoleAppender attached to the root logger.
  • A PatternLayout set to the pattern “%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n” attached to the ConsoleAppender

多个 logger 的例子

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
<?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>
<Logger name="com.foo.Bar" level="trace" additivity="false">
<AppenderRef ref="Console"/>
</Logger>
<Root level="error">
<AppenderRef ref="Console"/>
</Root>
</Loggers>
</Configuration>

Filter 详解

ThresholdFilter

ThresholdFilter是临界值过滤器,过滤掉低于指定临界值的日志(换言之 logger 和 appender 都有过滤功能,只不过是在端点上过滤罢了)。当日志级别等于或高于临界值时,过滤器返回NEUTRAL;当日志级别低于临界值时,日志会被拒绝。

1
2
3
4
5
6
7
8
9
10
11
12
//过滤掉所有低于INFO级别的日志。
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<!-- 过滤掉 TRACE 和 DEBUG 级别的日志-->
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>INFO</level>
</filter>
<encoder>
<pattern>
%-4relative [%thread] %-5level %logger{30} - %msg%n
</pattern>
</encoder>
</appender>

每隔 30s 查找一下日志更新级别

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

关于日志性能的观点

low-latency 是重要的

异步化是应对 event 爆发的利器(使用异步化的数据结构的 Disruptor,十几万的 qps都顶得住,异步化可以说是当前提升性能吞吐的最强方法)。日志异步化要引入独立后台线程 + 一个 queue。这种 queue 往往会带来 lock contention。使用 queue 的话,记录日志的操作被简化为 enqueue 操作,业务线程可以立刻调头回去执行业务逻辑。

AsyncLogger 使用一个 lock-free data structure(实际上就是 LMAX Disruptor)。

而 logback、log4j、log4j2 的 AsyncAppender 使用的是 ArrayBlockingQueue,会带来 lock contention(在 enqueue 操作上产生竞争)。

所有的异步操作都需要关注 queue size,queue size 满了以后服务的性能会回退到同步操作。

使用了优秀的数据结构,线程越多(workload 越大),日志框架的吞吐量越高。但队列总有满的时候,队列满以前的峰值叫作 peak throughput;队列满了以后的吞吐量叫作 maximum sustained throughput。不同的测试标准需要不同的工作负载(workload)。

logger -LogEvent-> filter -> appender

不要使用Location相关属性,例如 C or $class, %F or %file, %l or %location, %L or %line, %M or %method,大概降低 30到100倍。includeLocation要设置为false(默认为false,可以直接不设置)。

推荐使用RollingRandomAccessFile,大概可以视为RollingFileAppender的进化版,没有bufferedIO这个属性,对于RollingRandomAccessFile,缓存是固定开启的。fileName是实时写入的(未归档)文件名,filePattern则是归档文件的命名模式,因为开启了异步日志所以这里immediateFlush设置为false(不过好像不管它也无所谓),bufferSize缓冲区大小暂时默认(默认为8K),最后,TriggeringPolicy和RolloverStrategy是必须有的,没有显示定义就会采用默认的。asyncLogger 使用 asyncLoggerRingBufferSize。

异步日志的使用方法

Log4j2提供了两种实现日志的方式,一个是通过AsyncAppender,一个是通过AsyncLogger,分别对应前面我们说的Appender组件和Logger组件。注意这是两种不同的实现方式,在设计和源码上都是不同的体现。

在使用异步日志的时候需要注意一些事项,如下:

  1. 不要同时使用AsyncAppender和AsyncLogger,也就是在配置中不要在配置Appender的时候,使用Async标识的同时,又配置AsyncLogger,这不会报错,但是对于性能提升没有任何好处。
  2. 不要在开启了全局同步的情况下,仍然使用AsyncAppender和AsyncLogger。这和上一条是同一个意思,也就是说,如果使用异步日志,AsyncAppender、AsyncLogger和全局日志,不要同时出现。
  3. 如果不是十分必须,不管是同步异步,都设置immediateFlush为false,这会对性能提升有很大帮助。若是ImmediateFlush=true,一旦有新日志写入,立马将日志写入到磁盘的文件中。当日志很多,这种频繁操作文件显然性能很低下。
  4. 如果不是确实需要,不要打印location信息,比如HTML的location,或者pattern模式里的%C or $class, %F or %file, %l or %location, %L or %line, %M or %method, 等,因为Log4j需要在打印日志的时候做一次栈的快照才能获取这些信息,这对于性能来说是个极大的损耗。

AsyncAppender

AsyncAppender是通过引用别的Appender来实现的,当有日志事件到达时,会开启另外一个线程来处理它们。需要注意的是,如果在Appender的时候出现异常,对应用来说是无法感知的(异步化的缺点)。 AsyncAppender应该在它引用的Appender之后配置,默认使用 java.util.concurrent.ArrayBlockingQueue实现而不需要其它外部的类库。 当使用此Appender的时候,在多线程的环境下需要注意,阻塞队列容易受到锁争用的影响,这可能会对性能产生影响。这时候,我们应该考虑使用无锁的异步记录器(AsyncLogger)。

1
2
3
log4j.appender.A3.BufferedIO=true   
#Buffer单位为字节,默认是8K,IO BLOCK大小默认也是8K
log4j.appender.A3.BufferSize=8192
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
<appender name="DRFOUT" class="org.apache.log4j.DailyRollingFileAppender">    
<param name="File" value="logs/brws.log" />
<param name="Append" value="true" />
<param name="DatePattern" value="yyyy_MM_dd'.'" />
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%d [%t] %-5p %l %x - %m%n" />
</layout>
</appender>

<appender name="ASYNCOUT" class="org.apache.log4j.AsyncAppender">
<param name="BufferSize" value="512" />
<!-- 异步引用其他同步 appender -->
<appender-ref ref="DRFOUT" />
</appender>

<!-- 官方文档的另一种 AsyncAppender 版本 -->
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn" name="MyApp" packages="">
<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>
<Loggers>
<Root level="error">
<AppenderRef ref="Async"/>
</Root>
</Loggers>
</Configuration>

AsyncAppender 采用的是生产者消费者的模型进行异步地将Logging Event送到对应的Appender中。

a、 生产者:外部应用了Log4j的系统的实时线程,实时将Logging Event传送进AsyncAppender里

b、 中转:Buffer 和 DiscardSummary

c、 消费者:Dispatcher 线程和 appenders

工作原理:

1) Logging Event进入AsyncAppender,AsyncAppender会调用append方法,在append方法中会去把logging Event填入Buffer中,当消费能力不如生产能力时,AsyncAppender会把超出Buffer容量的Logging Event放到DiscardSummary中,作为消费速度一旦跟不上生成速度,中转buffer的溢出处理的一种方案。

2) AsyncAppender有个线程类Dispatcher,它是一个简单的线程类,实现了Runnable接口。它是AsyncAppender的后台线程。

Dispatcher所要做的工作是:

① 锁定Buffer,让其他要对Buffer进行操作的线程阻塞。

② 看Buffer的容量是否满了,如果满了就将Buffer中的Logging Event全部取出,并清空Buffer和DiscardSummary;如果没满则等待Buffer填满Logging Event,然后notify Disaptcher线程。

③ 将取出的所有Logging Event交给对应appender进行后面的日志信息推送。

以上是AsyncAppender类的两个关键点:append方法和Dispatcher类,通过这两个关键点实现了异步推送日志信息的功能,这样如果大量的Logging Event进入AsyncAppender,就可以游刃有余地处理这些日志信息了。

很简单的生产者-消费者,锁 buffer 的模型,但 log-event 和 disruptor 的模型很精妙(ringbuffer 和普通的拥塞队列都值得研究)。

AsyncLogger

AsyncLogger才是log4j2 的重头戏,也是官方推荐的异步方式。它可以使得调用Logger.log返回的更快。你可以有两种选择:全局异步和混合异步。

全局异步就是,所有的日志都异步的记录,在配置文件上不用做任何改动,只需要在jvm启动的时候增加一个参数;

混合异步就是,你可以在应用中同时使用同步日志和异步日志,这使得日志的配置方式更加灵活。因为Log4j文档中也说了,虽然Log4j2提供以一套异常处理机制,可以覆盖大部分的状态,但是还是会有一小部分的特殊情况是无法完全处理的,比如我们如果是记录审计日志,那么官方就推荐使用同步日志的方式,而对于其他的一些仅仅是记录一个程序日志的地方,使用异步日志将大幅提升性能,减少对应用本身的影响。混合异步的方式需要通过修改配置文件来实现,使用AsyncLogger标记配置。

全局异步

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
<?xml version="1.0" encoding="UTF-8"?>

<!-- Don't forget to set system property
-Dlog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector
to make all loggers asynchronous. -->

<Configuration status="WARN">
<Appenders>
<!-- Async Loggers will auto-flush in batches, so switch off immediateFlush. -->
<RandomAccessFile name="RandomAccessFile" fileName="async.log" immediateFlush="false" append="false">
<PatternLayout>
<Pattern>%d %p %c{1.} [%t] %m %ex%n</Pattern>
</PatternLayout>
</RandomAccessFile>
</Appenders>
<Loggers>
<Root level="info" includeLocation="false">
<AppenderRef ref="RandomAccessFile"/>
</Root>
</Loggers>
</Configuration>

在系统初始化的时候,增加全局参数配置:

1
System.setProperty("log4j2.contextSelector, "org.apache.logging.log4j.core.async.AsyncLoggerContextSelector");

你可以在你第一次获取Logger之前设置,也可以加载JVM启动参数里,类似

1
java -Dog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector

混合异步

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
<?xml version="1.0" encoding="UTF-8"?>

<!-- No need to set system property "log4j2.contextSelector" to any value
when using <asyncLogger> or <asyncRoot>. -->

<Configuration status="WARN">
<Appenders>
<!-- Async Loggers will auto-flush in batches, so switch off immediateFlush. -->
<RandomAccessFile name="RandomAccessFile" fileName="asyncWithLocation.log"
immediateFlush="false" append="false">
<PatternLayout>
<Pattern>%d %p %class{1.} [%t] %location %m %ex%n</Pattern>
</PatternLayout>
</RandomAccessFile>
</Appenders>
<Loggers>
<!-- pattern layout actually uses location, so we need to include it -->
<!-- 注意,这里使用了异步 logger -->
<AsyncLogger name="com.foo.Bar" level="trace" includeLocation="true">
<AppenderRef ref="RandomAccessFile"/>
</AsyncLogger>
<Root level="info" includeLocation="true">
<AppenderRef ref="RandomAccessFile"/>
</Root>
</Loggers>
</Configuration>

无垃圾的日志

防止垃圾回收是通过避免创建临时对象来实现的(即尽量复用对象)。

但有要注意避免:

  • 部分被复用的对象保存在 ThreadLocal 区域中。这样的设计对独立的应用程序来说没有问题,但是对于 web 应用可能会引起内存泄漏。
  • log4j 防止触发垃圾回收的另一个方式是在将文本转换为字符数组的时候复用缓冲区。所有类型的应用程序都可因此受益,且该功能默认是开启的。然而使用同步日志记录器的多线程应用程序可能会有性能影响,因为不同的线程需要竞争共享的缓冲区。如果遇到这种情况,应该优先使用异步日志记录器,或者禁用共享缓冲区。
  • 只有部分追加器已经修改以避免创建临时对象:Console(控制台)、File(文件)、RandomAccessFile(随机访问文件)、上述追加器的回卷追加器、MemoryMappedFile(内存映射文件)。任何其他追加器都会产生垃圾,并且需要被回收。然而需要注意的是,这些追加器本身可以免垃圾回收,仍然会有其他 I/O 相关的因素会影响它们的性能。
  • GelfLayout(Graylog Extended Log Format)布局只有在压缩选项禁用时才支持免垃圾回收,而 PatternLayout(我们最常用的布局方式) 只支持限定的转换模式,任何其他转换模式都会创建临时对象。
  • API 本身也已经为避免创建临时对象而修改。除了之前支持简单可变长度参数(这样会创建一个临时数据)的方法之外,log4j 新增了所有方法的重载版本,最多支持 10 个参数。调用方法超过 10 个参数仍然会使用可变长度参数,这将会创建临时数组。这个限制对于通过 SLF4J 使用 log4j 的场景影响较大,因为这个门面库只提供了最多两个参数的非变长参数。用户如果希望使用超过两个参数,并运行在免垃圾回收模式,就需要抛弃 SLF4J。
  • 虽然已经做了向下兼容,以避免开发者更新代码,有一类临时对象的创建和 log4j 框架本身无关:对基本数据类型的自动装箱。为了确保 JVM 不将基本数据类型装换成对应的对象,开发者在给 log4j 传递基本数据类型时,可以使用静态方法Unboxer.box()。该方法可以允许 log4j 直接处理基本数据类型而无需创建不必要的对象。

参考文献:

  1. https://www.jianshu.com/p/9f0c67facbe2