python - 使用logging.info而不是logger.info会破坏StreamHandler

Question

我正在使用两个日志处理程序。一个是 DEBUG 及以上级别的文件，另一个是 WARNING 及以上级别的控制台。我正在使用许多模块，其中一些是外部模块(使用 pip 安装)。当调用 logging.info()(与 logger.info() 相反)时，这会破坏控制台记录器的设置:

import logging
import logging.handlers
import sys, os
from demo_module import something, something_else

logger = logging.getLogger("demo")
logger.setLevel(logging.DEBUG)
main_handler = logging.FileHandler('demo.log')
formatter = logging.Formatter('%(asctime)s %(name)s %(levelname)-8s %(filename)s:%(lineno)d %(message)s')
main_handler.setFormatter(formatter)
logger.addHandler(main_handler)

# log serious issues to console
console_handler = logging.StreamHandler(stream=sys.stderr)
console_handler.setLevel(logging.WARNING)
console_handler.setFormatter(formatter)
logger.addHandler(console_handler)
logger.debug('this is a debug')
logger.info('this is an info')
logger.warning('this is a warning')
logger.error('this is an error')
logger.critical('reactor has melted down')
something()
logger.info('after something')
something_else()
logger.info('after something else')

demo_module.py 所在位置:

import logging
logger = logging.getLogger('demo')

def something():
    logger.info('something needs to be done')
    a = 1+1
    logger.info('something has been done')
    logger.error('some banale error')

def something_else():
    logger.info('calling logger.info')
    # OOPS, calling logging instead of logger here
    logging.info("module may use logging directly instead of logger")
    logger.info('logger.info called')

如您所见，在 demo_module.something_else() 内部调用了 logging.info 而不是 logger.info。

控制台的输出如下所示:

% python logger.py 
2017-10-07 17:45:08,077 demo WARNING  logger2.py:21 this is a warning
2017-10-07 17:45:08,077 demo ERROR    logger2.py:22 this is an error
2017-10-07 17:45:08,077 demo CRITICAL logger2.py:23 reactor has melted down
2017-10-07 17:45:08,078 demo ERROR    demo_module.py:8 some banale error
INFO:demo:logger.info called
INFO:demo:after something else

如您所见，最后两行丢失了我最初为控制台处理程序设置的所有设置，例如级别和格式化程序。如果这只是我的代码，我可以找到这个有问题的 logging.info() 语句并替换它，但有些代码不是我的，而是第三方的，因此超出了我的控制范围。知道如何让这些设置保持不变吗？

Answer 1

默认情况下，模块级日志记录函数将调用 logging.basicConfig()尝试配置根记录器。 Docs :

... module-level convenience functions, which delegate to the root logger, call basicConfig() to ensure that at least one handler is available.

logging.basicConfig的docs状态:

This function does nothing if the root logger already has handlers configured for it.

因此，解决方案是在调用任何模块级日志函数之前在根记录器上配置处理程序，同时指示记录器不要在记录器层次结构中传播消息，以避免重复输出。

import logging
import logging.handlers
import sys, os
from demo import something, something_else

formatter = logging.Formatter('%(asctime)s %(name)s %(levelname)-8s %(filename)s:%(lineno)d %(message)s')

# Configure the root logger.
root_logger = logging.getLogger()
root_logger.setLevel(logging.DEBUG)
# Configure file handler.
root_main_handler = logging.FileHandler('demo.log')
root_main_handler.setFormatter(formatter)
root_logger.addHandler(root_main_handler)
# Configure console handler.
root_console_handler = logging.StreamHandler(stream=sys.stderr)
root_console_handler.setLevel(logging.WARNING)
root_console_handler.setFormatter(formatter)
root_logger.addHandler(root_console_handler)

logger = logging.getLogger("demo")
logger.setLevel(logging.DEBUG)
main_handler = logging.FileHandler('demo.log')
main_handler.setFormatter(formatter)
logger.addHandler(main_handler)

# log serious issues to console
console_handler = logging.StreamHandler(stream=sys.stderr)
console_handler.setLevel(logging.WARNING)
console_handler.setFormatter(formatter)
logger.addHandler(console_handler)
# Don't propagate messages up to the root logger.
logger.propagate = False
logger.debug('this is a debug')
logger.info('this is an info')
logger.warning('this is a warning')
logger.error('this is an error')
logger.critical('reactor has melted down')
something()
logger.info('after something')
something_else()
logger.info('after something else')

控制台输出:

2017-10-07 18:46:50,644 demo WARNING  run.py:35 this is a warning
2017-10-07 18:46:50,644 demo ERROR    run.py:36 this is an error
2017-10-07 18:46:50,644 demo CRITICAL run.py:37 reactor has melted down
2017-10-07 18:46:50,645 demo ERROR    demo.py:8 some banale error

文件输出:

2017-10-07 18:46:50,644 demo DEBUG    run.py:33 this is a debug
2017-10-07 18:46:50,644 demo INFO     run.py:34 this is an info
2017-10-07 18:46:50,644 demo WARNING  run.py:35 this is a warning
2017-10-07 18:46:50,644 demo ERROR    run.py:36 this is an error
2017-10-07 18:46:50,644 demo CRITICAL run.py:37 reactor has melted down
2017-10-07 18:46:50,645 demo INFO     demo.py:5 something needs to be done
2017-10-07 18:46:50,645 demo INFO     demo.py:7 something has been done
2017-10-07 18:46:50,645 demo ERROR    demo.py:8 some banale error
2017-10-07 18:46:50,645 demo INFO     run.py:39 after something
2017-10-07 18:46:50,645 demo INFO     demo.py:11 calling logger.info
2017-10-07 18:46:50,645 root INFO     demo.py:13 module may use logging directly instead of logger
2017-10-07 18:46:50,645 demo INFO     demo.py:14 logger.info called
2017-10-07 18:46:50,645 demo INFO     run.py:41 after something else