Python — 日志消息重复输出多遍

症状

　　相邻两行时间戳与内容完全相同，先排除“重复发出”、直指“重复投递”：每条日志带相同 logger 名出现两遍三遍，且重复次数随进程运行时间或模块导入次数增长。质询记录器即可看到倍增本身：打印 getLogger(“app.jobs”).handlers 与各级祖先的 handlers，logger 加祖先的处理器总数就等于打印份数—— propagate=True 时记录先交给自己的处理器，再逐级传给祖先的每个处理器。

诊断思路

　　先数每个相关 logger 的 handler；再 grep 所有 addHandler 与 basicConfig 调用点——模块顶层的调用在每次导入该模块时执行，测试收集阶段反复导入会持续堆叠；最后确认传播形状：子 logger 的 parent 链上每有一个带 handler 的祖先就多一份输出。热重载、重连、测试夹具等再初始化路径只加不清，是次数随时间增长的另一半原因。

根因

　　一条日志记录的投递次数等于“发出 logger 的 handler 数 + 传播开启时每个祖先的 handler 数”。重复的 addHandler（典型在导入期或再初始化路径）让处理器堆叠，一条记录就按堆叠数量打印多遍。

修复与验证

　　配置集中在程序入口、只配根 logger；重配置做成幂等——先 removeHandler 清空再添加；库代码绝不挂 handler，只发记录、由应用决定投递；模块确需独立运行配置就放进 if name == “main” 守卫；propagate=False 只用于刻意隔离的流（如访问日志独立落盘）并写明注释，绝不当作去重手段。验证时冷启动发一条记录断言恰好一行；再模拟重复导入（importlib.reload 或二次调用 setup）后发一条，仍然恰好一行——两次恰好一行才算修复完成。

代码示例

2026-10-22 09:14:03 INFO app.jobs job finished
2026-10-22 09:14:03 INFO app.jobs job finished

import logging
print(logging.getLogger("app.jobs").handlers)   # [..StreamHandler]
print(logging.getLogger("app").handlers)          # [..StreamHandler, ..FileHandler]

import logging

def setup_logging():
    root = logging.getLogger()
    root.setLevel(logging.INFO)
    for h in list(root.handlers):
        root.removeHandler(h)          # idempotent re-entry
    handler = logging.StreamHandler()
    handler.setFormatter(logging.Formatter("%(asctime)s %(levelname)s %(name)s %(message)s"))
    root.addHandler(handler)

if __name__ == "__main__":
    logging.basicConfig(level=logging.INFO)