Python logging.handlers.QueueHandler 为什么会递归：队列日志、线程边界与安全配置

线上服务把日志改成队列后，业务线程确实轻了，但有一种故障很难看：终端开始重复刷同一条消息，队列长度只涨不降，最后连真正的错误也被淹没。问题通常不在 QueueHandler “不能异步”，而在监听线程处理日志时，又把自己的记录送回了同一个队列。

先把 QueueHandler 和 QueueListener 的职责拆开

QueueHandler.emit() 的核心动作是把日志记录放进队列；它不是最终输出端。QueueListener 在另一条线程中取记录，再交给 FileHandler、StreamHandler 等处理器。这个分工很适合把磁盘写入从请求线程移走，但也带来一条必须守住的边界：监听线程处理记录时，不要再通过相同的入队路径记录普通诊断信息。

最小可运行配置可以这样写：

import logging
import queue
from logging.handlers import QueueHandler, QueueListener

log_queue = queue.Queue()
sink = logging.StreamHandler()
sink.setFormatter(logging.Formatter('%(levelname)s %(name)s %(message)s'))

app_log = logging.getLogger('app')
app_log.setLevel(logging.INFO)
app_log.propagate = False
app_log.addHandler(QueueHandler(log_queue))

listener = QueueListener(log_queue, sink)
listener.start()
app_log.info('request accepted')
listener.stop()

这里的成功状态不是“调用了 start()”这么简单，而是能看到一条 INFO app request accepted，并且 listener.stop() 返回后队列不再有未消费记录。

重复输出是怎样从 logger 层级里长出来的

Python logger 默认会向父 logger 传播。假设 app 绑定了 QueueHandler，根 logger 又绑定了一个 StreamHandler，同一条记录可能先进入队列，随后沿父级继续输出一次。你看到的“递归”有时其实是重复传播；真正危险的情况，是监听处理器或其依赖代码又调用了挂着 QueueHandler 的 logger。

排查时不要先把所有级别改成 WARNING。先打印每个 logger 的 handler 和 propagate：

def describe_logger(name):
    logger = logging.getLogger(name)
    print(name, logger.level, logger.propagate,
          [type(item).__name__ for item in logger.handlers])

describe_logger('app')
describe_logger('root')

如果 app 已经有自己的输出处理器，就将 propagate 设为 False；如果必须依赖根 logger，则只能保留一条明确的输出路径。

同一队列为什么会让监听链路重新入队

典型错误配置是：应用 logger 使用 QueueHandler(log_queue)，监听线程消费这个队列；监听线程内部的异常处理、队列状态日志或下游 handler 又拿到了同一个应用 logger。于是流程变成“取出一条记录—记录处理过程—再次入队—再次取出”。记录数量不一定立刻爆炸，但它会表现为重复消息和停止时迟迟排不干净。

另一个需要特别避开的边界是 multiprocessing 自己的内部日志。如果它的内部 logger 使用与 QueueHandler 相同的 multiprocessing.Queue，官方文档明确提醒可能出现死锁或递归。多进程场景要给内部诊断流单独的 logger 和输出处理器，不要为了“统一收集”把它们接回业务队列。

一个可验证的安全边界：业务流和监听诊断流分开

业务日志只走 app，监听器的诊断信息使用独立 logger，并且不向根 logger 传播：

listener_log = logging.getLogger('logging.listener')
listener_log.setLevel(logging.WARNING)
listener_log.propagate = False
listener_log.addHandler(logging.StreamHandler())

def record_listener_problem(message):
    listener_log.warning('listener problem: %s', message)

这不是用更高的日志级别掩盖问题。实际核对时看三件事：业务日志仍能到达 sink；监听诊断只出现在独立输出端；反复触发一次 handler 异常后，log_queue.qsize() 不会持续上升。qsize() 在不同平台的精确性有限，适合做趋势观察，不能当作并发下的严格计数。

停机顺序决定最后几条日志会不会丢

停机时先让生产者停止写日志，再调用 listener.stop()。它会向监听线程发出停止信号，并等待队列中的记录处理完；随后再移除 handler、关闭输出端。若业务线程还在持续产生日志，停止动作和生产动作会互相竞争，结果就很难判断是丢失还是尚未消费。

app_log.removeHandler(app_log.handlers[0])
listener.stop()
sink.close()

生产代码中应保存实际的 QueueHandler 引用，不要用“第一个 handler”这种脆弱写法；上面的片段只是展示顺序。核对结果应包含最后一条业务记录、监听线程退出，以及没有新的入队动作。

常见问题

QueueHandler 会自动创建后台线程吗？

不会。后台消费线程由 QueueListener 提供；QueueHandler 只把记录交给队列。

设置 propagate=False 就能解决所有递归吗？

不能。它主要阻止 logger 向父级传播；如果监听处理路径仍显式使用同一个 QueueHandler，依然要拆分 logger 或输出端。

为什么队列没满，程序却越来越慢？

重复传播、监听线程频繁记录诊断信息，或下游输出处理器变慢，都可能让消费速度跟不上生产速度。应分别看入队次数、实际输出次数和监听线程处理耗时。

把配置收敛成一张检查清单

• 业务 logger 是否只有一条明确的 QueueHandler 路径？
• 父 logger 是否因 propagate 再输出了一次？
• QueueListener 的诊断 logger 是否与业务队列隔离？
• 多进程内部日志是否误用了同一条 multiprocessing.Queue？
• 停机前是否已经停止生产，再等待 listener 排空？

只要能沿着“生产—入队—消费—输出”逐段核对，QueueHandler 的问题就不再是一个看似随机的重复日志故障。