先看现象。logrotate 按天切割 uvicorn 的 access.log,4 个 worker 各自持有文件句柄,切割后旧文件继续被写,新日志里出现半行 JSON,日志平台解析失败率 6%。
把日志和配置对完,能解释这个现象的基本就这几处。copytruncate 与多进程并发写叠加,行被从中间切断。另一种情况是worker 没有重新打开文件的机制。
还有一种情况,JSON 日志一次写多段,跨 write 系统调用被切开。
另外,没有改成 stdout 交给容器统一收集。
第一件事是确认进程持有的还是旧 inode
python -c "import os;print(os.stat('access.log').st_ino)"
随后改成输出 stdout,由容器负责切割
python -c "print('uvicorn --log-config - 2>&1')"
接着用 WatchedFileHandler 让进程感知文件替换
python -c "import logging.handlers;print(logging.handlers.WatchedFileHandler)"
剩下的就是统计切割后新文件里的坏行比例
python -c "import json;bad=0;n=0;\nimport sys\nfor l in open('access.log'):\n n+=1\n try: json.loads(l)\n except: bad+=1\nprint(n,bad)"
改完先别撤,确认这几项。切换后新日志的解析失败率降到 0.1% 以下,切割时间点前后的行都完整,日志平台不再报解析错误。
提醒一点。多进程写同一个文件再做 rename,本身就是竞态,能交给容器收集就别自己切。拖得越久,排查成本越高,因为现场状态会被后续操作覆盖。
