本文较为详细地讲述log4j2的日志输出使用原理、如何配置,并结合具体的代码,给出程序调用的方法。为了讲清原理,本文从log4j的日志级别开讲,然后讲述主配置文件log4j2.xml的配置方法、程序调用方法,并给出一个比较完整的log4j2配置文件。
2015年9⽉apache基金会宣布log4j不再维护,最终版本定格为1.2.17,任何情况下,该版本不再推荐使用。
log4j2是log4j的作者,做的新版本log4j,沿用log4j名称和版本编号法则,版本为2.X,但与log4j完全不兼容,是基于slf4j门面做的实现。关于log江湖里在log4j之后,分成门面和实现两个东西,并产生了logback、log4j2、Simple logging等优秀实现,以及适配器、桥接等兼容解决办法,其中的原因,可以参考:
http://www.bryh.cn/a/142979.html
关于log4j2的官方文档,可以到下面的地址做详细阅读。再详尽的攻略,也不如官方文档来得全面、详细。
https://logging.apache.org/log4j/2.x/manual/
本文主要关注实际使用,对slf4j不做讨论。本文适合log4j2扫盲,或是有一定开发经验,但日志总是配置不好的读者做参考。
本文没有涉及log4j2异步日志写入的课题,如果需要考虑异步日志,可以参考下面的链接,有对全异步、部分异步的说明和实际操作。
https://blog.csdn.net/qq_26323323/article/details/124741008
本文最后给出了三个专题,这三个专题也是log4j2要点的一部分,但由于这三个专题各自篇幅都较长,为了尽快讲完主线,故意留在最后。
一、log4j的级别解读
1 8个级别
OFF-第8级,最高等级,虚拟级别,用于关闭所有日志记录。
FATAL-第7级,不可用的致命级别,已被slf4j弃用,官方解释是和ERROR没有绝对的界限。
ERROR-第6级,可用的错误级别,很常用,推荐级别,用于捕获错误事件。
WARN-第5级,可用的告警级别,用得相对较少但位置很关键,表示潜在的可能错误。
INFO-第4级,可用的信息级别,最常用,推荐级别,用于打出程序的关键信息、阶段性的历程碑信息。
DEBUG-第3级,可用的调试级别,详尽的、可用于程序调试的级别,看日志类似看代码的执行过程。
TRACE-第2级,可用的追踪级别,但一般不建议使用,用于极为详尽的step-by-step日志追踪。
ALL-第1级,最低等级,虚拟级别,用于打开所有日志记录。
2 从高到低的理解
这8个级别,最高的OFF和最低的ALL,只在配置文件里当成日志的开关,属于虚拟级别,程序里无法直接使用。
FATAL级别目前已经全线弃用;TRACE级别官方表示不建议用,可能在后续版本中会弃用。因此,在程序中,通过logger.XXXXX使用的,只有从高到低ERROR、WARN、INFO、DEBUG、TRACE五个级别。
理解FATAL、ERROR属于高级别,DEBUG、TRACE属于低级别,对于后面的配置,非常重要。这里可以记成金字塔,ERROR日志较少,处于金字塔顶端,而DEBUG日志很多,处于金字塔底端(越往下塔身越大)。
二、log4j2的配置文件
1 配置文件原理
log4j2的配置文件,暂且还支持.properties格式的古老写法,但功能严重受限,因此任何时候都不推荐再用该方法。目前主要支持的写法为xml、json、yaml。鉴于json和yaml的写法目前还没有被广泛接受,因此本文将全部使用xml格式做讲解。该配置文件的内容,包括node、子node、属性、属性值,都不区分大小写。
log4j2在读取配置文件时,先后顺序是这样的:CLASSPATH下的
log4j2-test.properties
log4j2-test.json
log4j2-test.xml
log4j2.properties
log4j2.json
log4j2.xml
可以明显看出设计意图,优先读取测试环境配置,后读取生产环境配置。本文的讲述,都基于log4j2.xml。
log4j2配置文件设置好后,将由Java程序进行初始化读取,程序对该文件进行加载的过程,将在本文最后一部分论述。
log4j2配置文件中所有的element、属性值、属性名,都不区分大小写,类名、文件、目录名、PatternLayout的字符串区分大小写。
2 起始和Configuration总段落
(1) xml起始
起始段落为固定的写法,注意encoding写为UTF-8
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE xml>
(2) Configuration的属性
status是log4j2本身需要输出的日志级别,一般配置为WARN即可,不需要改动。
monitorInterval是log4j2的重新刷新间隔,这里配置为30,单位是秒,即运行中的程序,每30秒log4j2的线程会重读本配置文件。
<Configuration status="WARN" monitorInterval="30">
(3) Properties段落
这个段落主要用于配置log4j2的属性,更有用的是配置一些变量,用在后面的appenders段落和loggers段落用${VARIABLE}引用。
这里配置日志存放目录、历史日志存放目录、日志文件切换大小、日志保存数量这4个变量。
<Properties>
<Property name="logDir">./logs</Property>
<Property name="histLogDir">./logs/hist</Property>
<Property name="splitSize">10 MB</Property>
<Property name="fileCount">5</Property>
</Properties>
3 appenders段落
Appenders段落是配置文件中内容最多、配置项最长的一段。
Appenders段落中定义了RollingFile以后,启动应用程序,对应的文件会生成。但在定义loggers段落前,这些文件中不会有任何内容写入。
Appenders段落中定义了Console以后,启动应用程序,对应会有控制台输出。即使loggers段落尚未配置,该输出也不受影响。这个和loggers段的默认配置有关,下一节会详细说明。
按照log4j2的官方文档,目前log4j2支持的appender非常多,这里只讲述最基本的Console、File、RollingFile三种,且RollingFile是最常用的,不同级别的日志输出文件的区分也一般通过配置多个RollingFile的appender实现。
(1) Console Appender
Console appender用于定义在控制台输出的日志内容。在开发调试中,输出到cmd、IDE的console中;在tomcat中,输出到catalina.out。下面先给出配置的一个例子。
<Console name="Console" target="SYSTEM_OUT">
<ThresholdFilter level="DEBUG" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
</Console>
Console的定义中,name属性是为该appender起名,后面的loggers段落的AppenderDef里面会引用,target属性只有Console才会用到,这里指向SYSTEM_OUT。
在子element中,ThresholdFilter定义了基本输出的级别,这里的例子给的是DEBUG,onMatch="ACCEPT" onMismatch="DENY"则表示,高于等于DEBUG级别的日志给与输出,低于DEBUG级别的日志不予输出。需要注意的是,这里是第一次定义日志级别,表示“可以输出”的日志,但并不保证最后会在console中输出DEBUG和以上级别的日志,后面会看到loggers段落会有第二次的定义,二者的“交集”才是最终输出的日志级别。关于ThresholdFilter的差异化配置和使用技巧,在专题三中会专门讲。
PatternLayout段落定义每一行输出日志的样式,这里定义的有,先后输出精确到毫秒的日期时间(%d)、线程名(%t)、日志级别(%p)、简写的类路径(%c)、代码行号(%L)、日志的打印信息(%m)、换行符(%n)。关于PatternLayout的输出内容、代号和一些省略、对齐技巧,会在专题一“PatternLayout格式说明”中专门讲。这样配置的PatternLayout,在控制台的输出,会是以下的样子。
2022-12-04 00:28:39.855 [main] ERROR com.zbt.sb002.e.Employee(23) 日志输出,ERROR日志---256,托尼
2022-12-04 00:28:39.862 [main] WARN com.zbt.sb002.e.Employee(24) 日志输出,WARN 日志---256,托尼
2022-12-04 00:28:39.863 [main] INFO com.zbt.sb002.e.Employee(25) 日志输出,INFO 日志---256,托尼
2022-12-04 00:28:39.864 [main] DEBUG com.zbt.sb002.e.Employee(26) 日志输出,DEBUG日志---256,托尼
(2) File Appender
File Appender正如其名,是向文件中输出日志。但该日志文件没有任何分文件的功能,全部往死里输出到一个日志文件。先给出配置的一个例子。
<File name="AllLog" fileName="${logDir}/allinone.log" append="false">
<ThresholdFilter level="ALL" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
</File>
这里的fileName属性,定义输出的日志路径和名字,必须要指定,这里用了之前properties里提前定义的变量logDir。append属性默认是true,表示应用下次启动时,新生成的日志会以追加方式放入该文件,不会覆盖文件中的原有内容。这里故意配成false,是考虑File类型的日志只有一个文件往死输出,会造成该文件无限扩大。设成false后,下次应用启动,该日志会被log4j2的线程先置空再输出新日志。此外这里的ThresholdFilter,level设为ALL,即输出全部日志。
其他的内容与Console完全相同,不再重复解释。输出到allinone.log中的内容,与console中的内容一致。
(3) RollingFile Appender
RollingFile Appender是在File Appender的基础上,增加了日志文件按照时间切分、大小切分,切分后在线日志和历史日志的目录文件区分,以及日志保留数量等一系列进阶的配置。因此RollingFile是log4j2的精华所在,由此可以产生很多灵活的配置变化。下面给出一个典型配置的例子。
<RollingFile name="RollingFileError" fileName="${logDir}/error.log"
filePattern="${histLogDir}/error-%d{yyyy-MM-dd}-%i.log">
<ThresholdFilter level="ERROR" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
<Policies>
<TimeBasedTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="${splitSize}"/>
</Policies>
<DefaultRolloverStrategy max="${fileCount}"/>
</RollingFile>
在RollingFile属性中,相比之前多了filePattern属性,该属性首先配置日志切分后,历史配置的目录和文件名。同时这里fileName属性负责配置在线日志文件的目录和文件名。
Policies节点,配置日志切分的策略,有TimeBasedTriggeringPolicy和SizeBasedTriggeringPolicy,也就是基于时间分文件和基于文件大小分文件两种策略。这两种策略可以同时存在,这时以两个策略谁先到为准。
基于文件大小的策略,需要在属性中配置具体大小,这里使用了之前properties中定义的splitSize变量。
基于时间的策略,没有任何属性,这时会使用filePattern属性中定义的%d{yyyy-MM-dd},也就是按照日期分文件。
和Policies节点节点并列的DefaultRolloverStrategy节点,定义日志到多少个以后可以执行滚动,即过早的历史日志文件执行删除。但像上面的这种只有一句,设置max属性为5的情况,滚动只对文件大小策略有效,对时间策略无效。如果想对时间有效,则需要为DefaultRolloverStrategy节点增加子节点配置,关于这一点,在后面用专题二做单独说明。
在上面的例子中,这个RollingFile配置的级别是ERROR,因此相比前面的Console和File的两个appender,这里只允许输出ERROR及ERROR以上级的日志。error.log中的输出如下。
2022-12-04 00:27:54.451 [main] ERROR com.zbt.sb002.e.Employee(24) 日志输出,ERROR日志---256,托尼
由于ERROR是实际可以使用的最高级别,因此这里只有ERROR级别的日志输出出来。
RollingFile类型的appender可以配置多个,让不同级别的日志分门别类进行输出,比如除了上面的ERROR级别,再配置一个INFO级别的appender,输出INFO及INFO以上级别日志。
<RollingFile name="RollingFileINFO" fileName="${logDir}/info.log"
filePattern="${histLogDir}/info-%d{yyyy-MM-dd}-%i.log">
<ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
<Policies>
<TimeBasedTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="${splitSize}"/>
</Policies>
<DefaultRolloverStrategy max="${fileCount}"/>
</RollingFile>
info.log输出如下。
2022-12-04 00:28:39.855 [main] ERROR com.zbt.sb002.e.Employee(23) 日志输出,ERROR日志---256,托尼
2022-12-04 00:28:39.862 [main] WARN com.zbt.sb002.e.Employee(24) 日志输出,WARN 日志---256,托尼
2022-12-04 00:28:39.863 [main] INFO com.zbt.sb002.e.Employee(25) 日志输出,INFO 日志---256,托尼
可以看到,INFO日志、INFO的两个以上级别WARN和ERROR日志,都出现在了info.log中。目前为止所有的日志文件,都是输出该级别及以上级别的日志,如果想只输出某个单一级别的日志,屏蔽它的以上级别,则需要在ThresholdFilter的onMatch和onMismatch上做文章,详见专题三。
4 loggers段落
loggers段落负责将日志输出到指定预定义好的Appender中。
(1) 必须有的root段
root段是所有日志输出的最终保障,是输出的根控制节点,必须有。
loggers段落全部没有时,或有loggers段但里面root段全部没有时,log4j2默认按照以下模式执行:
<loggers>
<root level="ERROR">
<AppenderRef ref="Console"/>
</root>
</loggers>
按照该默认的模式,只有控制台有ERROR及ERROR以上级别与Console appender定义级别的交集的日志级别输出。这样一来,上面定义的所有RollingFile都将没有意义,即对应的文件会生成,但没有任何日志。因此,loggers段落必须有,且至少应该有root段落。
还要注意,如果定义root段落但里面不给任何AppenderRef定义,则log4j认为用户已经指定root段,默认模式消失,结果就是连Console也不输出任何日志了。综上,loggers->root->若干AppenderRef这一套,在配置文件中必须出现,完整的日志配置才有意义。
下面给出root段完整配置的例子:
<root level="INFO">
<AppenderRef ref="Console"/>
<AppenderRef ref="RollingFileError"/>
<AppenderRef ref="RollingFileInfo"/>
<AppenderRef ref="RollingFileDebug"/>
<AppenderRef ref="RollingFileInfoOnly"/>
</root>
一般来说,凡是上面定义了且想要使用的通用Appender(console、info、error、debug等),在root段中都要以AppenderRef的方式引用,以让Appender有的放矢。
root段落配置好了以后,所有的class中的日志输出,按照上面配置的Console和RollingFile,以及root配置的AppenderRef,进行日志输出。root段落可以定义level属性,写日志时,使用的是该level及以上级别,与Appender中定义级别的交集。因此,这里的level通常用于应用在测试、生产中,日志级别的总控。
(2) 可选的logger段
在loggers中,logger段可以一个都没有,直接使用root做输出是完全可以的。如果需要配置一个或多个logger段,先要保障root段配置好并生效。
logger段的意义在于,给不同package的日志,做输出的定制化,logger中的name、level两个属性,以及AppendRef node,就是做这种定制化。
定制化意义1:
在使用框架和底层轮子时,这些外部包的日志,一般希望不输出太详细(低级别)的日志。
定制化意义1的实现原理:
定义框架和底层库相关包的日志输出级别为较高级别。
定制化意义1的实现:
比如一个框架为org.springframework.,一个轮子为org.mybatis.,分别设立独立的logger,name就是包名的前缀(1-2位),level为ERROR。这样他们只有ERROR及以上级日志可能被写出来。
定制化意义2:
应用自己开发的代码,有时需要日志详细些(低级别),但前面root的level已经做了较高级别总控的前提下,这里有机会给自己的代码开低级别日志。
定制化意义2的实现原理:
定义自己代码相关包的日志输出级别为较低级别。
定制化意义2的实现:
比如自己的代码包都为com.zbt.*,则为之设立独立的logger,name是com.zbt,level为DEBUG。这样自己的代码包,DEBUG及以上级日志都能被写出来。
定制化意义3:
有时会希望轮子的日志,或者自己应用的日志,除了写通用Appender(console、info、error、debug等),还输出到单独日志中来。
定制化意义3的实现原理:
前面先定义好一个特殊的Appender(RollingFile),这里为自己的包定义logger,在logger中写明AppenderRef,指向特殊的Appender。
定制化意义3的实现:
比如自己的代码包都为com.zbt.*,则为之设立独立的logger,name是com.zbt,level按需求就好。为该logger设立AppenderDef,里面指向预定义好的特殊Appender,比如zbt.log。
(3) logger和root的AppenderDef关系
如果说Appenders段的文件和级别定义,root段的级别、AppenderDef定义,相对比较单纯,关联关系也比较简单的话,那么logger段的加入,很大程度使得Appender、root、logger三者交织而复杂了很多。时常出现的配置不达目的,日志输出不出来,日志输出两行等问题,都出自于此,因此理清logger段和root段AppenderDef的关系,以及logger段重要的属性additivity,有着重要意义。
前面在论述root段落时说了,作为输出的保底,root段落一般必须定义多个AppenderDef。下面通过5个case来的结果来做分析:
case1:logger中不定义AppenderDef。这时该logger会直接使用root的AppenderDef,这也是保底输出的由来。这种情况等同于日志级别听从logger,输出日志文件听从root。
case2:logger中定义自己的一个或多个AppenderDef,且该Def(们)与root中的某(些)Def是相同的,则对应的Def的日志中会写入两条。这是日志有重复行问题的由来。
case3:和case2基本相同,但在logger中添加additivity属性,设为false,则由logger的Def写一次日志后,root不再负责写入,日志重复问题解决。additivity属性不设置时默认是true,是重行问题的罪魁祸首。
case4:logger中定义自己的一个或多个AppenderDef,但与root的AppenderDef互不相同。这时可以理解为logger输出到特定日志,root负责将所有(包括该logger的日志)输出到通用的日志中。
case5:和case4基本相同,但在logger中添加additivity属性,设为false,则logger输出到特定日志,root不再负责该logger日志向通用日志输出。
通过这5个case可以基本看出所有的情况:
程序中的日志输出是货物源头,Appender中的定义是货物终点,root是负责兜底的快递员,AppenderDef是运送通道。logger可以是个“甩手”快递员,它可以没有运送通道,只负责过滤货物,这时root依然使用root的通道运送。logger有运送通道时,root和logger各自独立过滤货物,用各自通道各运各的。logger有通道且明确additivity=flase,等于告诉root,我运了的快递,你就不要运了。
理解additivity属性,为true时(默认情况)表示name定义下的日志,除了logger的输出,继续向root传递并由root输出;为false时表示name定义下的日志,只由logger输出,不再向root传递。
理解AppenderRef,只是日志输出的通道,root和logger都可以用,logger没有时用root的。通道重复的时候就输出两次,除非用additivity="false"做屏蔽。
(4) loggers段落demo
root段打印日志的级别为INFO,即输出INFO及INFO以上级别的日志。在这个偏向生产的设定中,root将不向debug日志输出任何内容。
三个没有AppenderRef节点的logger,负责将springframework、mybatis的日志控制在WARN和ERROR级别,由root中引用的Appender进行输出。
最后定义一个应用程序的logger,级别为较低的DEBUG,由自己的AppenderDef进行输出,不再由root输出。且这个logger,除了向Console、Error、Info、Debug四个Appender输出以外,还向专属的ZBT Appender输出。
<loggers>
<logger name="_org.springframework" level="WARN"></logger>
<logger name="org.springframework" level="WARN"></logger>
<logger name="org.mybatis" level="ERROR"></logger>
<logger name="com.zbt.sb002" level="DEBUG" additivity="false">
<AppenderRef ref="Console"/>
<AppenderRef ref="RollingFileError"/>
<AppenderRef ref="RollingFileInfo"/>
<AppenderRef ref="RollingFileDebug"/>
<AppenderRef ref="RollingFileZBT"/>
</logger>
<root level="INFO">
<AppenderRef ref="Console"/>
<AppenderRef ref="RollingFileError"/>
<AppenderRef ref="RollingFileInfo"/>
<AppenderRef ref="RollingFileDebug"/>
</root>
</loggers>
三、程序调用log4j2
目前流行的logback、log4j2,都是基于slf4j的实现,这里给出使用log4j2实现slf4j的代码和相关配置
1 spring框架pom.xml引入log4j2
springboot中默认的是logback,如果要用log4j2,需要在pom.xml中,排除logback,加入log4j2。
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter</artifactId>
<!-- springboot默认用的logback日志框架,排除后面单配log4j2 -->
<exclusions>
<exclusion>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-logging</artifactId>
</exclusion>
</exclusions>
</dependency>
<!-- 引入log4j2依赖 -->
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>
2 原生Java代码引入log4j2
将以下4个jar包放入CLASSPATH:
slf4j-api-1.7.36
log4j-slf4j-impl-2.17.2
log4j-core-2.17.2
log4j-api-2.17.2
3 代码中定义slf4j的logger
给出本攻略中一直在用的代码
package com.zbt.sb002.entity;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class Employee {
private Integer empID;
private String empName;
private static final Logger logger = LoggerFactory.getLogger(Employee.class);
public Employee(Integer empID, String empName) {
this.empID = empID;
this.empName = empName;
}
@Override()
public String toString() {
return (this.empID +","+this.empName);
}
public void print(String output) {
logger.error("日志输出,ERROR日志---{}", output);
logger.warn ("日志输出,WARN 日志---{}", output);
logger.info ("日志输出,INFO 日志---{}", output);
logger.debug("日志输出,DEBUG日志---{}", output);
logger.trace("日志输出,TRACE日志---{}", output);
}
public static void main(String[] args) {
Employee employee = new Employee(256, "托尼");
employee.print(employee.toString());
}
}
log4j2是slf4j的实现,因此在代码的import中,只需要import slf4j的class即可。
4 DEBUG、TRACE日志在代码中的注意
鉴于这两个低级别日志数量比较多,所以编码中需要注意,如果logger.debug和logger.trace使用很多且集中,则应当用下面的代码做“包裹”,以提升运行效率。
if(logger.isDebugEnabled()) {
logger.debug("日志输出,DEBUG日志---{}", output);
}
if(logger.isTraceEnabled()) {
logger.trace("日志输出,TRACE日志---{}", output);
}
这样写了以后,如果日志级别比DEBUG高,则执行时,logger.debug这一行不会被执行。否则,即便日志级别比DEBUG高,按照log4j2的处理原理,这一行代码是需要执行的,即进行了字符串拼接操作,只是最终没有输出到日志文件中而已。
5 使用占位符而非加号做拼接
不推荐的写法:
logger.debug("日志输出,DEBUG日志---" + name + "的任务是" + task);
推荐的写法:
logger.debug("日志输出,DEBUG日志---{}的任务是{}", name, task);
使用占位符,一次性拼接字符创,让处理效率更高,代码可读性也更好。
6 捕获异常的错误日志
有了log4j2后,对于捕获的异常,应当用Logger.error(String msg, Throwable t),输出ERROR级别日志,并打印stacktrace。
先看一段正确的代码:
package com.zbt.sb002.entity;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class TestException {
private static final Logger logger = LoggerFactory.getLogger(TestException.class);
private static int getStringLength(String str) {
try {
int length = str.length(); //这里会有空指针异常
logger.info("字符串长度为:{}", length);
return length;
}catch(Exception e) {
logger.error(e.getMessage(),e);
return -1;
}
}
public static void main(String[] args) {
getStringLength(null);
}
}
正确的日志输出:
2022-12-04 16:45:39.537 [main] ERROR com.zbt.sb002.e.TestException(16) Cannot invoke "String.length()" because "str" is null
java.lang.NullPointerException: Cannot invoke "String.length()" because "str" is null
at com.zbt.sb002.entity.TestException.getStringLength(TestException.java:12) ~[classes/:?]
at com.zbt.sb002.entity.TestException.main(TestException.java:22) ~[classes/:?]
从这个在error.log的输出可以看出,使用了logger.error(e.getMessage(),e);后,在日志中既有ERROR级别日志(第一行),又有抛出异常的stacktrace(第二行),是完备的。这里很容易犯的是一个错误,代码的第15行按照习惯性的方式写为:
//错误!
e.printStackTrace();
这样写,在error.log中,没有任何输出,在控制台中会将异常的stacktrace进行打印,使得最关键的错误信息反而在日志中丢失。
还有一种作者认为不好的写法是,使用单个参数的logger.error(String msg)进行打印,写法如下
//写得不好
logger.error(e.getMessage());
这样写在日志中只有一行,不输出stacktrace:
2022-12-04 16:56:53.113 [main] ERROR com.zbt.sb002.e.TestException(16) Cannot invoke "String.length()" because "str" is null
这样的缺点是只看ERROR信息,没有stacktrace,信息不全,不利于查错判断。
四、一个完整的log4j2.xml
给出一个笔者认为比较完备的log4j2的配置文件,供读者参考。应当指明的是,完备不等于完美,这个配置中输出的日志文件定义较多,级别总体偏低,没有使用异步appender,从性能上讲是不太合适的,但这样又展示了较为全面的log4j2配置。百度上有很多所谓完美的配置,笔者不能认可,完美的配置一定是均衡考虑日志可读、日志量、运行性能、日志管理使用需求等多方面得出的,用一app一配置来形容一点不为过。因此只有对某一应用程序完美的配置,不存在通用的完美配置。
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE xml>
<Configuration status="WARN" monitorInterval="30">
<Properties>
<Property name="logDir">./logs</Property>
<Property name="histLogDir">./logs/hist</Property>
<Property name="splitSize">10MB</Property>
<Property name="fileCount">5</Property>
</Properties>
<Appenders>
<!-- Appender1 Console -->
<Console name="Console" target="SYSTEM_OUT">
<ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
</Console>
<!-- Appender2 File -->
<File name="AllLog" fileName="${logDir}/allinone.log" append="false">
<ThresholdFilter level="ALL" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
</File>
<!-- Appender3 RollingFile:Error -->
<RollingFile name="RollingFileError" fileName="${logDir}/error.log"
filePattern="${histLogDir}/error-%d{yyyy-MM-dd}-%i.log">
<ThresholdFilter level="ERROR" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
<Policies>
<TimeBasedTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="${splitSize}"/>
</Policies>
<DefaultRolloverStrategy max="${fileCount}"/>
</RollingFile>
<!-- Appender4 RollingFile:Info -->
<RollingFile name="RollingFileInfo" fileName="${logDir}/info.log"
filePattern="${histLogDir}/info-%d{yyyy-MM-dd}-%i.log">
<ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
<Policies>
<TimeBasedTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="${splitSize}"/>
</Policies>
<DefaultRolloverStrategy max="${fileCount}"/>
</RollingFile>
<!-- Appender5 RollingFile:Debug -->
<RollingFile name="RollingFileDebug" fileName="${logDir}/debug.log"
filePattern="${histLogDir}/debug-%d{yyyy-MM-dd}-%i.log">
<ThresholdFilter level="DEBUG" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
<Policies>
<TimeBasedTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="${splitSize}"/>
</Policies>
<DefaultRolloverStrategy max="${fileCount}"/>
</RollingFile>
<!-- A special RollingFile1: InfoOnly -->
<RollingFile name="RollingFileInfoOnly" fileName="${logDir}/infoonly.log"
filePattern="${histLogDir}/infoonly-%d{yyyy-MM-dd}-%i.log">
<Filters>
<ThresholdFilter level="WARN" onMatch="DENY" onMismatch="NEUTRAL"/>
<ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
</Filters>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
<Policies>
<TimeBasedTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="${splitSize}"/>
</Policies>
<DefaultRolloverStrategy max="${fileCount}"/>
</RollingFile>
<!-- A special RollingFile2: ZBT -->
<RollingFile name="RollingFileZBT" fileName="${logDir}/zbt.log"
filePattern="${histLogDir}/zbt-%d{yyyy-MM-dd}-%i.log">
<ThresholdFilter level="DEBUG" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
<Policies>
<TimeBasedTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="${splitSize}"/>
</Policies>
<DefaultRolloverStrategy max="${fileCount}"/>
</RollingFile>
</Appenders>
<Loggers>
<Logger name="_org.springframework" level="WARN"/>
<Logger name="org.springframework" level="WARN"/>
<Logger name="org.mybatis" level="ERROR"/>
<Logger name="com.zbt.sb002" level="DEBUG" additivity="false">
<AppenderRef ref="Console"/>
<AppenderRef ref="AllLog"/>
<AppenderRef ref="RollingFileError"/>
<AppenderRef ref="RollingFileInfo"/>
<AppenderRef ref="RollingFileDebug"/>
<AppenderRef ref="RollingFileInfoOnly"/>
<AppenderRef ref="RollingFileZBT"/>
</Logger>
<Root level="INFO">
<AppenderRef ref="Console"/>
<AppenderRef ref="AllLog"/>
<AppenderRef ref="RollingFileError"/>
<AppenderRef ref="RollingFileInfo"/>
<AppenderRef ref="RollingFileDebug"/>
<AppenderRef ref="RollingFileInfoOnly"/>
</Root>
</Loggers>
</Configuration>
专题一、PatternLayout格式说明
对PatternLayout中,pattern属性做出参数说明。PatternLayout将决定每一行日志打出的内容和格式,对于让日志清晰可读有着重要作用。在实际使用中,应注意日志行打印内容的长度和内容全面性的关系,适当控制长度,对于日志的可读性,有很大的帮助。
(a)%d,输出日期和时间,{}中可以格式化,格式化与java.text.SimpleDateFormat中的参数相同,一般配置为yyyy-MM-dd HH:mm:ss.SSS即可。
(b)%t,输出线程(thread)编号,若要限制线程编号的字符长度,可在%和t之间做位数限制。例如正常输出是[main],经过配置可有以下变化。
编号 | 写法 | 输出 | 说明 |
---|---|---|---|
1 | [%t] | [main] | 标准输出,输出线程完整的名字 |
2 | [%3t] | [main] | 从右算起,最少输出三个字符,多了不限,由于main是四个字符,因此全部输出 |
3 | [%8t] | [ main] | 从右算起,最少输出八个字符,多了不限,于是出现左边补空格 |
4 | [%-3t] | [main] | 从左算起,最少输出三个字符,由于main是四个字符,因此全部输出 |
5 | [%.3t] | [ain] | 从右算起,最多输出三个字符,其余被截掉 |
6 | [%.8t] | [main] | 从右算起,最多输出8个字符,其余被截掉,由于main只有四个字符,因此全部输出 |
7 | [%5.8t] | [ main] | 从右算起,最少输出5个字符,最多输出8个字符,<5则左补空格,>8则左边的截断 |
8 | [%2.3t] | [ain] | 从右算起,最少输出2个字符,最多输出3个字符,<2则左补空格,>3则左边的截断 |
9 | [%2.2t] | [in] | 从右算起,固定输出2个字符,即<=2且>=2,那么就是=2,不足2个左补空格,多余2个左边截断 |
10 | [%-2.3t] | [ain] | 从左算起,最少输出2个字符,最多输出3个字符,<2则右补空格,>3则左边的截断 |
11 | [%-2.3t] | [mai] | 从左算起,最少输出2个字符,最多输出3个字符,<2则右补空格,>3则右边的截断 |
12 | [%-2.-8t] | [main] | 从左算起,最少输出2个字符,最多输出8个字符,<2则右补空格,>8则右边的截断 |
13 | [%-8.-8t] | [main ] | 从左算起,固定输出8个字符,<8右边补空格,>8右边的截断 |
这里比较绕,原理就是一个数字的时候,正数表示从右算起(左边截或补),负数表示从左算(右边截或补),最少输出的字符数(最多不限)。数字前面加一个英文句号,表示最多输出的字符数(最少不限)。两个数字的时候,用num1.num2表示,num1表示最小字符数,num2表示最多字符数,二者取交集;这两个数,可以都为正,可以都为负,也可以一正一负,正负号这时表示该数字不满足时,对向截或补。不止是%t,其他任何觉得过长需要截断、过短需要补齐的参数,都可以按此方法配置长度。
这种限制输出,最有用的是[%-8.-8t],即-num1.-num1方式,这就把线程名字限定在了固定的输出长度,实际长度小于num1,则右补空格,大于num1则右边过长部分截掉。这样就保证了线程名输出可以行与行对齐,方便看日志。这里给出实际效果的例子。
2022-12-04 01:35:31.555 [main ] ERROR com.zbt.sb002.e.Employee(23) 日志输出,ERROR日志---256,托尼
2022-12-04 01:35:31.563 [main ] WARN com.zbt.sb002.e.Employee(24) 日志输出,WARN 日志---256,托尼
2022-12-04 01:35:31.564 [main ] INFO com.zbt.sb002.e.Employee(25) 日志输出,INFO 日志---256,托尼
2022-12-04 01:35:31.565 [main ] DEBUG com.zbt.sb002.e.Employee(26) 日志输出,DEBUG日志---256,托尼
(c) %p,输出日志的级别(priority),这个是一定要有的。上面的所有例子中,都用了%-5p的写法,表示最少输出5个字符,多了不限,不足5个右补空格。再次观察从高到低ERROR、WARN、INFO、DEBUG、TRACE五个级别,不是4个字符就是5个,这样就使得在日志级别这里又可以做到对齐了。上一个输出的例子中可以看到这样做的效果。
(d) %c,打印CLASS,这里指的是该CLASS加上package名称的全名,如com.zbt.sb002.entity.Employee。这个名字有时相对较长,为了减少输出,通常需要做简写。这里以com.zbt.sb002.entity.Employee的全名为例,列出简写的几种方式。
编号 | 写法 | Class输出 | 说明 |
---|---|---|---|
1 | %c | com.zbt.sb002.entity.Employee | 正常输出package+class的全名 |
2 | %c{1} | Employee | 输出从右算起的1个名字 |
3 | %c{3} | sb002.entity.Employee | 输出从右算起的3个名字 |
4 | %c{10} | com.zbt.sb002.entity.Employee | 输出从右算起的10个名字(这里完全显示) |
5 | %c{-1} | zbt.sb002.entity.Employee | 从左边算起截掉1个名字 |
6 | %c{-3} | entity.Employee | 从左边算起截掉3个名字 |
7 | %c{-5} | com.zbt.sb002.entity.Employee | 从左边算起截掉5个名字(但这里一共只有5个,不可以全截,因此-5失效) |
8 | %c{-10} | com.zbt.sb002.entity.Employee | 从左边算起截掉10个名字(但这里一共只有5个,不可以全截,因此-10失效) |
9 | %c{.} | ....Employee | 除去最后一个名字,其他的都用.表示,这样只打印了package深度和最后的CLASS |
10 | %c{1.} | c.z.s.e.Employee | 除去最后一个名字,其他的名字都只显示1个起始字母 |
11 | %c{2.} | co.zb.sb.en.Employee | 除去最后一个名字,其他的名字都只显示2个起始字母 |
12 | %c{5.1} | com.z.s.e.Employee | 第一个名字最多显示5个字符,后面每个显示1个字符,最后一个显示全名 |
13 | %c{5.2} | com.zb.sb.en.Employee | 第一个名字最多显示5个字符,后面每个最多显示2个字符,最后一个显示全名 |
14 | %c{5.4.1} | com.zbt.s.e.Employee | 第一个名字最多显示5个字符,第二个最多4个字符,后面每个显示1个字符,最后一个显示全名 |
15 | %c{.1} | .z.s.e.Employee | 第一个名字显示0个字符,后面每个显示1个字符,最后一个显示全名 |
16 | %c{.2} | .zb.sb.en.Employee | 第一个名字显示0个字符,后面每个显示2个字符,最后一个显示全名 |
17 | %c{5.2.~} | com.zb...Employee | 第一个名字最多显示5个字符,第二个最多2个字符,后面用~代替,直到最后一个显示全名 |
18 | %c{-.2.2.~} | -.zb.sb.~.Employee | 第一个名字以-代替,第二、三个最多2个字符,后面用~代替,直到最后一个显示全名 |
19 | %c{-2.2.~} | -.zb...Employee | 第一个名字以-代替,表达式-后面的2不被解析,第二位最多2个字符,后面用~代替,直到最后显全名 |
大括号里的表达式,叫做precision,总体原则是无论怎么缩减,最后一个名字即类的短名必须保留。除此以外可以看到前8个表达方法非常清晰,正数表示右起保留的个数,负数表示左起去除的个数。9-11的表达式是正数加上点,表示除类短名,其他所有只显示正数这么多个字符。12-14的表达式是A.B.C的形式,开始变得复杂,A、B都是表示第一个、第二个,以此类推,但最后一个正数表示后面的都以几个字符打印。15-19在官方手册中也没说清楚,但通过试验可以基本看到数字和点的解析规则。这里放上log4j2官方文档中对于这种复杂情况,不那么详细的解释:
If the precision contains any non-integer characters, then the layout abbreviates the name based on the pattern. If the precision integer is less than one, the layout still prints the right-most token in full. By default, the layout prints the logger name in full.
了解详情,可以参考:https://logging.apache.org/log4j/2.x/manual/layouts.html。
实际使用中,有些类,尤其是框架的类,全名特别的长,这里就要在长度控制和类名完整可读之间做个取舍。一般建议前两位或前三位尽量打印完整,好能看到该类的大致所属,再往后的打印1-2个字符作为提示,最后的类短名保证输出即可。以前三位打印完整为例,应该的写法是:%c{9.9.9.1},输出为:
2022-12-04 11:30:12.711 [main] ERROR com.zbt.sb002.e.Employee(Employee.java:23) 日志输出,ERROR日志---256,托尼
2022-12-04 11:30:12.718 [main] WARN com.zbt.sb002.e.Employee(Employee.java:24) 日志输出,WARN 日志---256,托尼
2022-12-04 11:30:12.719 [main] INFO com.zbt.sb002.e.Employee(Employee.java:25) 日志输出,INFO 日志---256,托尼
2022-12-04 11:30:12.720 [main] DEBUG com.zbt.sb002.e.Employee(Employee.java:26) 日志输出,DEBUG日志---256,托尼
(e) %F、%L,输出日志的文件名和行数,这两个很多时候搭配使用,因此一起讲。比如上面的例子中,类全名是com.zbt.sb002.e.Employee,对应的文件是Employee.java,打印语句的行数是第23行,因此(%F:%L)的写法显示为:(Employee.java:23)。但是从上面的打印也可以看出,当类全名显示完整的情况下,再打印文件名,有冗余,因此可以考虑只使用%L:
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
打印效果如下:
2022-12-04 11:36:20.035 [main] ERROR com.zbt.sb002.e.Employee(23) 日志输出,ERROR日志---256,托尼
(f) %M,输出方法名称,可结合上面的%c、%F、%L一起使用
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%F,%M(),%L) %m%n"/>
打印效果如下:
2022-12-04 16:02:12.344 [main] ERROR com.zbt.sb002.e.Employee(Employee.java,print(),23) 日志输出,ERROR日志---256,托尼
(g) %l,即小写的L,是%c、%M、%F、%L的综合体,属于简便配置方法,但不支持类全名的缩写
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %l %m%n"/>
使用%l等价于
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c.%M(%F:%L) %m%n"/>
打印效果如下:
2022-12-04 11:47:52.855 [main] ERROR com.zbt.sb002.entity.Employee.print(Employee.java:23) 日志输出,ERROR日志---256,托尼
因此,笔者认为%c和%L的组合,是最简便、且信息充足的输出方式。
(h) %m%n输出日志内容并换行,这个基本是固定的写法,缺一不可。
(i)在PatternLayout中,对于需要做转义的被占关键字,用两个反斜杠输出\,用两个百分号输出%。
最后,给出笔者认为比较完备但又简洁的写法:
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
专题二、Rollover策略和基于时间的历史日志删除
log4j2提供了异常丰富且不容易理解的Rollover策略,从2.5的版本开始,还增加了强力删除策略作为Rollover时候的引申触发功能。应当认为理解Rollover策略是理解log4j2做日志滚动、日志删除,并在运维中规划好日志存放空间的关键。
在一开始必须要意识到的是,Rollover,即“滚过”,新陈代谢,但不意味着日志一定会被删除。是否会删除要通过TimeBased、SizedBased、filePattern的%i参数和DefaultRolloverStrategy做综合评判。这一段对Rollover策略的讲述,将使用分析的方法,给出各种情况的配置以及分析出各种情况Roll和Rollover的触发,日志文件的滚动变化,但不会给出与代码相关的操作例子。
先看一个前面配置过的RollingFile的配置,为了更加直观,这里不再引用环境变量,而是将splitSize和fileCount直接给数值。
<RollingFile name="RollingFileINFO" fileName="${logDir}/info.log" filePattern="${histLogDir}/info-%d{yyyy-MM-dd}-%i.log">
<ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
<Policies>
<TimeBasedTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="10M"/>
</Policies>
<DefaultRolloverStrategy max="5"/>
</RollingFile>
在这个配置中,同时存在TimeBasedTriggeringPolicy(简称Time)和SizeBasedTriggeringPolicy(简称Size)。两个policy,谁先到,都会触发一次rollover。这里先简化一下,假定只有Size和只有Time,分析一下rollover策略。
A. Only SizeBasedTriggeringPolicy
只用日志大小做rollover,这样RollingFile的配置可以简化为下面的样子:
<RollingFile name="RollingFileINFO" fileName="${logDir}/info.log" filePattern="${histLogDir}/info-%i.log">
<ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
<Policies>
<SizeBasedTriggeringPolicy size="10M"/>
</Policies>
<DefaultRolloverStrategy max="5"/>
</RollingFile>
这里需要注意,如果只用Size,那么filePattern中,历史日志名字应该不带日期,以防阅读日志文件的人产生误解。对应的历史日志名字应指定%i,这个变量不但是文件名的一部分,还会指导后面的rollover。Size明确了10MB一个文件,也就是每当在线日志大小写满10MB的时候,将触发一次rollover,在线日志变成历史日志,同时创建一个新的空的在线日志。以此类推,直至发生了5次rollover,历史日志数量达到5个(info-1.log至info-5.log)。这时在线日志再次写满10MB,再次触发rollover,在线日志变为info-1.log,1变2,2变3……4变5,老的5则因为DefaultRolloverStrategy配置了max为5,而rollover的时候找到了1-5这5个历史日志,故老5号被删除。这种是最简单的情况,日志也确实按照预想实现了仅保留1个在线和5个历史,RolloverStrategy生效。
B. Only TimeBasedTriggeringPolicy
只用时间做rollover,配置可以简化为下面的样子:
<RollingFile name="RollingFileINFO" fileName="${logDir}/info.log" filePattern="${histLogDir}/info-%d{yyyy-MM-dd}.log">
<ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
<Policies>
<TimeBasedTriggeringPolicy/>
</Policies>
<DefaultRolloverStrategy max="5"/>
</RollingFile>
只用时间的时候,filePattern中日志名字最好不带%i,以免让人产生误解。就算是带了%i,比如前面的格式化时间为每天,则每天产生的历史日志只会有且仅有yyyy-MM-dd-1.log这个名字,不会出现yyyy-MM-dd-2.log等。在上面的例子中,每天一个日志,则当每天时钟过了0点,下一次有日志写入的时候,触发一次rollover,在线日志不论大小,都会变为新一天的时间戳,同时创建一个新的空的在线日志。以此类推,带时间戳的历史日志会一直排布下去,由于没有%i指定的历史日志为5号的名字,所以DefaultRolloverStrategy中的5没有效果,一直没有被触发,以时间戳命名的历史日志会越来越多,不会被删除。这就和直观想象产生了不同,即只用时间做rollover,DefaultRolloverStrategy在现有的简单的只有一个max=5的情况下,做不到1个在线5个历史。
多说一句,这里filePattern主要有以下五种基本切分,从每年一分,到每分钟一分,当然最常用的还是每天一分。但无论哪种,到点会触发Rollover,但历史日志不删且会越来越多。
年分日志:filePattern="${histLogDir}/info-%d{yyyy}.log"
月分日志:filePattern="${histLogDir}/info-%d{yyyy-MM}.log"
日分日志:filePattern="${histLogDir}/info-%d{yyyy-MM-dd}.log"
时分日志:filePattern="${histLogDir}/info-%d{yyyy-MM-dd-HH}.log"
分分日志:filePattern="${histLogDir}/info-%d{yyyy-MM-dd-HH-mm}.log"
有了这两种单纯情况的分析,再回过头来看Size和Time共存的情况。
C. Both SizeBasedTriggeringPolicy and TimeBasedTriggeringPolicy
<RollingFile name="RollingFileINFO" fileName="${logDir}/info.log" filePattern="${histLogDir}/info-%d{yyyy-MM-dd}-%i.log">
<ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
<Policies>
<TimeBasedTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="10M"/>
</Policies>
<DefaultRolloverStrategy max="5"/>
</RollingFile>
注意这里的filePattern需要同时指定%d{yyyy-MM-dd}和%i,%d用于Time切分,%i用于Size切分。前面讲了,同时设置,谁先到谁触发一次rollover。以上面配置中的size按照10MB分,time按照每天分,max为5为例,这里需要考虑两种情况。
情况1,每天的info日志量很大,短时间会突破10MB,一天内会突破50MB,则在0点以前,Time没有机会触发rollover,Size频繁触发rollover,且到5次以后,第6次触发的rollover会对当日的最老一个历史日志做删除。之后会有在线日志和当天日期yyyy-MM-dd-1至yyyy-MM-dd-5这5个历史日志不停地触发rollover。0点过后,Time触发rollover,历史日志保留yyyy-MM-dd-1至yyyy-MM-dd-5,新一天的日志写入在线日志,并很快继续触发新一天的rollover,到了第六次rollover的时候挨次删除最老的,长此以往。
情况2,每天的info日志量不大,一天内不会突破50MB,size有可能触发rollover(10MB<size<50MB)但不会删除文件,到了0点Time触发rollover也不删除文件,第二天继续size触发rollover或干脆不触发,到0点time触发rollover,长此以往。
综上,情况1由size触发rollover并删除老的历史日志,每天的日志实际是不完整的,当日日志量可控但时间上的日志会越来越多;情况2 size触发rollover但不删文件,time也触发rollover但不删文件,日志完整,但时间上的日志也会越来越多。
从分析完成的A、B、C三种策略的结果已经可以看出,DefaultRolloverStrategy max="5",实际只对size生效,对time根本无效。因此只要使用了time(B、C两种配置),要想控制住日志总量,必须想别的办法。
log4j2的作者应该是考虑到了这个问题,从2.5版本开始,为DefaultRolloverStrategy增加了Delete这个action,专门用于删除使用了time的早期历史日志,解决日志越积越多的问题。这里基于C的配置,给出带Delete的DefaultRolloverStrategy。
D. Both SizeBasedTriggeringPolicy and TimeBasedTriggeringPolicy, but with Delete action
<RollingFile name="RollingFileDebug" fileName="${logDir}/debug.log"
filePattern="${histLogDir}/debug-%d{yyyy-MM-dd}-%i.log">
<ThresholdFilter level="DEBUG" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
<Policies>
<TimeBasedTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="10M"/>
</Policies>
<DefaultRolloverStrategy max="5">
<Delete basePath="${histLogDir}" maxDepth="1">
<IfFileName glob="debug*.log" />
<IfLastModified age="P30D" />
</Delete>
</DefaultRolloverStrategy>
</RollingFile>
相比之前C的配置,只是在DefaultRolloverStrategy中加入Delete节点,其他不变。basePath为历史日志所在的目录,maxDepth=1表示删除范围仅限这一级目录,如果设为2,则会除了看历史目录,还看里面的一级子目录。后面给了两个If条件,两个是且的关系。
IfFileName,给出删除文件的文件名描述。
IfLastModified,给出删除文件在什么样的时间以前的,会被删除。这里可以支持的表达式为log4j2 API中的Duration类中的sequence定义,这里直接给出官网给的例子,很清晰:
"PT20S" -- parses as "20 seconds"
"PT15M" -- parses as "15 minutes" (where a minute is 60 seconds)
"PT10H" -- parses as "10 hours" (where an hour is 3600 seconds)
"P2D" -- parses as "2 days" (where a day is 24 hours or 86400 seconds)
"P2DT3H4M" -- parses as "2 days, 3 hours and 4 minutes"
在D的配置示例中,给的是P30D,即删除30天以前的老历史日志。
配置了delete以后,当time的rollover任意触发时,都会查找指定的basePath下,符合两个If条件的历史日志,无论是time的rolllover生成的,还是size的rollover生成的,甚至是人放进去的或者其他程序放进去的,只要查到了,就会执行delete。同时,DefaultRolloverStrategy max="5"依然约束着每天的size总量,每天生成不超过5x10MB,保留30天,故历史日志最大总size为5x10MBx30=1.5GB。
Delete action的加入,终于解决了多年以来,基于time生成历史日志,越积越多的问题。同时也要注意,这个Delete删除只认文件名和时间,如果用,请务必保持历史日志目录的干净,别放其他东西。
专题三、技巧-只输出一个级别的日志
前面讲到Console Appender、RollingFile Appender的时候,日志级别对应的实际打印内容,都是打印该级别和以上级别的日志。那么如果我们需要只打印一个级别,例如只打印INFO级别的日志,INFO的以上级WARN和ERROR不打印,该怎么配置呢?这里就要用到ThresholdFilter的灵活配置了。
以开始时候,Console段落的配置为起点:
<Console name="Console" target="SYSTEM_OUT">
<ThresholdFilter level="DEBUG" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
</Console>
其他内容都不变,只把leve调整成INFO:
<Console name="Console" target="SYSTEM_OUT">
<ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
</Console>
打印的内容如下,确实按照既定计划,将INFO及INFO以上级的日志全部打印了。
2022-12-04 11:59:27.776 [main] ERROR com.zbt.sb002.e.Employee(23) 日志输出,ERROR日志---256,托尼
2022-12-04 11:59:27.782 [main] WARN com.zbt.sb002.e.Employee(24) 日志输出,WARN 日志---256,托尼
2022-12-04 11:59:27.783 [main] INFO com.zbt.sb002.e.Employee(25) 日志输出,INFO 日志---256,托尼
如果只想打印INFO这一个级别,那么需要引入Filters节点,对ThresholdFilter做多级配置:
<Console name="Console" target="SYSTEM_OUT">
<Filters>
<ThresholdFilter level="WARN" onMatch="DENY" onMismatch="NEUTRAL"/>
<ThresholdFilter level="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
</Filters>
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5p %c{9.9.9.1}(%L) %m%n"/>
</Console>
先展开讲一下ThresholdFilter中的onMatch和onMismatch的原理。
onMatch表示符合的,也就是该级别及以上级(>=)。
onMismatch表示不符合的,也就是该级别以下级(<)。
onMatch和onMismatch都有三种值:ACCEPT、DENY和NEUTRAL,表示符合或不符合的日志如何处理。
ACCEPT表示接受,即可以输出。
DENY表示拒绝,即不可输出。
NEUTRAL类似于弃权,也就是本ThresholdFilter不做处理,留给下一个ThresholdFilter处理。
有了原理,当面对只想打印INFO这一个级别这一需求,就可以灵活做配置了。在INFO的ThresholdFilter之上,先处理INFO上一个级别,也就是用一个额外的ThresholdFilter对WARN级别进行处理,onMatch的,也就是WARN和WARN以上级别,都拒绝,而WARN以下级别,包括INFO,都用onMismatch="NEUTRAL"留给下面INFO的ThresholdFilter处理。到了INFO这一层,onMatch的设为接受,onMismatch的设为拒绝,这时的接受内容,已经仅剩下INFO自己这一个级别了。这样打出的日志如下:
2022-12-04 12:14:30.074 [main] INFO com.zbt.sb002.e.Employee(25) 日志输出,INFO 日志---256,托尼
综上,通过配置两级ThresholdFilter,巧妙地实现了只打印一个级别的日志。
标签:输出,级别,攻略,Employee,日志,log4j2,logger From: https://www.cnblogs.com/bmwhero/p/16951505.html