Logback多进程写入同一日志文件时滚动日期混乱问题

0、背景

近日对公司项目引入消息队列，对不要求即时返回的写场景进行了改造。

因为目前对kafka的学习比较深入了，加上对往期项目中引入kafka的经历的总结，这一过程比较顺利。

美中不足的是，由于在日志监控分析层面，已应用了ELK的日志收集、存储、展示分析技术栈，故希望在最小限度修改的前提下对消息队列的消费日志做统一的收集和整理，因而出现了多项目写入同一日志文件的需求。

相关环境说明如下：

JDK 1.8

springboot+springcloud 1.5.13.RELEASE

logback 1.1.11

各微服务依赖一个基础jar包

同一机器部署多个微服务

 

1、过程

测试中发现消息队列消费正常，分析日志时发现某个服务消费的topic没有日志，进而定位到一个logback RollingFileAppender很神奇的情况。

比如今天是4月9日，它却能稳定的把一部分日志记到今天的日志、把另一部分记到4月8日的滚动日志。

自然昨日的日志文件不在filebeat的收集列表之中，表现如同没有记录过。

一个正常，一个就像是被挤到昨天的日志文件了一样。

发生频率方面，启动服务时有时出现问题，0点切日时稳定复现问题。

关键的条件：多个项目共用一个写入的日志路径。

 

2、解决方案

在查找过程中，首先翻阅到很多纠结logback相对路径的问题。。

接下来看到logback提供的RollingFileAppender允许多进程写入方案：prudent选项。但是，由于不能配置file选项导致需要涉及到logstash配置变更、改动成本较大。

在反复调整搜索关键词后，终于：

“眼前有景道不得，崔颢题诗在上头。”前人之述备矣！

https://blog.csdn.net/Abysscarry/article/details/102847754

“崔兄”的场景在于不停机部署以及进程级别的故障转移，与我而言这也是一个很好的、尚未实现的努力方向。

最后参照项目中“添加与开源框架包路径相同的类”解决问题。后续保持观察。

 

3、备忘

（1）每有一条日志打印时，TimeBasedRollingPolicy都会去判断是否需要滚动，发现满足条件后就执行滚动操作。而我们第一感觉会认为0点判断吧。

（2）FileOutputStream构造函数中调用的native方法会自动创建文件。

（3）关于重复类加载

类被加载时，会先判断类是否已经被加载。第二个相同类不被载入。

项目使用Maven管理依赖时，类加载顺序按照pom.xml内使用的顺序（由上至下，靠上优先加载）；且父POM使用的依赖会被最后加载

https://blog.csdn.net/jason20ming/article/details/7192486

简单验证了一下，只要在项目引用的基础jar包中创建包名相同的类，然后保持在微服务项目的pom中首先引用基础jar包即可。

而spring-boot-starter作为parent，其所包含的logback模块会在最后加载。这样当ClassLoader发现TimeBasedRollingPolicy已加载时就不会再载入logback模块的同名文件了。

如果仍担心，把spring-boot-starter依赖的logback exclude掉，然后在pom底部单独引用也可以。这样稳定适用由上至下的顺序规则。