Python 交互式会话中的日志记录

Question

我正在尝试在我的Python 2.7应用程序中实现日志记录，发现它非常有用。然而，我注意到当交互式地运行Python时，每个日志消息都会打印多次。消息被打印的次数与我之前运行脚本的次数相同，因此似乎记录器在脚本结束时没有被正确清理（我猜测）。请考虑以下示例：

import sys
import logging

def main(argv=None):

    log = logging.getLogger('test')
    log.setLevel(logging.DEBUG)

    console_handler = logging.StreamHandler()
    console_handler.setFormatter(logging.Formatter("%(message)s"))
    log.addHandler(console_handler)

    log.info('Starting something...')
    log.info('Doing something...')
    log.info('Finished something.')

    logging.shutdown()

if __name__=='__main__':
    sys.exit(main(sys.argv[1:]))

打字

>>> import file.py
>>> file.main()

产生如下结果：

Starting something...
Doing something...
Finished something.

然后再次键入file.main()，结果为：

Starting something...
Starting something...
Doing something...
Doing something...
Finished something.
Finished something.

如果重复三次，每个消息都会出现三次，以此类推。有人知道为什么会这样吗？这是日志模块的预期行为吗？如果是，我该如何更改？如果按照脚本方式运行（python file.py），上述脚本只打印每个消息中的一个，与预期相符。

- Chris

Answer 1

是的，您正在创建和重复使用日志记录器的单个实例。添加到该记录器的每个处理程序也会记录消息。

您可能希望在模块级别或单独的函数中设置日志记录，以便仅运行一次。

也许像这样：

import atexit
import sys
import logging

log = logging.getLogger('test')
log.setLevel(logging.DEBUG)

console_handler = logging.StreamHandler()
console_handler.setFormatter(logging.Formatter("%(message)s"))
log.addHandler(console_handler)

def shutdown_logging():
    logging.shutdown()    

atexit.register(shutdown_logging)

def main(argv=None):
    log.info('Starting something...')
    log.info('Doing something...')
    log.info('Finished something.')


if __name__=='__main__':
    sys.exit(main(sys.argv[1:]))

- stderr

Answer 2

尝试以下方法作为解决办法：

if len(logging.root.handlers) == 0:
     log.add_handler(console_handler)

日志模块使用全局静态记录器对象，该对象在您使用解释器时跨会话保持不变。因此，每次调用add_handler都会添加一个全新的流处理器，但不会删除旧的处理器。日志只是通过其处理器进行迭代，并将输出发送到每个处理器，因此每次运行时都会有相同内容的新副本发送到控制台。

- beer_monk

---

好的，谢谢。我原以为 logging.shutdown() 的目的是删除添加到根记录器的任何处理程序。但是，现在查看了文档后才发现，它只是用于刷新和关闭任何处理程序（不是删除它们）。 - Chris

Answer 3

在重新加载配置之前，在调用file.main()之前，您可以每次删除所有处理程序。

file.logging.getLogger('test').handlers = []

---

注意（主观）：

正如@stderr所写，鼓励在模块级别定义日志记录器。然而，我认为在应用程序入口处设置它们也是一个好的实践。因此，在if __name__=='__main__'之后添加处理程序，或者在您的情况下，在您的（I）Python控制台中。这样，导入模块不会创建各种处理程序，而只有选择执行您模块的某些函数的人才会创建这些处理程序。

- PlasmaBinturong

Answer 4

这是@beer_monk解决方案的替代方法，即使您在其他地方触及了根处理程序，它也能正常工作。我在这里使用了__name__而不是'test'，这样在其他模块中重用代码就更容易，也许可以将其转换为一个以__name__为参数的函数。

if not __name__ in logging.Logger.manager.loggerDict:
    new_logger = logging.getLogger(__name__)
    new_logger.setLevel(logging.DEBUG)

    console_handler = logging.StreamHandler()
    console_handler.setFormatter(logging.Formatter("%(message)s"))
    new_logger.addHandler(console_handler)
log = logging.getLogger(__name__)

- kuzzooroo