Помогите мне разобраться в модуле регистрации Python и его обработчиках

Question

Мне действительно не хватает чего-то базового в модуле журналирования python.

В следующем коде я создаю объект регистратора (log) и добавляю к нему два обработчика.Один с уровнем «ИНФО» и один с уровнем «ВНИМАНИЕ».Они оба должны печатать на стандартный вывод.Я ожидаю, что вызов log.info(msg) приведет к одной копии msg в моем stdout, а вызов log.warn(msg) может привести к двум копиям msg, напечатанным на моем stdout.Вот код:

import logging
import sys


logging.basicConfig()
log = logging.getLogger('myLogger')
log.handlers = []
h1 = logging.StreamHandler(sys.stdout)
h1.level = logging.INFO
h1.formatter = logging.Formatter('H1 H1 %(message)s ')
h2 = logging.StreamHandler(sys.stdout) 
h2.level = logging.WARNING
h2.formatter = logging.Formatter('H2 H2 %(message)s')
log.addHandler(h1)
log.addHandler(h2)

print 'log.level == %s'%logging.getLevelName(log.level)
print 'log.info'
log.info('this is some info')
print 'done'
print 'log.warn'
log.warn('this is a warning')
print 'done'

Вывод действительно очень странный для меня.Вызов .info не приводит к визуальному эффекту.Тем не менее, обращение к warn приводит к двум копиям сообщения, напечатанным в stdout (что нормально), а также к одной копии, напечатанной в stderr (почему?).Это вывод вышеуказанного кода.Обратите внимание на форматирование последней строки в этом выводе.Эта строка выводится на stderr.

log.level == NOTSET
log.info
done
log.warn
H1 H1 this is a warning 
H2 H2 this is a warning
done
WARNING:myLogger:this is a warning

Итак, мои вопросы:

1. , почему мой вызов info не приводит к выводу, несмотря на то, что h1's уровень имеет значение INFO?
2. , почему мой вызов warn приводит к дополнительному выводу в stderr?

Answer 1

Вам нужно знать две вещи:

1. Корневой регистратор инициализируется с уровнем WARNING.

   Любое сообщение журнала, которое достигает регистратора, отбрасывается, если его уровень ниже уровня регистратора. Если уровень регистратора не установлен, он возьмет свой «эффективный уровень» из родительского регистратора. Таким образом, если корневой регистратор имеет уровень WARNING, все регистраторы имеют эффективный уровень по умолчанию WARNING. Если вы не настроите это иначе, все сообщения журнала с уровнем ниже, который будет отклонен.

2. При вызове basicConfig() система автоматически устанавливает StreamHandler для корневого регистратора, который печатает в стандартный поток ошибок.

   Когда ваша программа печатает свои сообщения журнала, на самом деле есть три обработчика : два, которые вы добавили, которые имеют свои собственные уровни, и один из системы, который будет печатать любое сообщение, не отклонено его регистратором. Вот почему вы получаете линию

   WARNING:myLogger:this is a warning
   

   Это исходит от системного регистратора. Он не делает этого для сообщения уровня INFO, потому что, как обсуждалось ранее, корневой логгер настроен на отклонение этих сообщений по умолчанию.

   Если вам не нужен этот вывод, не звоните basicConfig().

Дальнейшее чтение: http://docs.python.org/howto/logging.html

Answer 2

На самом деле существует пять уровней ведения журнала: отладка, информация, предупреждение, ошибка и критический уровень.Я вижу, что когда вы настраиваете свой регистратор, вы явно не устанавливаете свой уровень - я полагаю, что регистратор может по умолчанию выдавать предупреждение, если уровень не установлен.

Относительно того, почему он печатается несколько раздля предупреждения, я полагаю, это связано с тем, что вы создали два обработчика для информации и предупреждения.Что происходит, так это то, что регистратор выходит из строя по серьезности от предупреждения -> информация -> отладка, вызывая обработчик для каждого.Поскольку ваш уровень установлен на предупреждение, обработчик информации игнорируется.Кроме того, я считаю, что предупреждающие сообщения обычно записываются в sys.stderr.

Попробуйте выполнить следующее:

logging.basicConfig(level=logging.INFO)

См. Также:

• Модуль ведения журналадокументы
• Базовый пример ведения журнала