2019-08-27更新:TimeBasedRollingPolicy 策略下无法归档error日志。
问题描述:logback.xml文件里配置了按日转换日志文件,文件有info文件,error文件,但是在日志归档系统里查找,只能找到info文件,并没有error文件
排查过程:首先排查了扫描日志的脚本,大致逻辑是:当天是0827,那么扫描2019-08-26后缀的日志文件;确认是没有问题的。
然后进入一台线上机器,很巧发现了一个error日志,更新时间是0826的20:21,但是并没有分割成2019-08-26后缀的日志文件。那么猜测应该是logback的配置问题。
受 logback 指定每隔一段时间创建一个日志文件 文章的启发,去看了TimeBasedRollingPolicy策略的源码。时间分隔的策略是按照配置中的%d{yyyy-MM-dd} 的pattern来判断,文件分隔的时间是每分钟,还是每小时,每天。yyyy-MM-dd就是每天,yyyy-MM-dd-HH-mm就是每分钟。间隔的步长是1,固定的,如果想要实现比如每2个小时这种需求,要像参考文档一样去继承实现。但是参考文章中的配置类标签timeBasedFileNamingAndTriggeringPolicy,我没试验过是否可行,这个应该不是默认的标签,idea中没有自动跳出来。
那么回到我上面的问题,时间的判断是没有问题的,那么问题就出现在什么时候判断,通过查看源码,发现RollingFileAppender只有在写入文件内容的时候,才调用policy的isTriggeringEvent方法来判断是否分割的。
/**
* This method differentiates RollingFileAppender from its super class.
*/
@Override
protected void subAppend(E event) {
// The roll-over check must precede actual writing. This is the
// only correct behavior for time driven triggers.
// We need to synchronize on triggeringPolicy so that only one rollover
// occurs at a time
synchronized (triggeringPolicy) {
if (triggeringPolicy.isTriggeringEvent(currentlyActiveFile, event)) {
rollover();
}
}
super.subAppend(event);
}
那就很坑了,如果27号白天,在日志扫描归档任务之前,没有任何error日志产生,2019-08-26的分割文件就不会生成,等到扫描之后生成的话,就要等到下一周期的日志归档任务,但是下一次又只会扫描2019-08-27的分割日志,所以26号的分割日志就被遗漏了,但是info日志因为基本上每天都会有,所以info日志基本都是能被归档到。
2019-02-19更新
线上排查问题时,并发情况下日志混杂比较难查问题,可以通过在日志中使用MDC的方式,在每条日志中后面加上一个唯一标识,同一个请求的日志使用相同的唯一标识,在筛选日志时比较方便
1、logback是什么:
我的理解中,logback配置文件就是一切关于日志要求的配置信息的总和。
SLF4J(Simple logging facade for Java)是一种抽象的接口定义,当我们在logback配置文件中设置了我们关于日志的要求,采用不同的日志实现组件的时候,只要加载对应jar包即可。替换也只要替换相应的jar包,不需要对程序做其他的改动。
2、logback中三个重要的标签
Logger: 日志记录器,把它关联到应用对应的context上后,主要用于存放日志对象,定义日志类型,级别。
Appender: 指定日志输出的目的地,目的地可以是控制台,文件,或者数据库等
Layout: 负责把事件转换成字符串,格式化日志信息的输出
3、配置文件的加载顺序
1)logback首先在classpath寻找logback.groovy文件,
2)如果没找到,继续寻找logback-test.xml文件
3)如果没找到,继续寻找logback.xml文件
4)如果仍然没找到,则使用默认配置(打印到控制台)
4、logback实例解析(自己学习的时候总结的还算全面的一个例子)
<?xml version="1.0" encoding="UTF-8"?>
<!-- scan:当此属性设置为true时,配置文件如果发生改变,将会被重新加载,默认值为true。-->
<!--scanPeriod: 设置监测配置文件是否有修改的时间间隔,如果没有给出时间单位,默认单位是毫秒。当scan为true时,此属性生效。默认的时间间隔为1分钟。-->
<!--debug: 当此属性设置为true时,将打印出logback内部日志信息,实时查看logback运行状态。默认值为false-->
<configuration debug="false" scan="true">
<!--contextName:工程名-->
<contextName>LogbackDemo</contextName>
<!--property:变量值,在后续配置中以${log.dir}的方式引用-->
<property name="log.dir" value="E:\logs\" />
<property name="projectname" value="demo" />
<!--对于appender标签,name是appender的名称,class是全限定名。以下每个appender是输入到不同位置,具体看class基本就能看出来-->
<!--encoder标签就是输出日志的格式化-->
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">\
<!--target:输出到控制台时,是使用System.out还是System.err-->
<target>System.out</target>
<encoder charset="UTF-8">
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
</encoder>
</appender>
<appender name="fileAppender" class="ch.qos.logback.core.FileAppender">
<file>${log.dir}/${projectname}/fileAppender.log</file>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
</encoder>
<!--append:如果为true,末尾追加。如果为false,清空现有文件,rollingFileAppender也支持,默认为true-->
<append>true</append>
</appender>
<!--RollingFileAppender 滚动记录文件,先将日志记录到指定的文件,当符合某个条件的时候,将日志记录到其他文件-->
<appender name="rollingAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${log.dir}/${projectname}/rollingAppender.log</file>
<!--过滤器,满足什么条件的日志会被持久化纪录。此处用到是ThresholdFilter,还有一些其他的过滤,EvaluatorFilter,根据一些特定的值进行过滤-->
<!--<filter class="ch.qos.logback.core.filter.EvaluatorFilter">-->
<!--<evaluator>-->
<!--<!– 过滤掉所有日志消息中不包含"Exception"字符串的日志 –>-->
<!--<expression>return message.contains("Exception");</expression>-->
<!--</evaluator>-->
<!--<OnMatch>ACCEPT</OnMatch>-->
<!--<OnMismatch>DENY</OnMismatch>-->
<!--</filter>-->
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>INFO</level>
</filter>
<!--rolling的条件,达到什么条件转换纪录的文件,以下是按照时间,每日生成一个文件-->
<!--还有一些其他的策略,包括文件大小等-->
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<!--转换后的日志名-->
<fileNamePattern>${log.dir}/${projectname}/rollingAppender-%d{yyyy-MM-dd}.log
</fileNamePattern>
<!--最多保存30天-->
<maxHistory>30</maxHistory>
</rollingPolicy>
<encoder charset="UTF-8">
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
</encoder>
</appender>
<!-- 异步输出 -->
<appender name ="asyncAppender" class= "ch.qos.logback.classic.AsyncAppender">
<!-- 不丢失日志.默认的,如果队列的80%已满,则会丢弃TRACT、DEBUG、INFO级别的日志 -->
<discardingThreshold >0</discardingThreshold>
<!-- 更改默认的队列的深度,该值会影响性能.默认值为256 -->
<queueSize>2048</queueSize>
<!-- 添加附加的appender,最多只能添加一个 -->
<appender-ref ref ="rollingAppender"/>
<includeCallerData>true</includeCallerData>
</appender>
<!--logger指定哪一些类或者包,使用某个appender配置,以及这些日志的level,TRACE < DEBUG < INFO < WARN < ERROR-->
<!--logger中有个属性additivity: 默认为true,将此loger的打印信息向上级传递,一直会到root上-->
<logger name="org.apache">
<level value="INFO" />
<appender-ref ref="fileAppender" />
<appender-ref ref="rollingAppender" />
</logger>
<logger name="org.springframework">
<level value="INFO" />
<appender-ref ref="fileAppender" />
<appender-ref ref="rollingAppender" />
</logger>
<logger name="com.netflix">
<level value="INFO" />
<appender-ref ref="fileAppender" />
<appender-ref ref="rollingAppender" />
</logger>
<logger name="asyncLog">
<level value="INFO" />
<appender-ref ref="fileAppender" />
<appender-ref ref="rollingAppender" />
</logger>
<!--root 也是元素,但是它是根logger。只有一个level属性。因为已经被命名为为root-->
<root>
<level value="INFO" />
<appender-ref ref="STDOUT" />
</root>
</configuration>
5、使用
在项目中依赖实现了slf4j的日志组件。例如
<dependency> <groupId>org.slf4j</groupId> <artifactId>slf4j-log4j12</artifactId> <version>1.6.1</version> </dependency>
其次在代码中调用
1)直接在代码中使用logger的name属性,打印日志的时候就会按照你选的logger配置打印
private static final Logger log = LoggerFactory.getLogger("asyncLog");
2)这种写法,当loggerFactory从logback.xml中找不到name相同的logger,会以root为parent,直接copy一个logger,并维护到root的childrenList中。之前已经说了root是根logger,其他logger都是root的children。这段可以直接debug一下getLogger方法,逻辑还是比较简单的。
private static final Logger log = LoggerFactory.getLogger(Test.class);
具体流程如下:
我们需要的logger的name是org.zeng.Test.,
loggerFactory会按照org,org.zeng,org.zeng.Test的方式去查logback中logger标签的name。
如果实在找不到,就会以root为parent直接复制一个,维护到childrenList中
注意:以上具体流程是基于LoggerContext的实现。
参考链接:
http://webinglin.github.io/2015/06/04/Logback-%E5%AD%A6%E4%B9%A0%E7%AC%94%E8%AE%B0/
http://blog.csdn.net/dora_310/article/details/74891931