最近接手了一个流传很多手的魔性古早代码，追日志时发现有明显缺失。对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都已经被覆盖。
| day1 | day2 | day3 | day4 | day5 | day6 | |
|---|---|---|---|---|---|---|
| 假设 | A先写 | A先写 | B先写 | B先写 | A先写 | |
| log | day1的A+B | day2的B | day3的B | day4的A+其他B | day5的A+其他B | day6的B |
| log.day1 | day2的A | day2的A | day2的A | day2的A | day2的A | |
| log.day2 | day3的A | day3的A | day3的A | day3的A | ||
| log.day3 | day4的第一个B | day4的第一个B | day4的第一个B | |||
| log.day4 | day5的第一个B | day5的第一个B | ||||
| log.day5 | day6的A |
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
