studying
人心最苦处,最是拖泥带水

问题

这两天接手了一个线上服务问题,有一个服务采用的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这个版本又刚好有问题,于是有了这次生产问题~

对比下2.11.2和2.13.3的log4j代码

posted on 2021-11-19 18:56  小白一只726  阅读(1696)  评论(0编辑  收藏  举报