多进程使用同一log4j配置导致的日志丢失与覆盖问题

最近接手了一个流传很多手的魔性古早代码，追日志时发现有明显缺失。对log4j不熟，不过可以猜测日志出问题肯定和多进程使用同一个log4j配置有关。经多次排查，终于捋清了其中逻辑。本文对排查过程进行复盘。

一、表征

故事背景：项目有多个入口。一边即以持续运行获取消息的后台进程形式运行，一边又作为单次任务调度的普通进程被不断启动并结束退出。也就是说，同一个项目同时运行着多个进程，并且使用着同一个log4j配置。
下面称后台进程为进程A，普通进程为进程B。A在后台持续运行，B多次短暂执行。

|<----------------- A ------------------- ......

  |<- B ->|    |<--- B --->|   |<- B ->|

起因：进程B的运行效果与预计不符，需排查B的日志定位问题。
神奇的现象：
1）有的B有日志有的没有，没发现明显的出现规律。
2）有的B日志完整，有的不完整。
3）只有近几个小时的B有日志，写进文件的B的日志居然过一段时间会消失。
4）历史日志中，绝大多数日期只有一个B的日志，而个别日志有很多。
 
 

二、内因

每一个A/B的日志指针都分别以append方式打开日志文件，文件指针互相独立，各自向后写。从而导致两个问题：
问题1：因A写的慢、B写的快（业务实际情况），所以每一个B均在文件末尾append，和上一B相邻，而A会逐渐覆盖B的日志，直到开始滚动分页。
 
问题2：当切换到下一自然日0点时，开始滚动分页时，如果此时有B正在运行，则A和B各自有一个指针。
参考https://blog.csdn.net/somechange/article/details/80895507 所说。
如果A先写，则两次滚动分页后，A往log.yesterday中写，而B往log中写，并在任务完成后释放句柄并退出。新的B继续在log中写。
如果B先写，则两次滚动分页后，A往log中写，B往log.yesterday中写，并在任务完成后释放句柄并退出。新的B继续在log中写。
无论如何，真正的log.yesterday都已经被覆盖。
 
 

 
D日（D <= T-2）的日志只有四种情况：（T日即当前日期）
① 记录了D+1日的第一个B（因为D+1日有B跨天，且B先写）
② 记录了D+1日的所有A（因为D+1日有B跨天，且A先写）
③ 记录了D日的所有A+ 未被覆盖的B（因为D+1日没有B跨天，且D日B先写）
④ 记录了D日的所有的非首个B（因为D+1日没有B跨天，且D日A先写）
 
符合观察到的现象。
done

多进程使用同一log4j配置导致的日志丢失与覆盖问题的相关教程结束。