Почему QueueListener в Python logging игнорирует уровни и как это исправить

Почему при логировании через QueueHandler/QueueListener в Python FileHandler игнорирует setLevel и пишет INFO. Решение: respect_handler_level и пример кода.

Когда вы направляете логирование Python через очередь, легко предположить, что фильтрация на уровне обработчиков будет работать так же, как в прямой цепочке обработчиков. В Python 3.12.9 на Windows конфигурация на базе logging.handlers.QueueHandler и logging.handlers.QueueListener может выглядеть так, словно игнорирует setLevel у FileHandler, пропуская в файл записи с более низким уровнем. Минимальный пример ниже показывает, что и INFO, и WARNING оказываются в Test.log, хотя файловый обработчик настроен на WARNING.

Reproducing the unexpected output

Код создаёт FileHandler с уровнем WARNING, отправляет все записи журнала в multiprocessing.Queue через QueueHandler и потребляет их с помощью QueueListener. Несмотря на заданный порог, INFO всё равно попадает в файл.

import logging
import logging.handlers
from multiprocessing import Queue

sink_file = logging.FileHandler('Test.log', encoding='utf-8')
sink_file.setLevel(logging.WARNING)
sink_file.setFormatter(logging.Formatter('%(levelname)s: %(message)s'))

record_queue = Queue()
listener = logging.handlers.QueueListener(record_queue, sink_file)
listener.start()

root_log = logging.getLogger()
for h in root_log.handlers[:]:
    root_log.removeHandler(h)

queue_sink = logging.handlers.QueueHandler(record_queue)
root_log.addHandler(queue_sink)
root_log.setLevel(logging.DEBUG)

app_log = logging.getLogger("TestLogger")
app_log.info("This is INFO")
app_log.warning("This is WARNING")

listener.stop()
logging.shutdown()

What’s actually happening

Одного уровня файлового обработчика недостаточно, когда записи проходят через QueueListener. В такой конфигурации слушатель пересылает входящие записи подключённому обработчику вне зависимости от его порога, поэтому в файл попадают и INFO, и WARNING. Это неожиданно, если вы рассчитываете, что setLevel обработчика будет автоматически учитываться при работе через очередь.

The fix

В QueueListener есть опция, заставляющая его учитывать уровни, заданные у целевых обработчиков. Если включить её, FileHandler будет выдавать только WARNING и выше, а другие обработчики, подключённые к тому же слушателю, при необходимости смогут получать записи с меньшей серьёзностью. Подробности — в официальной документации: QueueListener.

import logging
import logging.handlers
from multiprocessing import Queue

sink_file = logging.FileHandler('Test.log', encoding='utf-8')
sink_file.setLevel(logging.WARNING)
sink_file.setFormatter(logging.Formatter('%(levelname)s: %(message)s'))

record_queue = Queue()
listener = logging.handlers.QueueListener(
    record_queue,
    sink_file,
    respect_handler_level=True
)
listener.start()

root_log = logging.getLogger()
for h in root_log.handlers[:]:
    root_log.removeHandler(h)

queue_sink = logging.handlers.QueueHandler(record_queue)
root_log.addHandler(queue_sink)
root_log.setLevel(logging.DEBUG)

app_log = logging.getLogger("TestLogger")
app_log.info("This is INFO")
app_log.warning("This is WARNING")

listener.stop()
logging.shutdown()

Why this matters

Очереди часто используют для объединения логов от разных компонентов или процессов. Это также типичный подход, когда разным целям нужны разные уровни — например, отправлять DEBUG и INFO в один приёмник, а файл держать «чистым», только с WARNING и выше. Если не включить у слушателя учёт фильтрации на уровне обработчиков, границы размываются, и файлы начинают зарастать шумом.

Takeaways

Если вы рассчитываете на пороги у отдельных обработчиков в связке с QueueListener, явно включайте respect_handler_level, чтобы каждый обработчик применял свой setLevel. Так журналы остаются целевыми, задуманная фильтрация сохраняется для разных приёмников, а неожиданные записи не просачиваются в конвейерах на очередях.