Log4j2中的同步⽇志与异步⽇志
1.背景
Log4j 2中记录⽇志的⽅式有同步⽇志和异步⽇志两种⽅式，其中异步⽇志⼜可分为使⽤AsyncAppender和使⽤AsyncLogger两种⽅式。
2.Log4j2中的同步⽇志
所谓同步⽇志，即当输出⽇志时，必须等待⽇志输出语句执⾏完毕后，才能执⾏后⾯的业务逻辑语句。
下⾯通过⼀个例⼦来了解Log4j2中的同步⽇志，并借此来探究整个⽇志输出过程。
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="debug" name="MyApp" packages="">
<!--全局Filter-->
<ThresholdFilter level="ALL"/>
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
</Console>
<RollingFile name="RollingFile" fileName="logs/app.log"
filePattern="logs/app-%d{yyyy-MM-dd HH}.log">
<!--Appender的Filter-->
<ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout>
<Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
</PatternLayout>
<Policies>
<SizeBasedTriggeringPolicy size="500MB"/>
</Policies>
</RollingFile>
</Appenders>
<Loggers>
<Logger name="ituan.Main" level="trace" additivity="false">
<!--Logger的Filter-->
<ThresholdFilter level="debug"/>
<appender-ref ref="RollingFile"/>
</Logger>
<Root level="debug">
<AppenderRef ref="Console"/>
</Root>
</Loggers>
</Configuration>
java代码如下：
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
public class Main {
public static void main(String args[]) {
Logger logger = Logger(Main.class);
Person person = new Person("Li", "lei");
logger.info("hello, {}", person);
}
private static class Person {
private String firstName;
private String lastName;
public Person(String firstName, String lastName) {
this.firstName = firstName;
this.lastName = lastName;
log4j2不打印日志}
public String toString() {
return "Person[" + firstName + "," + lastName + "]";
}
}
}
使⽤以上的配置，当我们运⾏程序后，以下log将被添加到logs/app.log中。
2017-09-13 19:41:00,889 Main [main] hello, Person[Li,lei]
logger.info运⾏时到底发⽣了什么？⽇志信息是如何输出到app.log中的？
Log4j2中⽇志输出的详细过程如下：
1.⾸先使⽤全局Filter对⽇志事件进⾏过滤。
Log4j2中的⽇志Level分为8个级别，优先级从⾼到低依次为OFF、FATAL、ERROR、WARN、INFO、DEBUG、TRACE、 ALL。
全局Filter的Level为ALL，表⽰允许输出所有级别的⽇志。logger.info()请求输出INFO级别的⽇志，通过。
2.使⽤Logger的Level对⽇志事件进⾏过滤。
Logger的Level为TRACE，表⽰允许输出TRACE级别及以上级别的⽇志。logger.info()请求输出INFO级别的⽇志，通过。
3.⽣成⽇志输出内容Message。
使⽤占位符的⽅式输出⽇志，输出语句为logger.info("increase {} from {} to {}", arg1, arg2, arg3)的形式，最终输出时{}占位符处的内容将⽤arg1,arg2,arg3的字符串填充。
log4j2⽤Object[]保存参数信息，在这⼀阶段会将Object[]转换为String[]，⽣成含有输出模式串"increase {} from {} to {}"和参数数组String[]的Message，为后续⽇志格式化输出做准备。
4.⽣成LogEvent。
LogEvent中含有loggerName（⽇志的输出者），level（⽇志级别），timeMillis（⽇志的输出时间），message（⽇志输出内容），threadName（线程名称）等信息。
在上述程序中，⽣成的LogEvent的属性值为ituan.Main，Level=INFO，timeMillis=1505659461759，message为步骤3中创建的Message，threadNama=main。
5.使⽤Logger配置的Filter对⽇志事件进⾏过滤。
Logger配置的Filter的Level为DEBUG，表⽰允许输出DEBUG及以上级别的⽇志。logger.info()请求输出INFO级别的⽇志，通过。
6.使⽤Logger对应的Appender配置的Filter对⽇志事件进⾏过滤。
Appender配置的Filter配置的INFO级别⽇志onMatch=ACCEPT，表⽰允许输出INFO级别的⽇志。logger.info()请求输出INFO级别的⽇志，通过。
7.判断是否需要触发rollover。
此步骤不是⽇志输出的必须步骤，如配置的Appender为⽆需进⾏rollover的Appender，则⽆此步骤。
因为使⽤RollingFileAppender，且配置了基于⽂件⼤⼩的rollover触发策略，在此阶段会判断是否需要触发rollover。判断⽅式为当前的⽂件⼤⼩是否达到了指定的size，如果达到了，触发rollover操作。关于Log4j2中的RollingFileAppender的rollover，可参见。
8.PatternLayout对LogEvent进⾏格式化，⽣成可输出的字符串。
上述l⽂件中配置的Pattern及各个参数的意义如下：
<Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
参数意义
%d⽇期格式，默认形式为2012-11-02 14:34:02,781
%p⽇志级别
%c{1.}%c表⽰Logger名字，{1.}表⽰精确度。若Logger名字为org.apachemons.Foo，则输出Foo。
%t处理LogEvent的线程的名字
%m⽇志内容
%n⾏分隔符。"\n"或"\r\n"。
在此步骤，PatternLayout将根据Pattern的模式，利⽤各种Converter对LogEvent的相关信息进⾏转换，最终拼接成可输出的⽇志字符串。
如DatePatternConverter对LogEvent的⽇志输出时间进⾏格式化转换；LevelPatternConverter对LogEvent的⽇志级别信息进⾏格式化转换；LoggerPatternConverter对LogEvent的Logger的名字进⾏格式化转换；MessagePatternConverter对LogEvent的⽇志输出内容进⾏格式化转换等。
经各种Converter转换后，LogEvent的信息被格式化为指定格式的字符串。
9.使⽤OutputStream，将⽇志输出到⽂件。
将⽇志字符串序列化为字节数组，使⽤字节流OutoutStream将⽇志输出到⽂件中。如果配置了immediateFlush为true，打开app.log就可观察到输出的⽇志了。
3.Log4j2中的异步⽇志
使⽤log4j2的同步⽇志进⾏⽇志输出，⽇志输出语句与程序的业务逻辑语句将在同⼀个线程运⾏，如上⾯的例⼦，打印的⽇志中显⽰的线程名称为main，与业务逻辑语句在同⼀个线程中（此句有误，LogEv
ent中的线程名称不是输出LogEvent的线程，是⽣成LogEvent的线程，输出LogEvent的线程和⽣成LogEvent可能不是⼀个线程！）。
⽽使⽤异步⽇志进⾏输出时，⽇志输出语句与业务逻辑语句并不是在同⼀个线程中运⾏，⽽是有专门的线程⽤于进⾏⽇志输出操作，处理业务逻辑的主线程不⽤等待即可执⾏后续业务逻辑。
Log4j2中的异步⽇志实现⽅式有AsyncAppender和AsyncLogger两种。
其中，AsyncAppender采⽤了ArrayBlockingQueue来保存需要异步输出的⽇志事件；AsyncLogger则使⽤了Disruptor框架来实现⾼吞吐。
3.1 AsyncAppender
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn">
<Appenders>
<RollingFile name="MyFile" fileName="logs/app.log">
<PatternLayout>
<Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
</PatternLayout>
<SizeBasedTriggeringPolicy size="500MB"/>
</RollingFile>
<Async name="Async">
<AppenderRef ref="MyFile"/>
</Async>
</Appenders>
<Loggers>
<Root level="error">
<AppenderRef ref="Async"/>
</Root>
</Loggers>
</Configuration>
上⾯就是⼀个使⽤AsyncAppender的典型配置，配置AsyncAppender后，⽇志事件写⼊⽂件的操作将在单独的线程中执⾏。
AsyncAppender的常⽤参数
参数名类型说明
name String Async Appender的名字。
AppenderRef String异步调⽤的Appender的名字，可以配置多个。
blocking boolean默认为true。如果为true，appender将⼀直等待直到queue中有空闲；如果为false，当队列满的时候，⽇志事件将被丢弃。(如果配置了error appender，要丢弃的⽇志事件将由error appende
r处理)
bufferSize integer队列中可存储的⽇志事件的最⼤数量，默认为128。(源码中为128，Log4j2官⽹为1024，官⽹信息有误)
关于AsyncAppender的其他参数，可参考Log4j2对的详细介绍。
每个Async Appender，内部维护了⼀个ArrayBlockingQueue，并将创建⼀个线程⽤于输出⽇志事件，如果配置了多个AppenderRef，将分别使⽤对应的Appender进⾏⽇志输出。
3.2 AsyncLogger
Log4j2中的AsyncLogger的内部使⽤了Disruptor框架。
Disruptor简介
Disruptor是英国外汇交易公司LMAX开发的⼀个⾼性能队列，基于Disruptor开发的系统单线程能⽀撑每秒600万订单。
⽬前，包括Apache Strom、Log4j2在内的很多知名项⽬都应⽤了Disruptor来获取⾼性能。
Disruptor框架内部核⼼数据结构为RingBuffer，其为⽆锁环形队列。
单线程每秒能够处理600万订单，Disruptor为什么这么快？
a.lock-free-使⽤了CAS来实现线程安全
ArrayBlockingQueue使⽤锁实现并发控制，当get或put时，当前访问线程将上锁，当多⽣产者、多消费者的⼤量并发情形下，由于锁竞争、线程切换等，会有性能损失。
Disruptor通过CAS实现多⽣产者、多消费者对RingBuffer的并发访问。CAS相当于乐观锁，其性能优于Lock的性能。
b.使⽤缓存⾏填充解决伪共享问题
计算机体系结构中，内存的访问速度远远低于CPU的运⾏速度，在内存和CPU之间，加⼊Cache，CPU⾸先访问Cache中的数据，CaChe未命中，才访问内存中的数据。
伪共享：Cache是以缓存⾏（cache line）为单位存储的，当多个线程修改互相独⽴的变量时，如果这些变量共享同⼀个缓存⾏，就会⽆意中影响彼此的性能。
关于伪共享的深度分析，可参考《》这篇⽂章。
AsyncLogger
Log4j2异步⽇志如何进⾏⽇志输出，我们同样从⼀个例⼦出发来探究Log4j2的异步⽇志。
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="debug" name="MyApp" packages="">
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
</Console>
<RollingFile name="RollingFile" fileName="logs/app.log"
filePattern="logs/app-%d{yyyy-MM-dd HH}.log">
<PatternLayout>
<Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
</PatternLayout>
<Policies>
<SizeBasedTriggeringPolicy size="500MB"/>
</Policies>
</RollingFile>
<RollingFile name="RollingFile2" fileName="logs/app2.log"
filePattern="logs/app2-%d{yyyy-MM-dd HH}.log">
<PatternLayout>
<Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
</PatternLayout>
<Policies>
<SizeBasedTriggeringPolicy size="500MB"/>
</Policies>
</RollingFile>
</Appenders>
<Loggers>
<AsyncLogger name="ituan.Main" level="trace" additivity="false">
<appender-ref ref="RollingFile"/>
</AsyncLogger>
<AsyncLogger name="RollingFile2" level="trace" additivity="false">
<appender-ref ref="RollingFile2"/>
</AsyncLogger>
<Root level="debug">
<AppenderRef ref="Console"/>
<AppenderRef ref="RollingFile"/>
</Root>
</Loggers>
</Configuration>
java代码如下：
public class Main {
public static void main(String args[]) {
Logger logger = Logger(Main.class);
Logger logger2 = Logger("RollingFile2");
Person person = new Person("Li", "lei");
logger.info("hello, {}", person);
logger2.info("good bye, {}", person);
}
上述l中配置了两个AsyncLogger，名字分别为ituan.Main和RollingFile2。
并且，在main⽅法中分别使⽤两个logger来输出两条⽇志。
在加载l的启动阶段，如果检测到配置了AsyncRoot或AsyncLogger，将启动⼀个disruptor实例。
上述程序中，main线程作为⽣产者，EventProcessor线程作为消费者。
⽣产者⽣产消息
当运⾏到类似于logger.info、logger.debug的输出语句时，将⽣成的LogEvent放⼊RingBuffer中。
消费者消费消息
如果RingBuffer中有LogEvent需要处理，EventProcessor线程从RingBuffer中取出LogEvent，调⽤Logger相关联的Appender输出LogEvent（具体输出过程与同步过程相同，同样需要过滤器过滤、Patter
nLayout格式化等步骤）。
如果RingBuffer中没有LogEvent需要处理，EventProcessor线程将处于等待阻塞状态（默认策略）。
需要注意的是，虽然在l中配置了多个AsyncLogger，但是并不是每个AsyncLogger对应着⼀个处理线程，⽽是仅仅有⼀个EventProcessor线程进⾏⽇志的异步处理。
4.总结
⽇志输出⽅式
sync同步打印⽇志，⽇志输出与业务逻辑在同⼀线程内，当⽇志输出完毕，才能进⾏后续业务逻辑操作
Async Appender异步打印⽇志，内部采⽤ArrayBlockingQueue，对每个AsyncAppender创建⼀个线程⽤于处理⽇志输出。
Async Logger异步打印⽇志，采⽤了⾼性能并发框架Disruptor，创建⼀个线程⽤于处理⽇志输出。

版权声明：本站内容均来自互联网，仅供演示用，请勿用于商业和其他非法用途。如果侵犯了您的权益请与我们联系QQ:729038198，我们将在24小时内删除。