og4j1.x升级log4j2.x及异步日志开启
由于log4j1.x采用同步的方式打印log,当项目中打印log的地方很多的时候,频繁的加锁拆锁会导致性能的明显下降。log4j推出了异步logging的方式,所以项目准备升级log4j2.x。
备注:项目使用maven管理第三方类库,所以jar包的替换是通过更改maven配置的方式进行更改的
简介
通常我们在日常的应用开发中,日志起到一个非常重要的作用。对于不同的环境来说,我们不可能像开发环境那样有一个完善的支持。这时候日志的作用就更加凸显出来了。日志不仅仅用于开发的时候排查错误,在不同的环境下,它还可以用来检测系统的运行情况,甚至监控系统的性能指标。所以,我们有必要对于日志的来由和使用做一个深入的理解。这里结合目前最常用的日志框架log4j2来进行讨论。
log应用的几个要素
为什么要记log
我们都知道,在应用开发里,针对不同的环境,如何知道我们系统是正常运行的呢?这里几乎唯一能够依靠的就是log了。所以,问题不在于需不需要log,而是该如何去配置和使用log。而且,在不同的环境限制下,我们不能在所有的环境都像开发环境一样,可以有完善的调试跟踪器。所以,也只有log能够起到一个重要的分析问题和追踪问题的作用。
log里该记什么
其实根据具体应用的需要,log里需要的记录的东西非常多。比如应用如果突然崩溃了,我们需要能够有日志记录来分析它为什么会崩。如果应用出错的时候,我们也需要记录到底是哪里出错了,最好有错误的类型和消息以及栈信息记录。有时候,还有一些重要事件的发生,这也会引起我们的注意,那么也有必要通过日志进行记录。
总的来说,日志里需要记录的东西实在是太多了。而且他们都对应不同的应用层面。这一点也是在记录日志的时候需要考虑的。
log该怎么写
和我们通常理解的写到文件里不一样。log并不一定要写到文件里。它还可以有很多中别的记录方式。比如:
控制台:
这是最常用的一种方式了。在常用的一些测试里,我们只是希望在屏幕的输出里看到这些记录信息。它就相当于我们使用的System.out.println()等方法。只是在实际使用上比这种输出方法要更加优雅一些。
普通文件:
我们可以将日志内容持久化到一些文件里。当然,一些普通的文件如果记录的内容比较杂乱的话,这些非结构化的内容检索起来比较麻烦。实际上还是有一些其他方式的记录文件的,比如xml, json或者syslog文件等等。这些文件遵循一定的格式规范,相对来说有一定的规律可循,在解析和处理上会更加便利一点。
socket:
在一些大型应用中,我们可能并不仅仅只是记录日志信息,还需要通过socket将日志内容发送到网络的某个地方来统一的收集和处理。这里,一个典型的就是通过socket作为传输手段了。
数据库:
在某些情况下,我们也可以将日志记录到关系型或者某些nosql数据库中。这些数据相对来说更加格式化也更加便于管理一些。
除了以上列举出来的一些方式,我们还有很多其他的日志记录手段,像通过邮件和短信协议来记录日志。由此可见,日志的记录方式多种多样,使得它可以适应更多具体的需要。
log level和category
基于目前的讨论,我们已经发现,对于不同级别的需要我们需要提供不同的日志信息。而有的信息属于比较紧急的,而有的仅仅是为了输出分析或者追踪的需要。那么,如果没有一个合理的级别划分处理的话,将所有的log内容混在一起确实不太合理。加入将很多调试的信息混杂在具体分析错误的日志里,会使得查找信息变得更加困难。而且,各种不相关的信息混杂在一起,也会导致日志文件的急剧增长,这对于日志文件的存储和处理也不利。所以,我们有必要对日志的内容进行详细的分类处理。
以log4j为例,它定义的log level主要如下表所示:
在上表中,有两个特殊的level, ON和OFF。其中ON表示如果设置成这个级别,则所有各类型的日志信息都会被记录下来。而OFF则表示不记录任何的日志信息。除了这两个意外,其他的级别从上到下按照严重程度排列。而且,这里还有一个有意思的规则来避免前面提到的各种级别的日志混杂在一起。比如上表中,每一列表示当前log事件的级别,而每一行表示log配置的级别。所以当目前配置的级别高于log事件的级别,则这部分的日志信息是不会有输出的。比如第二行的trace。当我们配置的log级别是DEBUG以及更高的时候,它不会有任何的输出。所以通过这种方式它能有效的规避前面出现的问题。
log级别定义比较好理解。那么对于log category的定义则是另外一个层次的问题。既然我们前面定义好了对于不同级别的需要定义不同的level。那么,在我们的应用里,可能需要对于不同级别的输出需求都有。这些总不能通过一个logger来包打一切吧?这时候,就需要支持定义多个不同的log实例,每个实例可以定义有不同的级别。在应用里使用这些日志也就更加方便。关于这些的详细配置和使用会在后面继续描述。
log4j2
前面的讨论算是对于log的基本概念有了一定的了解。那么,在具体的应用里,我们一般都是通过某个具体的log框架来实现这些日志记录目标的。而log4j2几乎是目前最流行的日志框架了。我们在这里对它的使用和配置做一个进一步的讨论。
依赖定义
如果我们希望在应用里使用log4j2,我们一般需要引入如下的依赖:
- <dependency>
- <groupId>org.apache.logging.log4j</groupId>
- <artifactId>log4j-api</artifactId>
- <version>${log4j.version}</version>
- <scope>compile</scope>
- </dependency>
- <dependency>
- <groupId>org.apache.logging.log4j</groupId>
- <artifactId>log4j-core</artifactId>
- <version>${log4j.version}</version>
- <scope>runtime</scope>
- </dependency>
这里的依赖比较有意思。一个是scope在compile的log4j-api。这是我们应用程序里需要直接使用的api。而这里还有一个依赖,就是log4j-core,但是它的scope是runtime。为什么这里要定义两个应用呢?这里因为log框架里一个比较有意思的原则。就是接口与实现分离。在log4j里,我们通过定义的一组标准接口来写日志。但是具体实现日志的库则在运行时才提供,这样可以保证最大程度的松耦合,也减少接口定义和实现的互相干扰。在这里,我们引用的是log4j的标准实现。由于一些历史以及兼容的原因,我们也可以引用另外的一些实现。比如log4j-jcl,它是实现支持Commons Logging API的适配器。而log4j-slf4j-impl则是实现适配slf4j的适配器。
配置
在引入log4j2的依赖之后,还有一个重要的就是设置它的配置文件。那么它支持哪些配置文件呢?文件可以设置成什么样的格式呢?而且,这些配置文件应该放在哪里呢?我们这里一一分析过来。
log4j2实际上支持4种方式的配置:
1. 通过XML, JSON, YAML或者properties文件作为配置文件来设置。
2. 通过程序创建ConfigurationFactory和Configuration实现。
3. 通过程序调用Configuration接口暴露的api,并添加组件到默认的配置中实现。
4. 通过程序调用内部类Logger的方法。
当然,我们在大多数情况下都是通过配置文件的方式来实现的。在本文里,我们主要讨论基于xml文件实现配置效果的方式。
在知道要用什么来进行配置之后,那么这些配置文件该放到哪里呢?在log4j2里,配置文件检测的过程如下:
1. log4j会检测名为"log4j.configurationFile"的系统属性值,如果这个值被设置了,则会尝试通过ConfigurationFactory来加载这个值对应的文件。
2. 否则它会尝试查找log4j2-test.properties这个文件。
3. 否则它会尝试查找文件log4j2-test.yaml 和 log4j2-test.yml。
4. 否则它会尝试查找文件log4j2-test.json 和 log4j2-test.jsn。
5. 否则查找文件log4j2-test.xml。
6. 否则查找文件log4j2.properties。
7. 否则查找文件log4j2.yaml 和 log4j2.yml。
8. 否则查找文件log4j2.json 和 log4j2.jsn。
9. 否则查找文件log4j2.xml。
10. 否则尝试读取DefaultConfiguration信息,这样会将日志信息输出到屏幕上。
当然,如果上述所有的配置信息都不满足,它将会在屏幕输出上显示错误信息。上述的流程看起来比较复杂,不过我们在实际应用中只需要根据要求将符合命名的文件放到类路径上就可以了。
loggers
前面讨论了这么多,我们先来看一个简单的xml配置文件示例:
- <?xml version="1.0" encoding="UTF-8"?>
- <configuration status="WARN">
- <appenders>
- <Console name="Console" target="SYSTEM_OUT">
- <PatternLayout
- pattern="%d{DEFAULT} [%t] %-5p %c{36} - %m%n"/>
- </Console>
- </appenders>
- <loggers>
- <root level="info">
- <appender-ref ref="Console" />
- </root>
- </loggers>
- </configuration>
这个文件代表了这一类配置文件的典型信息。我们可以看到它是由一个configuration元素嵌套了appenders和loggers组成。我们一部分一部分的看过来。
首先,在configuration这里有一个status="WARN"的配置。这表示什么意思呢?在我们日常配置各种日志框架的时候,我们一般是设置我们的应用输出各种信息。但是对于日志框架它本身来说呢?如果它本身碰到各种问题了该怎么办呢?这里就是设置日志框架本身的。它表示如果log4j2框架面临WARN以及更高级别的事件时,它也会通过我们配置的日志信息将这些给输出出来。
里面的appenders部分则表示日志输出的选项。
appenders
在log4j2里其实有很多种appenders,也就是说我们前面提到过的各种日志输出方式。像前面示例里我们只是给出一个简单的Console输出。其它的输出appender比较多,比如说:CassandraAppender, FailoverAppender, FileAppender, FlumeAppender, JDBCAppender, JMS Appender, JPAAppender, HttpAppender, RollingFileAppender。当然,这里我们只讨论最常见的console, FileAppender, RollingFileAppender这几种。其他的可以参考对应的文档。
以前面的console appender为例,它的配置也许是最简单的了。在Console元素里设置好name和target就可以了。因为这里是直接输出到屏幕,所以只需要考虑它的输出样式就可以了。
在实际应用中,还有一种appender更加常见和实用,就是基于文件的appender,像fileappender和rollingfileappender。它使用的场景相对来说复杂一些。一个基于rollingfileappender的配置如下:
- <RollingFile name="WroxFileAppender" fileName="../logs/application.log"
- filePattern="../logs/application-%d{MM-dd-yyyy}-%i.log">
- <PatternLayout>
- <pattern>%d{DEFAULT} [%t] %X{id} %X{username} %-5p %c{36}: %msg%n</pattern>
- </PatternLayout>
- <Policies>
- <SizeBasedTriggeringPolicy size="10 MB" />
- </Policies>
- <DefaultRolloverStrategy min="1" max="4" />
- </RollingFile>
结合基于文件来保存日志的几个需要考虑的点,我们来讨论这部分配置。首先一个,文件要保存到哪里。所以这里就是通过fileName来制定保存的日志文件的路径。其次,我们知道,文件保存日志的话,不应该无限制的往这个文件里写,导致文件的不断增大。那么,就需要考虑一定的策略,比如说,当文件增大的多大的时候,就另外新开一个文件来记录日志。这里就是RollingFile来做的。它通过写成滚动文件的方式,可以将原来文件过期之后再继续利用。当然,这里就会继续引出新的问题。比如说,我们希望保存这些达到一定大小的日志文件,那么这个文件到多大的时候就该保存呢?这是通过SizeBasedTriggeringPolicy里设置size大小来实现。当然,我们也可以通过时间限制来实现每多久产生一个新的文件。还有,这些文件该保存多少个合适呢?这就需要通过DefaultRolloverStrategy来实现,比如说保存最少1个,最多4个。还有就是,既然这些达到一定大小或者限制的文件要保留,这些保留的文件该怎么命名呢?它肯定不能和输出日志的文件同名。所以这些也需要在filePattern里设置。
layout
在上述的配置里,还有一个重要的地方没讨论,就是layout。在log4j2里,其实有很多layout的配置,来支持各种样式和格式的输出。这样会是的日志的记录更加方便和灵活。一些典型的layout如下:CSV Layouts,GELF Layout, HTML Layout, JSON Layout, Pattern Layout, Serialized Layout, Syslog Layout, XML Layout, YAML Layout。 由于在应用中,我们采用Pattern layout的方式比较多。我们重点讨论这部分。
在PatternLayout里,我们通过Pattern这个元素来指定输出日志的格式,以上述的示例%d{DEFAULT} [%t] %X{id} %X{username} %-5p %c{36}: %msg%n为例来看。它的格式定义有点像正则表达式。我们针对最常见的几个配置项进行讨论。
%c 输出所属的类目,通常是类的全名。它后面的括号里设置的数字用来配置显示的类层次数。比如设置为1的话,表示仅仅显示这个类的最低一级的类名,而不显示它的更高级别的包名。
%d 输出当前的日期。它后面的括号里可以定义各种日期的格式,比如前面的DEFAULT, 他表示以如下格式显示的日期:2012-11-02 14:34:02,781。
%l 输出产生这个日志所在代码的位置。精确到所在的类及方法里的某一行的数字。
%m 输出代码中指定的消息。它也可以定义成%msg或%message的样子。
%n 输出一个回车换行符。
%p 输出日志当前的优先级,比如有我们前面讨论的TRACE, DEBUG, INFO, WARN, ERROR等。
%r 输出应用从启动到输出该log信息耗费的毫秒数。
%t 产生当前日志的线程名。
%x 输出当前线程的上下文,比如线程上下文map里定义的一些名值对。
理解了上述这些符号代码的意思之后,我们就知道怎么去定制自己应用的输出日志格式了。上述示例里输出的日志示例将像如下的格式:
- 2018-02-15 15:20:36,850 [http-nio-8080-exec-3] d08c57a2-8738-4ed1-8699-db759bafd949 ERROR com.wrox.ActionServlet: No action specified.
log的使用和继承关系
前面讨论了那么多,一直在讲怎么配置log,就是一直没有说怎么在程序里使用log4j2。其实只要把前面的配置弄好之后,怎么使用日志就非常简单了。最常用的一种方式如下:
- private static Logger logger = LogManager.getLogger(Your class name.class);
通过这种方式,就可以得到一个唯一的基于当前类的logger。而且任意一个指定相同参数的getLogger的方法,返回的肯定是同一个logger对象。当然,log4j2还提供一个更加简化的获取logger的方法:
- private static Logger logger = LogManager.getLogger();
它会根据调用这个方法所在的类来获取logger。有了这个logger对象之后,我们可以通过调用它的不同优先级的方法,比如logger.info(), logger,warn()等。
在得到了logger之后,我们最后需要注意的问题就是结合logger的继承关系来配置它们了。在之前的讨论里我们看到,loggers里面有一个root的logger。在所有的logger里,都有一个root的logger,它是所有logger的父logger。这有点像类的继承层级结构,就可以把它当作java里的Object类好了。这个继承层次关系稍微有点复杂,如果一不注意会使得我们丢失一些log信息。
logger里的层级结构关系如下图:
我们可以看到,如果我们自己没有设置当前某个包范围内的logger优先级,那么它默认就是继承root logger的优先级。像上图中,root logger定义的优先级是WARN,那么,com这个范围内的logger默认的就是warn。所以这时如果我们去尝试输出低于WARN级别的日志,是不会看到有任何输出的。因为它们都被屏蔽了。
比如说,如果我们有一个如下的配置文件:
- <?xml version="1.0" encoding="UTF-8"?>
- <configuration status="WARN">
- <appenders>
- <Console name="Console" target="SYSTEM_OUT">
- <PatternLayout
- pattern="%d{DEFAULT} [%t] %-5p %c{36} - %m%n"/>
- </Console>
- </appenders>
- <loggers>
- <root level="warn">
- <appender-ref ref="Console" />
- </root>
- </loggers>
- </configuration>
我们同时有如下的代码:
- package com.wrox;
- import org.apache.logging.log4j.LogManager;
- import org.apache.logging.log4j.Logger;
- public class App {
- private static Logger logger = LogManager.getLogger();
- public static void main( String[] args ) {
- logger.warn("info log");
- }
- }
程序将输出如下的内容:
- 2018-02-15 15:42:36,126 [main] WARN com.wrox.App - warn log
但是,如果我们将logger.warn改成更低的像logger.info, logger.debug。那么将看不到任何输出。
看来这种logger继承关系也有一个好处,就是如果我们不想自定义自己的Logger优先级,只要有一个定义好的父logger就省事了。当然,在很多情况下因为我们需要不同优先级别的logger,我们需要做一些调整。有时候我们不希望继承它的父logger的配置。那该怎么办呢?我们可以通过配置logger的additivity属性来实现。它表示是否继承父logger的属性。默认值是true。所以,如果我们配置一个如下的logger信息的话:
- <?xml version="1.0" encoding="UTF-8"?>
- <configuration status="WARN">
- <appenders>
- <Console name="Console" target="SYSTEM_OUT">
- <PatternLayout
- pattern="%d{DEFAULT} [%t] %-5p %c{36} - %m%n"/>
- </Console>
- </appenders>
- <loggers>
- <root level="warn">
- <appender-ref ref="Console" />
- </root>
- <logger name="com.wrox" level="info" additivity="false">
- <appender-ref ref="Console"/>
- </logger>
- </loggers>
- </configuration>
我们在这里新建了一个logger,它不会继承root logger的属性,所以在这个包com.wrox以及它的子包里的所有logger都默认继承自它了。如果我们在代码里尝试如下的代码:
- logger.info("info log");
我们可以看到如下的输出:
- 2018-02-15 15:47:15,805 [main] INFO com.wrox.App - info log
所以,在这里root logger的限制对它来说就不起作用了。
关于获取logger的地方,还有一个细节值得我们注意。就是在前面定义的配置文件里,我们一般是指定它所在的包及范围。当然,也可以设置一个指定的logger name。比如说我们将配置文件设置成如下的方式:
- <?xml version="1.0" encoding="UTF-8"?>
- <configuration status="WARN">
- <appenders>
- <Console name="Console" target="SYSTEM_OUT">
- <PatternLayout
- pattern="%d{DEFAULT} [%t] %-5p %c{36} - %m%n"/>
- </Console>
- </appenders>
- <loggers>
- <root level="warn">
- <appender-ref ref="Console" />
- </root>
- <logger name="com.wrox" level="info" additivity="false">
- <appender-ref ref="Console"/>
- </logger>
- <logger name="sample" level="info">
- <appender-ref ref="Console"/>
- </logger>
- </loggers>
- </configuration>
在这里,我们定义了一个名字为"sample"的logger。那么,我们该如何引用这个logger呢?我们可以通过在代码里引用这个名字的logger。具体的引用代码如下:
- private static Logger logger = LogManager.getLogger("sample");
当然,如果我们执行程序的话,会发现同样的日志给输出了两遍:
- 2018-02-15 15:50:49,302 [main] INFO sample - info log
- 2018-02-15 15:50:49,302 [main] INFO sample - info log
这是因为我们自定义的logger它默认是继承自root logger的。所以也会导致root logger这边的输出。我们只需要禁止它的继承关系就可以了。
AsyncLogger
在log4j2里,还有一个比较重要的特性,就是asyncLogger。因为它不是通过同步的方式将日志发送记录下来,而是采用异步的方式。这种方式带来的好处就是日志记录上的性能有极大的提升。在某些情况下,我们可以考虑采用它来配置日志。
采用AsyncLogger需要使用一个额外的依赖,就是库disruptor。它的依赖如下:
- <dependency>
- <groupId>com.lmax</groupId>
- <artifactId>disruptor</artifactId>
- <version>3.3.7</version>
- </dependency>
有了这个之后,它的日志配置还是挺简单的,一个具体的示例如下:
- <?xml version="1.0" encoding="UTF-8"?>
- <configuration status="WARN">
- <appenders>
- <Console name="Console" target="SYSTEM_OUT">
- <PatternLayout
- pattern="%d{DEFAULT} [%t] %-5p %c{36} - %m%n"/>
- </Console>
- <RollingFile name="WroxFileAppender" fileName="../logs/application.log"
- filePattern="../logs/application-%d{MM-dd-yyyy}-%i.log">
- <PatternLayout>
- <pattern>%d{DEFAULT} [%t] %X{id} %X{username} %-5p %c{36}: %msg%n</pattern>
- </PatternLayout>
- <Policies>
- <SizeBasedTriggeringPolicy size="10 MB" />
- </Policies>
- <DefaultRolloverStrategy min="1" max="4" />
- </RollingFile>
- </appenders>
- <loggers>
- <root level="warn">
- <appender-ref ref="Console" />
- </root>
- <AsyncLogger name="com.wrox" level="info" includeLocation="true" additivity="false">
- <appender-ref ref="WroxFileAppender"/>
- <appender-ref ref="Console"/>
- </AsyncLogger>
- </loggers>
- </configuration>
在这个示例里,我们定义了两个appender,一个是console,一个是RollingFile。我们定义的AsyncLogger只需要在loggers元素里定义这么一个项,然后将appender引用进来就可以了。
总结
在应用程序里,记录日志是一个看起来很细小但是却很重要的步骤。如何记录日志,选择合适的日志框架也是一个需要仔细思考的问题。日志的记录方式,保存和处理方式,记录的格式等等都牵涉到很多的细节。并不像我们想象的那么简单