在一个多 worker 的 Python 服务里，日志按天落盘本来是件很普通的事，但真正跑进 Docker 和多进程环境之后，事情往往没有想象中那么简单。我们这次遇到的，就是一个非常典型、也非常容易被忽视的问题：日志文件日期彻底混乱了。

最离谱的时候，目录里会看到一个名字像这样的文件：

app.log.2026-04-18

但打开之后，里面却混进了 2026-04-23 的日志。

这种现象第一眼看上去很玄学，实际上原因并不玄学。核心就是一句话：

多 worker 进程同时写同一个轮转日志文件，天然就容易出事。

这篇文章把这个问题的成因、误区，以及我们当前先落地的临时方案整理一下。也提前说明：这不是最终版日志架构，只是先把现在线上最痛的跨天串文件问题止住。

背景

项目运行在 Docker 里，服务启动方式是：

uvicorn src.main:app --host 0.0.0.0 --port 8000 --workers 4

也就是说：

• 一个容器
• 4 个 Uvicorn worker 进程
• 所有 worker 都会初始化日志

原来的日志实现使用的是 Python 标准库的：

TimedRotatingFileHandler

配置思路也很常见：

• 当前写入 logs/app.log
• 到午夜时轮转
• 旧文件加日期后缀

如果是单进程，这套做法很多时候能跑。

但一旦切到多 worker，这种方案就开始埋雷了。

我们观察到的异常现象

表面症状主要有两个：

1. 旧日期文件里混入新日期内容
2. 同一时间段出现多次重复初始化日志

第二个现象非常重要。日志里会连续看到类似内容重复多次：

• Initializing application...
• TaskManager initialized...
• Application initialized successfully

这其实是在提醒我们：

• 不是一个进程在初始化
• 而是 4 个 worker 都各自做了一次初始化

换句话说，日志系统不是“全局唯一实例”，而是每个 worker 进程里各有一套。

真正的问题不是“时区错了”，而是“多进程写同一文件”

最开始大家也会很自然地想到时区问题。

毕竟 Docker 容器默认往往是 UTC，如果按 midnight 轮转：

• 你以为是北京时间午夜切割
• 实际上可能是 UTC 午夜切割

这个问题确实存在，但它只会导致：

• 切割时间不符合本地预期
• 文件日期和人的直觉不一致

它不会导致一个日期文件里混进另一天的日志。

出现“2026-04-18 文件里混入 2026-04-23 内容”这种情况，根因基本只能往下面这个方向找：

多个进程同时操作同一个日志文件及其轮转过程。

TimedRotatingFileHandler 在多 worker 下为什么会出问题

核心原因很简单：

• 每个 worker 都持有自己的 TimedRotatingFileHandler
• 每个 handler 都认为自己在独立管理 logs/app.log
• 到了应该切割的时候，多个进程可能几乎同时判断“该轮转了”
• 它们会分别去 rename、关闭、重开同一个文件

于是就会出现各种竞争：

• 某个进程已经把文件切走了
• 另一个进程还握着旧文件句柄继续写
• 第三个进程又重新创建了新的 app.log
• 最终目录里的文件名和内容就开始错位

这不是某一行代码写错的问题，而是这种方案在多进程共享文件场景下，本来就不稳。

我们最后定下来的约束

这次处理日志问题时，有一个前提条件是明确的：

多 worker 不动。

也就是说：

• 不能为了日志简单，直接把 workers=4 改成 1
• 服务并发模型要保留
• 但日志还得继续落盘

在这个前提下，就必须接受一个现实：

不要再让多个 worker 共用一个日志文件。

当前先落地的临时方案

我们这次先采用的是一个足够简单、也足够稳的方案：

每个 worker 按“日期 + 进程号”写自己的日志文件。

文件名长这样：

app-2026-04-23.101.log
app-2026-04-23.102.log
app-2026-04-23.103.log
app-2026-04-23.104.log

这样一来：

• worker 101 只写自己的文件
• worker 102 只写自己的文件
• 不再共享文件句柄
• 不再共享轮转动作

这个方案最大的优点是朴素：

不优雅，但稳定。

