Python logging模块需理解Logger、Handler、Formatter、Filter四层协作机制;root logger与自定义logger行为差异源于basicConfig仅初始化root且propagate机制影响日志传递;FileHandler缓存丢失需手动flush或设force=True;时区问题应通过formatter.converter=time.gmtime统一UTC。

Python 的 logging 模块不是“配好就能用”的黑盒,它的行为由 Logger、Handler、Formatter、Filter 四层协作决定,任意一层配置错,日志就可能丢失、错位或格式混乱。
为什么 root logger 看似生效,但自定义 logger 却不输出?
这是最常踩的坑:误以为 logging.basicConfig() 能影响所有 logger。实际上它只初始化 root logger,且仅在首次调用时生效;而 logging.getLogger('xxx') 创建的是独立实例,默认 propagate=True,会向上委托给 root —— 但如果 root 没 handler 或 level 太高,你的日志就被静默吞掉。
- 检查是否显式设置了子 logger 的
level,例如logger.setLevel(logging.DEBUG) - 确认子 logger 是否关闭了传播:
logger.propagate = False(适合完全独立控制) - 避免混用
basicConfig()和手动添加 handler:后者更可控,推荐全程手动构建
Handler 写文件时突然不落盘?
FileHandler 和 RotatingFileHandler 默认使用行缓冲(line-buffered),但 Python 进程异常退出(如 SIGKILL)、或日志量少未触发 flush 时,缓存中的日志就丢了。
- 强制同步写入:初始化时加参数
delay=False(默认)+mode='a',再配合handler.flush()手动刷盘 - 更稳妥的做法是设置
logging.basicConfig(force=True)(Python 3.8+),它会先移除已有 handler 再重建 - 生产环境建议用
TimedRotatingFileHandler并启用backupCount,避免单文件无限膨胀
Formatter 中 %(asctime)s 时间比系统时间慢 8 小时?
这是时区问题。asctime 默认走 time.localtime(),若服务器时区为 UTC(如多数 Docker 镜像),而你本地是 CST,就会差 8 小时。
立即学习“Python免费学习笔记(深入)”;
- 统一用 UTC 时间记录:在
Formatter初始化前设logging.Formatter.converter = time.gmtime - 或改用更灵活的
%(created)f(Unix 时间戳,秒级精度),后续用 Pandas 或datetime.fromtimestamp()转换 - 注意:不要在 Formatter 字符串里硬编码
%Y-%m-%d %H:%M:%S,应通过datefmt参数传入,否则converter不生效
import logging import time正确:指定 converter + datefmt
formatter = logging.Formatter( '%(asctime)s - %(name)s - %(levelname)s - %(message)s', datefmt='%Y-%m-%d %H:%M:%S' ) formatter.converter = time.gmtime # 强制 UTC
真正难的不是写几行 logger.info(),而是理解 level 传递路径、handler 生命周期、以及 formatter 如何与底层 time 模块耦合——这些细节不摸清,线上日志一出问题,第一反应往往是“是不是框架 bug”,其实只是 propagation 被意外截断,或者 handler 被重复 add 了两次。










