Python 日志记录模块 : duplicated console output [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')

我在新启动的内核上运行它。 文件处理程序 按预期工作。但是在控制台输出中，我得到了一些重复的消息:

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 .

观察结果如下:在普通 python 或 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 notebook 中，会立即安装默认的 stderr 根记录器:

In [1]: import logging

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

也许我遗漏了什么，但我认为在笔记本中，不应该自动安装处理程序，原因有很多:

1. 这将使标准 python、IPython 控制台和 IPython notebook 之间的默认日志记录配置保持一致。
2. 一旦用户使用根记录器写入日志消息，处理程序就会自动安装，因此日志消息不会轻易被遗漏。
3. 在当前行为下，配置子记录器的库和该子记录器的处理程序可能会很容易地向笔记本发送垃圾邮件，其中包含本应只存在于日志文件(或其他地方)的调试消息。例如，astropy 似乎有这样的问题，而我自己的图书馆也遇到了同样的问题。问题是对于这样的图书馆，没有“干净”的解决方法。该库可以在导入时删除根记录器的处理程序，这是 hack-y。它可以将自己的记录器的 propagate 属性设置为 False，这样日志消息就不会传播到根记录器，但这不仅会禁止调试输出进入笔记本，还有更严厉的消息。此外，如果用户愿意，它还可以防止用户实际捕获所有日志输出。

另一种方法可能是添加一个配置选项，为自动添加的流处理程序指定日志级别，这样就可以忽略不太严重的消息自动显示在笔记本中。但这仍然会使 IPython 控制台和 IPython 笔记本之间的行为有所不同。

我看到确保没有设置默认处理程序的唯一缺点是某些正在使用的库/笔记本可能依赖于此行为并积极解决它，例如，如果它们检测到它们正在运行，则禁用它们自己的处理程序在 ipython 笔记本中。这种情况可能会随着这种变化而中断。

因此将 logger.propagate 设置为 False 或使用 reload(logging) 将防止重复输出，但取决于会产生副作用。

请注意，reload 在较新版本的 python(3.4，可能更早)中不可用。从 3.1 开始，请参阅 importlib.reload