而我们这次的目标也很明确，不是马上把日志体系一步做到最好，而是先把“跨天串文件”这个问题彻底结束掉。

所以这里要明确一句：

当前方案是临时工程解，不是我们心里最理想的长期日志方案。

新方案怎么工作

新的日志逻辑不再依赖 TimedRotatingFileHandler，而是改成：

1. 当前进程启动时拿到自己的 PID
2. 每次写日志前，按指定时区计算当天日期
3. 把日志写入 app-YYYY-MM-DD.<pid>.log
4. 如果日期变化，就切换到新的文件名
5. 清理超过保留天数的旧日志

配套上，我们还显式给容器配置了时区，例如：

TZ=Asia/Shanghai
LOG_TIMEZONE=Asia/Shanghai

这样做之后，至少有两件事变得确定了：

1. 文件日期按本地时区计算
2. 每个进程只碰自己的文件

也就是说，之前那个最烦人的问题：

日期文件名和内容日期错位

在这个方案下就基本被消掉了。

这个方案解决了什么

它解决的是下面这些具体问题：

1. 跨天串文件
   多个 worker 不再共享同一个轮转文件，旧文件里混入新日期内容的问题基本可以结束。

2. 多进程 rename 竞争
   因为不再多人共同操作一个 app.log，也就没有一起 rename 同一个文件的问题。

3. 日期语义混乱
   日志文件名按明确时区生成，不再默认跟着 UTC 午夜走。

这个方案没有解决什么

这也要诚实写清楚。

这个方案是我们当前阶段的临时但靠谱方案，它不是终极形态，也不是后续不会再动的最终结论。

它没有解决的点主要有：

1. 同一天会有多个文件
   排查问题时，可能要同时 grep 几个日志文件。

2. 不是中心化日志方案
   如果以后服务规模继续变大，最终可能还是会走：

• stdout + Docker 日志驱动
• ELK / Loki / Datadog
• 专门的日志采集与聚合

3. 旧历史日志不会自动变整齐
   新方案生效后，新的日志会按新规则写，但老的 app.log* 历史文件依旧会留在目录里。

为什么我们接受这个方案

因为在当前约束下，它是性价比最高的选择。

我们有三个现实要求：

1. 多 worker 不动
2. 日志必须继续落盘
3. 尽快结束跨天混乱问题

在这个约束组合下，最实际的办法就是：

不要追求一个共享单文件的优雅结构，而是先把进程间文件竞争拆开。

这其实是很多工程问题里都适用的思路：

• 如果共享资源容易打架
• 那就优先拆分资源边界

这里的共享资源，就是日志文件本身。

后续更优方案还没有搬上来

这部分也要说清楚，避免读完之后误以为“日志问题已经彻底一次性收工”。

并没有。

我们现在只是先把最危险的共享文件竞争拆掉了，但更完整、更长期的日志方案还没有正式搬上来。

后续如果继续演进，可能会往下面几个方向走：

1. stdout 为主，平台统一采集
   这是容器场景最自然的方案。

2. 专门的日志写入进程/队列
   多 worker 不直接落文件，而是统一汇聚后写盘。

3. 集中式日志系统
   把查询、过滤、检索都交给专门的日志平台。

但这些都比当前需求更重，也意味着更多改造成本，所以这次没有一并推进。

现阶段，我们优先要的是：

日志别再跨天乱套。

至于统一采集、集中检索、单视图聚合这些更“舒服”的能力，后面再逐步补。

最终结论

这次日志问题的核心教训非常清楚：

• TimedRotatingFileHandler 在单进程下常见，在多 worker 下风险很大
• 时区问题只是表层因素
• 真正致命的是多进程共同写同一个轮转文件

我们当前处理方式是：

• 保留多 worker
• 保留日志落盘
• 改成每个 worker 每天单独文件
• 文件名带日期和 PID
• 明确使用本地时区生成日期

这不是最终形态，但它足够直接，也足够有效。

更好的后续方案我们已经想到了，只是这次还没有搬上来。

对于当前这个项目来说，这个方案已经能满足最重要的目标：

结束日志跨天串文件问题。