Модуль протоколирования Python: дублированный вывод консоли [IPython Notebook/Qtconsole]

Question

Я пытаюсь играть с модулем python logging, но здесь немного запутался. Ниже приведен стандартный сценарий для создания logger, а затем создайте и добавьте file handler и console handler в logger.

import logging 

logger = logging.getLogger('logging_test') 
logger.setLevel(logging.DEBUG) 

print(len(logger.handlers)) # output: 0 

# create file handler which logs even debug messages 
fh = logging.FileHandler('/home/Jian/Downloads/spam.log', mode='w') 
fh.setLevel(logging.DEBUG) 

# create console handler with a higher log level 
ch = logging.StreamHandler() 
ch.setLevel(logging.DEBUG) 

# create formatter and add it to the handlers 
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') 
ch.setFormatter(formatter) 
fh.setFormatter(formatter) 

# add the handlers to logger 
logger.addHandler(ch) 
logger.addHandler(fh) 

print(len(logger.handlers)) # output: 2 

# write some log messages 
logger.debug('debug message') 
logger.info('info message') 
logger.warn('warn message') 
logger.error('error message') 
logger.critical('critical message') 

Я запускаю это на вновь запущенном ядре. file handler работает должным образом. Но на выходе консоли, у меня есть какое-то дублированные сообщения:

2015-07-14 10:59:26,942 - logging_test - DEBUG - debug message 
DEBUG:logging_test:debug message 
2015-07-14 10:59:26,944 - logging_test - INFO - info message 
INFO:logging_test:info message 
2015-07-14 10:59:26,944 - logging_test - WARNING - warn message 
WARNING:logging_test:warn message 
2015-07-14 10:59:26,945 - logging_test - ERROR - error message 
ERROR:logging_test:error message 
2015-07-14 10:59:26,946 - logging_test - CRITICAL - critical message 
CRITICAL:logging_test:critical message 

Я полагаю, эти сообщения журнала с метками времени являются от определенного пользователя console handler, но где дублированные сообщения приходят? Могу ли я избавиться от них, скажем, сохранить только каждую другую линию? Любая помощь приветствуется.

Answer 1

Вопрос был поднят here.

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

In [1]: import logging 

In [2]: logging.getLogger().handlers 
Out[2]: [] 

In [3]: logging.warn('Something happened!') 
WARNING:root:Something happened! 

In [4]: logging.getLogger().handlers 
Out[4]: [<logging.StreamHandler at 0x42acef0>] 

Тем не менее, в записной книжке IPython есть STDERR корень по умолчанию регистратор установленный сразу:

In [1]: import logging 

In [2]: logging.getLogger().handlers 
Out[2]: [<logging.StreamHandler at 0x35eedd8>] 

Может быть, я что-то не хватает, но я думаю, что в записной книжке, там должен обработчик не устанавливаются автоматически, по ряду причин:

1. Было бы сделать конфигурацию протоколирования по умолчанию соответствует между стандартным питоном, консолью IPython и ноутбуком IPython.
2. Как только пользователь записывает сообщение журнала с корневым регистратором, обработчик устанавливается автоматически, поэтому сообщения журнала не так легко пропускаются.
3. С текущим поведением библиотека, которая настраивает дочерний регистратор и обработчик для этого дочернего регистратора, может легко спамить ноутбук сообщениями отладки, которые должны находиться только в файле журнала (или в другом месте). Например, у астрологии, похоже, есть такая проблема, и я сталкиваюсь с той же проблемой с моей собственной библиотекой. Проблема в том, что для такой библиотеки нет «чистого» способа обойти это. Библиотека может удалить обработчик корневого регистратора при импорте, который является hack-y. Он может установить свой собственный атрибут propagate регистратора на False, чтобы сообщения журнала не распространялись на корневой журнал, но это не только отключает вывод отладки из входа в ноутбук, но и более серьезные сообщения. Кроме того, он запрещает пользователям фактически захватывать все выходные данные журнала, если они этого захотят.

Альтернативой может быть добавление опции конфигурации, которая определяет уровень журнала для автоматически добавленного обработчика потока, так что становится возможным игнорировать менее строгие сообщения, появляющиеся в ноутбуке автоматически. Но это все равно будет отличаться от поведения между консолью IPython и ноутбуком IPython.

Единственный недостаток, который я вижу в том, что у него нет набора обработчиков по умолчанию, заключается в том, что некоторые используемые библиотеки/ноутбуки могут полагаться на это поведение и активно обходить его, например, отключив свои собственные обработчики, если обнаруживают, что они работает в ноутбуке ipython. Такие случаи, вероятно, нарушатся с такими изменениями.

Таким образом, установка logger.propagate на False или использование reload(logging) предотвратит дублирование вывода, но в зависимости от этого будут иметь побочные эффекты.

Обратите внимание, что reload недоступен в новой версии python (3.4, возможно, ранее). С 3,1 года см importlib.reload

Answer 2

При выполнении

# create console handler with a higher log level 
ch = logging.StreamHandler() 
ch.setLevel(logging.DEBUG) 

Вы создаете другой StreamHandler. Чтобы решить вашу проблему, вы должны захватить StreamHandler из IPython:

import logging 

handlers = logging.getLogger().handlers 
for h in handlers: 
    if isinstance(h, logging.StreamHandler): 
     handler_console = h 
     break 

Если он не существует, вы создаете свой собственный:

if handler_console is None: 
    handler_console = logging.StreamHandler() 

Наконец формат (установить другие свойства) по желанию:

if handler_console is not None: 
    # first we need to remove to avoid duplication 
    logging.getLogger().removeHandler(handler_console) 
    formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') 
    handler_console.setFormatter(formatter) 
    # then add it back 
    logger.addHandler(handler_console) 

Answer 3

Мое решение:

import logging 

logger = logging.getLogger() 
logger.propagate = False