码迷,mamicode.com
首页 > 其他好文 > 详细

log4j笔记:升级2.X版本的日志滚动问题

时间:2016-07-02 20:12:55      阅读:223      评论:0      收藏:0      [点我收藏+]

标签:

因为slf4j依赖的log4j在流量大的时候总遇到多线程引起的死锁问题,升级到log4j2.x版本。原来的log4j.properties配置文件已经不被log4j2支持了,需要改写为log4j2.xml。在升级的过程中,配置与原先相同,使用异步日志,按小时滚动,却发现配置后日志输出正常,但滚动的功能不正常,查出以下两个问题。

 

1. 日志不按小时滚动

原来的配置如下:

 <RollingRandomAccessFile name="RollingFile" fileName="${backupFilePatch}${fileName}" filePattern="${backupFilePatch}${fileName}.%d{yyyy-MM-dd}.%i" immediateFlush="false">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} %p %c{1}[%L]-%m%n"/>
            <Policies>
                <TimeBasedTriggeringPolicy interval="1" modulate="true"/>            
            </Policies>
            <DefaultRolloverStrategy max="120"/>
 </RollingRandomAccessFile>

根据官网的介绍,我理解成了interval=1的时候固定按小时滚动,其实interval的单位是根据filePattern来的,即filePattern配置中的最小单位,所以在yyyy-MM-dd这样的配置中,interval的单位是day,而%i则是interval的序号,日志是按天滚动的。所以将配置改为${backupFilePatch}${fileName}.%d{yyyy-MM-dd.HH}就能按小时滚动了。

 

2. 每小时滚动后,日志不写入新文件,而是写入旧的归档文件。

这个问题更诡异。tomcat启动后,日志是写入log文件的,但是整点日志滚动之后,log归档为log-日期,产生一个新的log文件,但日志还是打入了归档之后的文件log-日期。放置了一天之后,发现更诡异的事情,日志总是写入上一个归档文件。例如,7点的时候,产生一个归档文件log-日期.6,7点到8点的日志都打入了文件6,log文件始终是空的,而8点之后,log归档为log-日期-7,之后的日志都打入文件7,新产生的log文件还是为空。

该问题遍寻不着解法。在某一次整点时,正好刷新了一下,发现log文件有新内容,再刷新又成为上面那种现象了。由此联想到,有可能不只是log4j2在对这个文件进行操作。

 

排查发现,改写log4j2.xml之后,原来的log4j.properties还留在项目里。由于maven层层叠叠的依赖,有几个包引用的是log4j1.x版本,在运行的时候,始终有一个包用的是log4j1.x在打日志,因此加载的是log4j.properties的配置。log4j.properties和log4j2.xml的配置完全相同,写入的也是同一个日志文件。整点的时候,这两个类都对log文件进行归档操作,猜想是log4j2先执行归档,写入新log文件,而这个文件又被log4j1归档,因此后面log4j2的日志都写入了上一个归档文件。

 

将log4j.properties中的日志改为其他名称,问题解决。

log4j笔记:升级2.X版本的日志滚动问题

标签:

原文地址:http://www.cnblogs.com/liumuqiu/p/5635941.html

(0)
(0)
   
举报
评论 一句话评论(0
登录后才能评论!
© 2014 mamicode.com 版权所有  联系我们:gaon5@hotmail.com
迷上了代码!