使用logging.info而不是logger.info wrecks

Question

我使用两个日志处理程序。一个文件用于级别调试和以上，另一个文件到控制台，用于警告和上面。我正在使用许多模块，其中一些模块是外部的(使用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()以尝试配置根记录器。文档

..。委托给根记录器的模块级方便函数调用basicConfig()，以确保至少有一个处理程序可用。

logging.basicConfig的文档状态：

如果根记录器已经为其配置了处理程序，则此函数将不执行任何操作。

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

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