Python日志模块：重复的控制台输出[IPython Notebook/Qtconsole]

Question

我正在尝试使用Python的logging模块进行实验，但是在这里感到有些困惑。以下是创建一个logger的标准脚本，然后创建并添加文件处理器和控制台处理器到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

我猜那些带时间戳的日志消息来自用户定义的控制台处理程序，但是重复的消息从哪里来？ 我能摆脱它们吗，比如只保留每两行？ 非常感谢任何帮助。

- Jianxun Li

---

你在哪个开发环境中运行？PyCharm，Eclipse，WingIDE，还是IDLE？ - Peter Wood

笔记本电脑出了问题，但在 Pycharm 和 Ipython 中代码运行正常。 - Padraic Cunningham

在我的ipython中直接运行有效，尝试在notebook中导入后添加reload(logging)。 - Padraic Cunningham

等我回到电脑上会处理的，问题基本上是IPython使用了日志记录模块，如果你在笔记本中启动时运行import logging;logging.getLogger().handlers，你会看到一个已经在使用中的fh。 - Padraic Cunningham

尝试设置logger.propagate = False。 - Peter Wood

Answer 1

问题已经在这里提出。

观察结果如下：在正常的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笔记本之间保持一致。
2. 只要用户使用根记录器写入日志消息，处理程序就会自动安装，因此日志消息不容易被忽略。
3. 按照当前的行为，配置子记录器及其处理程序的库可能会轻松地使用调试消息垃圾邮件笔记本，而这些消息只应该进入日志文件（或其他位置）。例如，astropy似乎存在这样的问题，我也遇到了自己的库的同样问题。问题是对于这样的库，没有“干净”的解决方法。该库可以在导入时删除根记录器的处理程序，这是hack-y的。它可以将其自己的记录器的传播属性设置为False，以便日志消息不会传播到根记录器，但这不仅禁用了调试输出进入笔记本，还禁止用户实际捕获所有日志输出（如果他们想要的话）。

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

我唯一看到的缺点是确保没有设置默认处理程序的库/笔记本可能依赖于此行为并积极解决它，例如如果它们检测到它们正在运行ipthon笔记本，则禁用自己的处理程序。这样的情况可能会因此更改而破坏。

因此，将logger.propagate设置为False或使用reload（logging）将防止重复输出，但取决于具体情况可能会产生副作用。

请注意，reload在较新版本的Python（3.4，可能更早）中不可用。从3.1开始，请参见importlib.reload

- Padraic Cunningham

---

对我来说，默认的StreamHandler也适用于IPython Qt控制台，而在从命令行启动的普通IPython中则不存在。 - Bas Swinckels

Answer 2

当你执行

时

，

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

您正在创建另一个StreamHandler。为了解决问题，您应该从iPython中捕获StreamHandler：

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)

- Euclides

---

我尝试过了，但它不起作用。更简单的解决方案是在“logger = logging.getLogger()”之后设置：“logger.propagate = False”。 - Maks

Answer 3

我的解决方案是：

import logging

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

- Maks

---

对我没用，所以我在Python 2.7中使用了 logger.handlers.pop() ，它解决了问题。 - radtek