問題
這兩天接手了一個線上服務問題,有一個服務采用的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這個版本又剛好有問題,於是有了這次生產問題~