参考:(方便记录,直接将内容贴过来了。如有侵权,请留言删除,此致敬意!)
首先,在日志系统的森林里面理理头绪,修炼内功。参考文章如下:
1.https://www.cnblogs.com/gavanwanggw/p/7305218.html
2.https://www.cnblogs.com/gavanwanggw/p/7305218.html
Java日志系统确实比较丰富,常用的有log4j、JUL、logback等等,同时伴随着日志系统的发展,出现了日志框架commons-logging和slf4j。
简短地描述下日志发展,最先出现的是apache开源社区的log4j,这个日志确实是应用最广泛的日志工具,成为了java日志的事实上的标准。然而,当时Sun公司在jdk1.4中增加了JUL日志实现,企图对抗log4j,但是却造成了混乱,这个也是被人诟病的一点。当然也有其他日志工具的出现,这样必然造成开发者的混乱,因为这些日志系统互相没有关联,替换和统一也就变成了比较棘手的一件事。想象下你的应用使用log4j,然后使用了一个其他团队的库,他们使用了JUL,你的应用就得使用两个日志系统了,然后又有第二个库出现了,使用了simplelog。这个时候估计让你崩溃了,这是要闹哪样?这个状况交给你来想想办法,你该如何解决呢?进行抽象,抽象出一个接口层,对每个日志实现都适配或者转接,这样这些提供给别人的库都直接使用抽象层即可。不错,开源社区提供了commons-logging抽象,被称为JCL,也就是日志框架了,确实出色地完成了兼容主流的日志实现(log4j、JUL、simplelog),基本一统江湖,就连顶顶大名的spring也是依赖了JCL。看起来事物确实是美好,但是美好的日子不长,接下来另一个优秀的日志框架slf4j的加入导致了更加混乱的场面。比较巧的是slf4j的作者(Ceki Gülcü)就是log4j的作者,他觉得JCL不够优秀,所以他要自己搞一套更优雅的出来,于是slf4j日志体系诞生了,并为slf4j实现了一个亲子——logback,确实更加优雅,但是由于之前很多代码库已经使用JCL,虽然出现slf4j和JCL之间的桥接转换,但是集成的时候问题依然多多,对很多新手来说确实会很懊恼,因为比单独的log4j时代“复杂”多了,可以关注下这个,抱怨声确实很多。到此本来应该完了,但是Ceki Gülcü觉得还是得回头拯救下自己的“大阿哥”——log4j,于是log4j2诞生了,同样log4j2也参与到了slf4j日志体系中,想必将来会更加混乱。接下来详细解读日志系统的配合使用问题。
JCL的实现原理,使用JCL一般(如果是log4j可以不需要)需要一个配置commons-logging.properties在classpath上,这个文件有一行代码:
org.apache.commons.logging.LogFactory= org.apache.commons.logging.impl.LogFactoryImpl
这个是告诉JCL使用哪个日志实现,JCL会在classpath下去加载对应的日志工厂实现类,具体的日志工厂实现类可以是log4j实现,可以是jul实现等等。用户只需要依赖JCL的api即可,对日志系统的替换只需要修改下commons-logging.properties文件切换到对应的日志工厂实现即可。但是我们也可以看到因为JCL是运行时去加载classpath下的实现类,会有classloader问题。而且因为log4j尚不支持参数占位符打日志的方式,所以JCL也会更加无力。
slf4j的设计确实比较优雅,采用比较熟悉的方式——接口和实现分离,有个纯粹的接口层——slf4j-api工程,这个里边基本完全定义了日志的接口,所以对于开发来说,只需要使用这个即可。有接口就要有实现,比较推崇的实现是logback,logback完全实现了slf4j-api的接口,并且性能也比log4j更好,同时实现了变参占位符日志输出方式等等新特性。刚刚也提到log4j的使用比较普遍,所以支持这批用户依然是必须的,slf4j-log4j12也实现了slf4j-api,这个算是对log4j的适配器。同样推理,也会有对JUL的适配器slf4j-jdk14等等。为了使使用JCL等等其他日志系统后者实现的用户可以很简单地切换到slf4j上来,给出了各种桥接工程,比如:jcl-over-slf4j会把对JCL的调用都桥接到slf4j上来,可以看出jcl-over-slf4j的api和JCL是相同的,所以这两个jar是不能共存的。jul-to-slf4j是把对jul的调用桥接到slf4j上,log4j-over-slf4j是把对log4j的调用桥接到slf4j。下边用一个图来表示下这个家族的大致成员
如上图,最上层表示桥阶层,下层表示具体的实现层,中间是接口层,可以看出这个图中所有的jar都是围绕着slf4j-api活动的,其中slf4j-jul的jar名称是slf4j-jdk14。slf4j-api和具体的实现层是怎么绑定的呢?这个其实是在编译时绑定的,这个可能不好理解,最直接的表达方式是不需要想jcl那样配置一下,只需要把slf4j-api和slf4j-log4j放到classpath上,即实现绑定。原理可以下载slf4j-api的源码查看,这个设计还是很巧妙的,slf4j-api中会去调用StaticLoggerBinder这个类获取绑定的工厂类,而每个日志实现会在自己的jar中提供这样一个类,这样slf4j-api就实现了编译时绑定实现。但是这样接口的源码编译需要依赖具体的实现了,不太合理吧?当时我也有这样的迷惑,因为打开slf4j-api的jar,看不到StaticLoggerBinder,就查看了slf4j-api的源码,在源码中看到了StaticLoggerBinder这个类,猜想应该是slf4j-api在打包过程中有动作,删除了自己保重的那个类,结果不出所料,确实是pom中的ant-task给处理了,pom中处理方式如下:
- <plugin>
- <groupId>org.apache.maven.plugins</groupId>
- <artifactId>maven-antrun-plugin</artifactId>
- <executions>
- <execution>
- <phase>process-classes</phase>
- <goals>
- <goal>run</goal>
- </goals>
- </execution>
- </executions>
- <configuration>
- <tasks>
- <echo>Removing slf4j-api's dummy StaticLoggerBinder and StaticMarkerBinder</echo>
- <delete dir="target/classes/org/slf4j/impl"/>
- </tasks>
- </configuration>
- </plugin>
打出来的slf4j-api是不完整的,只有找到包含StaticLoggerBinder这个类的包才可以,于是slf4j-log4j和logback-classic都提供了这个类。另外,slf4j-log4j和logback以及slf4j-jdk14是不能同时和slf4j共存的,也就是说只能有一个实现存在,不然启动会提示有多个绑定,判断多个实现的代码也很简单,如下:
- private static String STATIC_LOGGER_BINDER_PATH = "org/slf4j/impl/StaticLoggerBinder.class";
- private static void singleImplementationSanityCheck() {
- try {
- ClassLoader loggerFactoryClassLoader = LoggerFactory.class
- .getClassLoader();
- Enumeration paths;
- if (loggerFactoryClassLoader == null) {
- paths = ClassLoader.getSystemResources(STATIC_LOGGER_BINDER_PATH);
- } else {
- paths = loggerFactoryClassLoader
- .getResources(STATIC_LOGGER_BINDER_PATH);
- }
- // use Set instead of list in order to deal with bug #138
- // LinkedHashSet appropriate here because it preserves insertion order during iteration
- Set implementationSet = new LinkedHashSet();
- while (paths.hasMoreElements()) {
- URL path = (URL) paths.nextElement();
- implementationSet.add(path);
- }
- if (implementationSet.size() > 1) {
- Util.report("Class path contains multiple SLF4J bindings.");
- Iterator iterator = implementationSet.iterator();
- while(iterator.hasNext()) {
- URL path = (URL) iterator.next();
- Util.report("Found binding in [" + path + "]");
- }
- Util.report("See " + MULTIPLE_BINDINGS_URL + " for an explanation.");
- }
- } catch (IOException ioe) {
- Util.report("Error getting resources from path", ioe);
- }
- }
同时这个图中桥阶层和对应的实现jar是不能共存的,比如log4j-over-slf4j和slf4j-log4j,jul-to-slf4j和slf4j-jdk14,这个很好理解,会有死循环,启动也会报错。这种想象也就是说jar之前有互斥性,怎么使用maven有效解决“全局排除”会在以后的博文中讲解。jcl-over-slf4j是把对jcl的调用桥接到slf4j上,前文说到它和jcl是互斥的。图中的红线就表示互斥关系。
当然slf4j也提供了可以把对slf4j的调用桥接到JCL上的工程包——slf4j-jcl,可以看出slf4j的设计者考虑非常周到,想想这样的情况:遗留系统使用的是JCL+log4j,因为系统功能演进,依赖了其他业务线的库,恰好那个库依赖了slf4j-api,并且应用需要关心这个库的日志,那么就需要转接日志到JCL上即可。细心的你可能一经发现,slf4j-jcl和jcl-over-slf4j也是互斥的,太多互斥的了:(。
对于log4j2的加入,也很简单,和logback是很相似的,如下图:
红线依然表示依赖的互斥,当然log4j-slf4j-impl也会和logback-classic、slf4j-log4j、slf4j-jdk14互斥。
常见的问题:
1.slf4j-api和实现版本不对应,尤其是1.6.x和1.5.x不兼容,如果没有特殊需求,直接升级到最新版本。
2.slf4j的多个实现同时存在,比如slf4j-log4j和logback-classic,排除其中一个即可。
3.log4j和logback不能同时使用?可以同时使用,这两个并不矛盾,遗留系统可能直接使用了log4j的代码,并且不能通过log4j-over-slf4j桥接,那么可以让他继续使用log4j,这里有详细的介绍。
4.该如何选用这些呢?建议在非特殊情况下,都使用slf4j-api+logback,不要直接使用日志实现,性能没什么影响。对于要提供给别人的类库,建议使用slf4j-api,使用方可以自由选择具体的实现,并且建议类库不要依赖具体的日志实现。对于自己的桌面小应用,可以直接使用log4j,毕竟只是随便做做。
5.logback因为木有spring提供的启动listener,所以要自己写?可以看看这里,开源社区已经做好了。
6.日志系统一般不会影响到系统性能,除非你的系统对性能非常苛刻,如果这样你可以考虑使用Blitz4j,这个是Netflix社区对log4j的性能改进版,不过他们依然建议去使用log4j或者logback。
内功修炼第二阶段:
https://www.cnblogs.com/gavanwanggw/p/7305218.html
1、概述
眼下java应用日志收集都是採用日志框架(slf4j、apache commons logging)+日志系统(log4j、log4j2、LogBack、JUL等)的方式。而针对在分布式环境须要实时分析统计的日志,一般採用apache flume、facebook scribe等分布式日志收集系统。
日志框架:提供日志调用的接口,实际的日志输出托付给日志系统实现。
- JCL(Jakarta Commons Logging):比較流行的日志框架,非常多框架都依赖JCL,比如Spring等。
- SLF4j:提供新的API,初衷是配合Logback使用,但同一时候兼容Log4j。
日志系统:负责输出日志
- Log4j:经典的一种日志解决方式。内部把日志系统抽象封装成Logger 、appender 、pattern 等实现。我们能够通过配置文件轻松的实现日志系统的管理和多样化配置。
- Log4j2:Log4j的2.0版本号。对Log4j进行了优化。比方支持參数API、支持异步appender、插件式架构等
- Logback:Log4j的替代产品。须要配合日志框架SLF4j使用
- JUL(java.util.logging):JDK提供的日志系统。较混乱,不经常使用
眼下我们的应用大部分都是使用了SLF4j作为门面,然后搭配log4j或者log4j2日志系统。
以下将介绍slf4j + Log4j2 日志组件的引入、以及配置和使用
2、Maven依赖
</pre><pre name="code" class="html"><dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>1.7.13</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-slf4j-impl</artifactId>
<version>2.4.1</version>
</dependency>
<!--兼容log4j-->
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-1.2-api</artifactId>
<version>2.0</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-api</artifactId>
<version>2.4.1</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-core</artifactId>
<version>2.4.1</version>
</dependency>
<!--log4j2 异步appender须要-->
<dependency>
<groupId>com.lmax</groupId>
<artifactId>disruptor</artifactId>
<version>3.2.0</version>
</dependency>
3、配置
- Appenders:也被称为Handlers。负责将日志事件记录到目标位置。在将日志事件输出之前,Appenders使用Layouts来对事件进行格式化处理。
- Layouts:也被称为Formatters,它负责对日志事件中的数据进行转换和格式化。Layouts决定了数据在一条日志记录中的终于形式。
- Loggers:Logger负责捕捉事件并将其发送给合适的Appender。
当Logger记录一个事件时。它将事件转发给适当的Appender。
然后Appender使用Layout来对日志记录进行格式化,并将其发送给控制台、文件或者其他目标位置。另外。Filters能够让你进一步指定一个Appender能否够应用在一条特定的日志记录上。在日志配置中,Filters并非必需的,但能够让你更灵活地控制日志消息的流动。
3.1 Appender
3.1.1 ConsoleAppender
ConsoleAppender是最经常使用的Appenders之中的一个。它仅仅是将日志消息显示到控制台上。
很多日志框架都将其作为默认的Appender。而且在主要的配置中进行预配置。
比如,在Log4j中ConsoleAppender的配置參数例如以下所看到的。
參数 | 描写叙述 |
---|---|
filter | 用于决定是否须要使用该Appender来处理日志事件 |
layout | 用于决定怎样对日志记录进行格式化,默认情况下使用“%m%n”。它会在每一行显示一条日志记录 |
follow | 用于决定Appender是否须要了解输出(system.out或者system.err)的变化,默认情况是不须要跟踪这样的变化 |
name | 用于设置Appender的名字 |
ignoreExceptions | 用于决定是否须要记录在日志事件处理过程中出现的异常 |
target | 用于指定输出目标位置。默认情况下使用SYSTEM_OUT。但也能够改动成SYSTEM_ERR |
<!--这个输出控制台的配置-->
<Console name="Console" target="SYSTEM_OUT">
<!--控制台仅仅输出level及以上级别的信息(onMatch)。其它的直接拒绝(onMismatch)-->
<ThresholdFilter level="DEBUG" onMatch="ACCEPT" onMismatch="DENY"/>
<!--这个都知道是输出日志的格式-->
<PatternLayout pattern="%d{HH:mm:ss.SSS} %-5level %class{36} %L %M - %msg%xEx%n"/>
</Console>
3.1.2 FileAppender
FileAppenders将日志记录写入到文件里。它负责打开、关闭文件。向文件里追加日志记录,并对文件进行加锁。以免数据被破坏或者覆盖。
在Log4j中,假设想创建一个FileAppender,须要指定目标文件的名字。写入方式是追加还是覆盖。以及是否须要在写入日志时对文件进行加锁:
<File name="File" fileName="fileAppender.log" append="true" locking="true">
<PatternLayout pattern="%d{HH:mm:ss.SSS} %-5level %class{36} %L %M - %msg%xEx%n"/>
</File>
3.1.3 RollingFileAppender
RollingFileAppender跟FileAppender的基本使用方法一样。
但RollingFileAppender能够设置log文件的size(单位:KB/MB/GB)上限、数量上限,当log文件超过设置的size上限,会自己主动被压缩。
RollingFileAppender能够理解为滚动输出日志,假设log4j 2记录的日志达到上限,旧的日志将被删除,腾出的空间用于记录新的日志。
<!--这个会打印出全部的信息。每次大小超过size,则这size大小的日志会自己主动存入按年份-月份建立的目录以下并进行压缩,作为存档-->
<RollingFile name="RollingFile1" fileName="logs/log1.log"
filePattern="logs/$${date:yyyy-MM}/log-%d{MM-dd-yyyy}-%i.log">
<PatternLayout pattern="%d{yyyy-MM-dd 'at' HH:mm:ss z} %-5level %class{36} %L %M - %msg%xEx%n"/>
<SizeBasedTriggeringPolicy size="100MB"/>
</RollingFile>
3.1.5 其它appender
我们已经介绍了一些经经常使用到的Appenders,还有非常多其他Appender。
它们加入了新功能或者在其他的一些Appender基础上实现了新功能。比如,Log4j中的RollingFileAppender扩展了FileAppender。它能够在满足特定条件时自己主动创建新的日志文件。SMTPAppender会将日志内容以邮件的形式发送出去;FailoverAppender会在处理日志的过程中,假设一个或者多个Appender失败,自己主动切换到其他Appender上。
假设想了解其它能够參考:https://logging.apache.org/log4j/2.0/manual/appenders.html
3.2 Layouts
Layouts将日志记录的内容从一种数据形式转换成第二种。日志框架为纯文本、HTML、syslog、XML、JSON、序列化以及其他日志提供了Layouts。
这里贴一篇文章简介下我们经常使用的PatternLayout :http://wiki.jikexueyuan.com/project/log4j/log4j-patternlayout.html
其它的layouts配置能够參考:https://logging.apache.org/log4j/2.0/manual/layouts.html
<PatternLayout pattern="%d{yyyy-MM-dd 'at' HH:mm:ss z} %-5level %class{36} %L %M - %msg%xEx%n"/>
3.3 Loggers
Logger负责捕捉事件并将其发送给合适的Appender。Logger之间是有继承关系的。
总是存在一个rootLogger,即使没有显示配置也是存在的,而且默认输出级别为DEBUG。其他的logger都继承自这个rootLogger。
Log4J中的继承关系是通过名称能够看出来,如"A"、"A.B"、"A.B.C",A.B继承A。A.B.C继承A.B,比較类似于包名。
<loggers>
<logger name="com.sankuai" level="info" includeLocation="true" additivity="true">
<appender-ref ref="RollingFile2"/>
<appender-ref ref="RollingFile1"/>
</logger>
<logger name="com.sankuai.meituan" level="error" includeLocation="true" additivity="true">
<appender-ref ref="RollingFile2"/>
<appender-ref ref="RollingFile1"/>
</logger>
<!--建立一个默认的root的logger-->
<root level="error">
<appender-ref ref="Console"/>
<appender-ref ref="RollingFile1"/>
</root>
</loggers>
additivity是 子Logger 是否继承 父Logger 的 输出源(appender) 的标志位。详细说,默认情况下 子Logger 会继承 父Logger 的appender,也就是说 子Logger 会在 父Logger 的appender里输出。若是additivity设为false,则 子Logger 仅仅会在自己的appender里输出。而不会在 父Logger 的appender里输出。
3.4 日志级别
DEBUG , INFO ,WARN ,ERROR四种,分别相应Logger类的四种方法
debug(Object message ) ;
info(Object message ) ;
warn(Object message ) ;
error(Object message ) ;
假设设置级别为INFO。则优先级大于等于INFO级别(如:INFO、WARN、ERROR)的日志信息将能够被输出,
小于该级别的如:DEBUG将不会被输出
4、Log4j2 AsyncLogger与AsyncAppender
先上图
第一张图能够看出Log4j2的asyncLogger的性能较使用asyncAppender和sync模式有很大的提升。特别是线程越多的时候。
第二张图是将log4j2的异步日志机制和其它日志系统进行对照,log4j2的asyncLogger 性能也是非常有优势。
这里主要涉及了两个概念AsyncLogger和AysncAppender。是支持异步的Logger和Appender,以下分别简要介绍下这两个概念。
4.1 AsyncAppender
AsyncAppender持有其它的配置了aysnc的appender引用列表(appender须要通过配置注冊成异步的)。当其它的logger须要打日志的时候(logEvent事件),asyncAppender会接收logEvent,缓存到queue中,然后用单独的线程完毕从queue中取logEvent打印到目的appender,这个逻辑比較简单,看下源代码就能明确这个流程。ps. AsyncAppender是Log4j 和Log4j2 都有的,不是新东西,但从上面的性能对照上还是有一点点差异的。基本的原因是:(引用官方说法)Asynchronous Appenders already existed in Log4j 1.x, but have been enhanced to flush to disk at the end of a batch (when the queue is empty).
关于AsyncAppender能提高性能的场景。能够看下这个篇文章。
http://littcai.iteye.com/blog/316605
怎样配置一个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>
@Plugin(name = "Async", category = "Core", elementType = "appender", printObject = true)
public final class AsyncAppender extends AbstractAppender {
private static final long serialVersionUID = 1L;
private static final int DEFAULT_QUEUE_SIZE = 128;
private static final String SHUTDOWN = "Shutdown";
private static final AtomicLong THREAD_SEQUENCE = new AtomicLong(1);
private static ThreadLocal<Boolean> isAppenderThread = new ThreadLocal<>();
private final BlockingQueue<Serializable> queue;
private final int queueSize;
private final boolean blocking;
private final long shutdownTimeout;
private final Configuration config;
private final AppenderRef[] appenderRefs;
private final String errorRef;
private final boolean includeLocation;
private AppenderControl errorAppender;
private AsyncThread thread;
private AsyncAppender(final String name, final Filter filter, final AppenderRef[] appenderRefs,
final String errorRef, final int queueSize, final boolean blocking, final boolean ignoreExceptions,
final long shutdownTimeout, final Configuration config, final boolean includeLocation) {
super(name, filter, null, ignoreExceptions);
this.queue = new ArrayBlockingQueue<>(queueSize);
this.queueSize = queueSize;
this.blocking = blocking;
this.shutdownTimeout = shutdownTimeout;
this.config = config;
this.appenderRefs = appenderRefs;
this.errorRef = errorRef;
this.includeLocation = includeLocation;
}
@Override
public void start() {
final Map<String, Appender> map = config.getAppenders();
final List<AppenderControl> appenders = new ArrayList<>();
for (final AppenderRef appenderRef : appenderRefs) {
final Appender appender = map.get(appenderRef.getRef());
if (appender != null) {
appenders.add(new AppenderControl(appender, appenderRef.getLevel(), appenderRef.getFilter()));
} else {
LOGGER.error("No appender named {} was configured", appenderRef);
}
}
if (errorRef != null) {
final Appender appender = map.get(errorRef);
if (appender != null) {
errorAppender = new AppenderControl(appender, null, null);
} else {
LOGGER.error("Unable to set up error Appender. No appender named {} was configured", errorRef);
}
}
if (appenders.size() > 0) {
thread = new AsyncThread(appenders, queue);
thread.setName("AsyncAppender-" + getName());
} else if (errorRef == null) {
throw new ConfigurationException("No appenders are available for AsyncAppender " + getName());
}
thread.start();
super.start();
}
@Override
public void stop() {
super.stop();
LOGGER.trace("AsyncAppender stopping. Queue still has {} events.", queue.size());
thread.shutdown();
try {
thread.join(shutdownTimeout);
} catch (final InterruptedException ex) {
LOGGER.warn("Interrupted while stopping AsyncAppender {}", getName());
}
LOGGER.trace("AsyncAppender stopped. Queue has {} events.", queue.size());
}
/**
* Actual writing occurs here.
*
* @param logEvent The LogEvent.
*/
@Override
public void append(LogEvent logEvent) {
if (!isStarted()) {
throw new IllegalStateException("AsyncAppender " + getName() + " is not active");
}
if (!(logEvent instanceof Log4jLogEvent)) {
if (!(logEvent instanceof RingBufferLogEvent)) {
return; // only know how to Serialize Log4jLogEvents and RingBufferLogEvents
}
logEvent = ((RingBufferLogEvent) logEvent).createMemento();
}
logEvent.getMessage().getFormattedMessage(); // LOG4J2-763: ask message to freeze parameters
final Log4jLogEvent coreEvent = (Log4jLogEvent) logEvent;
boolean appendSuccessful = false;
if (blocking) {
if (isAppenderThread.get() == Boolean.TRUE && queue.remainingCapacity() == 0) {
// LOG4J2-485: avoid deadlock that would result from trying
// to add to a full queue from appender thread
coreEvent.setEndOfBatch(false); // queue is definitely not empty!
appendSuccessful = thread.callAppenders(coreEvent);
} else {
final Serializable serialized = Log4jLogEvent.serialize(coreEvent, includeLocation);
try {
// wait for free slots in the queue
queue.put(serialized);
appendSuccessful = true;
} catch (final InterruptedException e) {
// LOG4J2-1049: Some applications use Thread.interrupt() to send
// messages between application threads. This does not necessarily
// mean that the queue is full. To prevent dropping a log message,
// quickly try to offer the event to the queue again.
// (Yes, this means there is a possibility the same event is logged twice.)
//
// Finally, catching the InterruptedException means the
// interrupted flag has been cleared on the current thread.
// This may interfere with the application's expectation of
// being interrupted, so when we are done, we set the interrupted
// flag again.
appendSuccessful = queue.offer(serialized);
if (!appendSuccessful) {
LOGGER.warn("Interrupted while waiting for a free slot in the AsyncAppender LogEvent-queue {}",
getName());
}
// set the interrupted flag again.
Thread.currentThread().interrupt();
}
}
} else {
appendSuccessful = queue.offer(Log4jLogEvent.serialize(coreEvent, includeLocation));
if (!appendSuccessful) {
error("Appender " + getName() + " is unable to write primary appenders. queue is full");
}
}
if (!appendSuccessful && errorAppender != null) {
errorAppender.callAppender(coreEvent);
}
}
/**
* Create an AsyncAppender.
*
* @param appenderRefs The Appenders to reference.
* @param errorRef An optional Appender to write to if the queue is full or other errors occur.
* @param blocking True if the Appender should wait when the queue is full. The default is true.
* @param shutdownTimeout How many milliseconds the Appender should wait to flush outstanding log events
* in the queue on shutdown. The default is zero which means to wait forever.
* @param size The size of the event queue. The default is 128.
* @param name The name of the Appender.
* @param includeLocation whether to include location information. The default is false.
* @param filter The Filter or null.
* @param config The Configuration.
* @param ignoreExceptions If {@code "true"} (default) exceptions encountered when appending events are logged;
* otherwise they are propagated to the caller.
* @return The AsyncAppender.
*/
@PluginFactory
public static AsyncAppender createAppender(@PluginElement("AppenderRef") final AppenderRef[] appenderRefs,
@PluginAttribute("errorRef") @PluginAliases("error-ref") final String errorRef,
@PluginAttribute(value = "blocking", defaultBoolean = true) final boolean blocking,
@PluginAttribute(value = "shutdownTimeout", defaultLong = 0L) final long shutdownTimeout,
@PluginAttribute(value = "bufferSize", defaultInt = DEFAULT_QUEUE_SIZE) final int size,
@PluginAttribute("name") final String name,
@PluginAttribute(value = "includeLocation", defaultBoolean = false) final boolean includeLocation,
@PluginElement("Filter") final Filter filter, @PluginConfiguration final Configuration config,
@PluginAttribute(value = "ignoreExceptions", defaultBoolean = true) final boolean ignoreExceptions) {
if (name == null) {
LOGGER.error("No name provided for AsyncAppender");
return null;
}
if (appenderRefs == null) {
LOGGER.error("No appender references provided to AsyncAppender {}", name);
}
return new AsyncAppender(name, filter, appenderRefs, errorRef, size, blocking, ignoreExceptions,
shutdownTimeout, config, includeLocation);
}
/**
* Thread that calls the Appenders.
*/
private class AsyncThread extends Thread {
private volatile boolean shutdown = false;
private final List<AppenderControl> appenders;
private final BlockingQueue<Serializable> queue;
public AsyncThread(final List<AppenderControl> appenders, final BlockingQueue<Serializable> queue) {
this.appenders = appenders;
this.queue = queue;
setDaemon(true);
setName("AsyncAppenderThread" + THREAD_SEQUENCE.getAndIncrement());
}
@Override
public void run() {
isAppenderThread.set(Boolean.TRUE); // LOG4J2-485
while (!shutdown) {
Serializable s;
try {
s = queue.take();
if (s != null && s instanceof String && SHUTDOWN.equals(s.toString())) {
shutdown = true;
continue;
}
} catch (final InterruptedException ex) {
break; // LOG4J2-830
}
final Log4jLogEvent event = Log4jLogEvent.deserialize(s);
event.setEndOfBatch(queue.isEmpty());
final boolean success = callAppenders(event);
if (!success && errorAppender != null) {
try {
errorAppender.callAppender(event);
} catch (final Exception ex) {
// Silently accept the error.
}
}
}
// Process any remaining items in the queue.
LOGGER.trace("AsyncAppender.AsyncThread shutting down. Processing remaining {} queue events.",
queue.size());
int count = 0;
int ignored = 0;
while (!queue.isEmpty()) {
try {
final Serializable s = queue.take();
if (Log4jLogEvent.canDeserialize(s)) {
final Log4jLogEvent event = Log4jLogEvent.deserialize(s);
event.setEndOfBatch(queue.isEmpty());
callAppenders(event);
count++;
} else {
ignored++;
LOGGER.trace("Ignoring event of class {}", s.getClass().getName());
}
} catch (final InterruptedException ex) {
// May have been interrupted to shut down.
// Here we ignore interrupts and try to process all remaining events.
}
}
LOGGER.trace("AsyncAppender.AsyncThread stopped. Queue has {} events remaining. "
+ "Processed {} and ignored {} events since shutdown started.", queue.size(), count, ignored);
}
/**
* Calls {@link AppenderControl#callAppender(LogEvent) callAppender} on all registered {@code AppenderControl}
* objects, and returns {@code true} if at least one appender call was successful, {@code false} otherwise. Any
* exceptions are silently ignored.
*
* @param event the event to forward to the registered appenders
* @return {@code true} if at least one appender call succeeded, {@code false} otherwise
*/
boolean callAppenders(final Log4jLogEvent event) {
boolean success = false;
for (final AppenderControl control : appenders) {
try {
control.callAppender(event);
success = true;
} catch (final Exception ex) {
// If no appender is successful the error appender will get it.
}
}
return success;
}
public void shutdown() {
shutdown = true;
if (queue.isEmpty()) {
queue.offer(SHUTDOWN);
}
}
}
/**
* Returns the names of the appenders that this asyncAppender delegates to as an array of Strings.
*
* @return the names of the sink appenders
*/
public String[] getAppenderRefStrings() {
final String[] result = new String[appenderRefs.length];
for (int i = 0; i < result.length; i++) {
result[i] = appenderRefs[i].getRef();
}
return result;
}
/**
* Returns {@code true} if this AsyncAppender will take a snapshot of the stack with every log event to determine
* the class and method where the logging call was made.
*
* @return {@code true} if location is included with every event, {@code false} otherwise
*/
public boolean isIncludeLocation() {
return includeLocation;
}
/**
* Returns {@code true} if this AsyncAppender will block when the queue is full, or {@code false} if events are
* dropped when the queue is full.
*
* @return whether this AsyncAppender will block or drop events when the queue is full.
*/
public boolean isBlocking() {
return blocking;
}
/**
* Returns the name of the appender that any errors are logged to or {@code null}.
*
* @return the name of the appender that any errors are logged to or {@code null}
*/
public String getErrorRef() {
return errorRef;
}
public int getQueueCapacity() {
return queueSize;
}
public int getQueueRemainingCapacity() {
return queue.remainingCapacity();
}
}
AsyncLogger是Log4j2引入的新特性,业务代码调用Logger.log的时候直接返回。而不须要等到appender输出到日志目的地后才返回。
Log4j2的Asynclogger是通过LMAX Disruptor取代queue实现的异步(无锁的并发框架,http://ifeve.com/disruptor/。Disruptor简单介绍),达到更高的并发和lower latency。
4.2 AsyncLogger
1,Disruptor使用了一个RingBuffer替代队列,用生产者消费者指针替代锁。 2,生产者消费者指针使用CPU支持的整数自增。无需加锁而且速度非常快。Java的实如今Unsafe package中。 |
虽然AsyncLogger 可以大幅度的提高性能。可是也会带来一些问题。以下是翻译官方的文档的Trade-offs:
Benefits
- Higher throughput,达到相对于sync logger的6-68倍的吞吐量
- Lower logging latency,latency是调用Logger.log直到return的时间。asyncLogger的latency比syncLogger以及基于queue的aysncAppender都要低,不仅平均latency低,并且99%、95%latency 也都低于后两者
- 减少极端大的日志量时候的延迟尖峰
Drawbacks
- Error handling, 假设在打印日志的时候出现错误,使用asyncLogger。业务是不知道异常的(能够通过配置ExceptionHandler处理异常)。假设打印日志是业务逻辑的一部分,不建议使用asyncLogger
- 打印一些可变的内容的时候。使用asyncLogger 会出现故障。大部分时间,不须要操心这点。Log4j确保了类似于 logger.debug("My object is {}", myObject),使用myObject在打印日志的时刻的版本号打印(Log4j 全部打印都日志都是封装到Message的实现类里,存储在 final String里),无论之后是否改变。可是log4j也支持一些了可变的Message,如 MapMessage and StructuredDataMessage 。这些假设在打印日志时候改变,就有问题了
全局配置异步Logger
配置全部Logger都为AsyncLogger,仅仅须要添加disruptor包,然后配置一个system property,-DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector。Log4j的配置文件不须要改动。
混合使用同步和异步Logger
单独配置某个logger为async的,通过<asyncRoot>或者<asyncLogger>
<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 -->
<AsyncLogger name="com.foo.Bar" level="trace" includeLocation="true">
<AppenderRef ref="RandomAccessFile"/>
</AsyncLogger>
<Root level="info" includeLocation="true">
<AppenderRef ref="RandomAccessFile"/>
</Root>
</Loggers>
</Configuration>
ps. location的问题
当layouts配置了输出%C or $class, %F or %file, %l or %location, %L or %line, %M or %method,或者HTML locationInfo, log4j会获取location的一个快照,而这对于sync 和async的logger都是一个耗时的操作(官方文档上说syncLogger会慢1.3~5倍。async会慢4-20倍)。所以默认都是不会输出location信息,除非Logger配置了includeLocation="true"(官方文档这么说的,可是我測试的是默认是输出的,无论了。反正当日志出现慢的时候,能够考虑通过配置includeLocation控制是否输出location信息)。
=====================================以下为作者自己探究================
由于上面的架构图,只是描述了关系。为了实际使用,我们不可能同时使用以上系统中的多个,只能选一个。我在这里选择了log4j2作为springmvc项目的日志记录系统。
我们知道log4j与log4j2实际上并不是连贯的一套日志系统,因为log4j2不兼容log4j.因此,当我们使用log4j2的时候,就必须避开log4j版本的jar包。
log4j2项目是apache项目,具体官网下载地址:
https://www.apache.org/dyn/closer.lua/logging/log4j/2.10.0/apache-log4j-2.10.0-bin.zip
这里下载之后,解压发现里面有居多jar包,而不仅仅是一个。
具体有这一些。
当使用springmvc项目的时候,是需要配置filter,servlet的。所以,
<!-- log4j配置,文件路径,因为是跟随项目启动 -->
<context-param>
<param-name>log4jConfigLocation</param-name>
<param-value>/WEB-INF/log4j2.xml</param-value>
</context-param>
<!-- log4j2-begin -->
<listener>
<listener-class>org.apache.logging.log4j.web.Log4jServletContextListener</listener-class>
</listener>
<filter>
<filter-name>log4jServletFilter</filter-name>
<filter-class>org.apache.logging.log4j.web.Log4jServletFilter</filter-class>
</filter>
<filter-mapping>
<filter-name>log4jServletFilter</filter-name>
<url-pattern>/*</url-pattern>
<!-- <dispatcher>REQUEST</dispatcher> <dispatcher>FORWARD</dispatcher>
<dispatcher>INCLUDE</dispatcher> <dispatcher>ERROR</dispatcher> -->
</filter-mapping>
<!-- log4j2-end -->
在web.xml中需要加上这段代码。
pom文件记录如下:
<properties>
<slf4j.version>1.7.25</slf4j.version>
<log4j.version>2.8.2</log4j.version>
<spring.version>4.3.14.RELEASE</spring.version>
</properties>
<!-- 日志开始 -->
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>${slf4j.version}</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-slf4j-impl</artifactId>
<version>${log4j.version}</version>
</dependency>
<!--兼容log4j -->
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-1.2-api</artifactId>
<version>2.0</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-api</artifactId>
<version>${log4j.version}</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-core</artifactId>
<version>${log4j.version}</version>
</dependency>
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-web</artifactId>
<version>${log4j.version}</version>
</dependency>
<!--log4j2 异步appender须要 -->
<dependency>
<groupId>com.lmax</groupId>
<artifactId>disruptor</artifactId>
<version>3.2.0</version>
</dependency>
<!--日志结束 -->
注意:这里不仅需要log4j-core,还需要log4j-web.jar。这都是log4j的部分。所以,可以把图上的jar包根据情况进行添加。
日志配置文件:
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="off" monitorInterval="1800">
<properties>
<property name="LOG_HOME">d://logs/tomcat-8081</property>
<property name="FILE_NAME">springRedisCloudTest</property>
</properties>
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n" />
</Console>
<RollingRandomAccessFile name="running-log"
fileName="${LOG_HOME}/${FILE_NAME}.log"
filePattern="${LOG_HOME}/$${date:yyyy-MM}/${FILE_NAME}-%d{yyyy-MM-dd}-%i.log.gz">
<PatternLayout
pattern="%date{yyyy-MM-dd HH:mm:ss.SSS} %level [%thread][%file:%line] - %msg%n" />
<Policies>
<TimeBasedTriggeringPolicy />
<SizeBasedTriggeringPolicy size="10 MB" />
</Policies>
<DefaultRolloverStrategy max="20" />
</RollingRandomAccessFile>
</Appenders>
<Loggers>
<Logger name="springRedisCloudTest" level="info"
additivity="true">
<AppenderRef ref="running-log" />
</Logger>
<Root level="info">
<AppenderRef ref="Console" />
</Root>
</Loggers>
</Configuration>
使用:
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
private Logger logger = LoggerFactory.getLogger(RedisController.class);
logger.info("PRINT A MARK IN THE METHOD");