问题
这两天接手了一个线上服务问题,有一个服务采用的log4j2输出每天的用户元数据日志,每天00:00:00的时候对前一天的日志进行归档,
然后新建一个当天要用的日志文件,在线上发现了问题,比如昨天是2021-11-18,归档之后归档文件的名称却是2021-11-19,这不是我们
想要的效果,因为这个归档文件中实际上包含的都是2021-11-18的日志
我的配置
pom.xml
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-log4j2</artifactId>
<version>2.3.3.RELEASE</version>
</dependency>
spring-boot-starter-log4j2这个启动依赖里面包含了log4j的依赖,并且log4j的版本都是2.13.3
log4j2-spring.xml
<RollingFile name="userMetadataTo" fileName="${log.path}userMetadataTo_${hostName}.log"
filePattern="${log.path}userMetadataTo_%d{yyyy-MM-dd}_${hostName}_%i.log">
<!--输出的日志数据格式-->
<PatternLayout pattern="%msg%n"/>
<!-- 每天0点生成新的日志文件 -->
<CronTriggeringPolicy schedule="0 0 0 * * ?"/>
</RollingFile>
可以看到,配置很简单,就是使用cron表达式声明每天00:00:00这个时间点的时候进行日志翻滚
如何解决
网上找类似问题
翻了很多网上类似的问题,最终在apache的issue里面翻到了问题所在
CronExpression.getTimeBefore() returns incorrect result
issue怎么说
这个issue里面主要是说log4j定时任务运行的时候,有一个函数getTimeBefore()有问题,没有返回上一个周期(当前时间-配置的定时周期)
而是直接返回的当前时间,比如现在是2021-11-19 00:00:00,log4j的定时任务开始执行,我们配置的定时任务是每天00:00:00执行,所以
这个周期就是24x60x60x1000(将一天换算成毫秒),那么最终归档的文件名称就应该是2021-11-19 00:00:00的毫秒时间戳 - 24x60x60x1000,
这样就可以正确的得到2021-11-18 00:00:00这个时间,但是2.11.2这个版本的log4j最终是返回当前日期,所以归档的文件名会有错误。
issue里面的错误的版本和我的一致吗
issue里面有错误的版本是2.11.2,并且说明了到2.13.1的版本这个问题已经修复了,而我实际在spring-boot-starter-log4j2这个依赖用到
的是2.13.3的版本,这就很奇怪了~
依赖问题
当前实际依赖的log4j版本
于是我在pom的Dependency Analyzer找了下,发现里面用的都是2.11.2的版本
应该依赖的log4j版本
然而在mavenrepository里面显示这个版本依赖的log4j都应该是2.13.3才对:
父POM害我
最终在父POM里面发现了一个配置
<dependency>
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-bom</artifactId>
<version>${log4j2.version}</version>
<type>pom</type>
<scope>import</scope>
</dependency>
这个${log4j2.version}对应的版本刚好就是2.11.2,然后看一下log4j-bom是干啥的
log4j-bom里面管理了很多log4j相关的依赖,将这些依赖的版本都限制为2.11.2,问题到此就已经明了了,本来呢我依赖的这个
spring-boot-starter-log4j2不应该出现归档文件名称错误的问题
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-log4j2</artifactId>
<version>2.3.3.RELEASE</version>
</dependency>
但是呢刚好依赖的公司的父POM给覆盖成了2.11.2,然后2.11.2这个版本又刚好有问题,于是有了这次生产问题~