Python 2.7：在两个 python 脚本中使用 `logging` 模块时，日志显示两次

Question

上下文：

Python 2.7。

同一文件夹中的两个文件：

• 首先：主脚本。
• 第二个：自定义模块。

目标：

可以在没有任何冲突的情况下使用logging 模块（参见下面的输出）。

文件：

a.py:

import logging
from b import test_b

def test_a(logger):
    logger.debug("debug")
    logger.info("info")
    logger.warning("warning")
    logger.error("error")

if __name__ == "__main__":
    # Custom logger.
    logger = logging.getLogger("test")

    formatter = logging.Formatter('[%(levelname)s] %(message)s')
    handler = logging.StreamHandler()
    handler.setFormatter(formatter)

    logger.setLevel(logging.DEBUG)
    logger.addHandler(handler)

    # Test A and B.
    print "B"
    test_b()
    print "A"
    test_a(logger)

b.py:

import logging

def test_b():
    logging.debug("debug")
    logging.info("info")
    logging.warning("warning")
    logging.error("error")

输出：

如下所示，日志显示两次。

python a.py
B
WARNING:root:warning
ERROR:root:error
A
[DEBUG] debug
DEBUG:test:debug
[INFO] info
INFO:test:info
[WARNING] warning
WARNING:test:warning
[ERROR] error
ERROR:test:error

有人能解决这个问题吗？

编辑：不运行 test_b() 将不会导致日志重复和正确的日志格式（预期）。

Answer 1

我不确定我是否理解你的情况，因为描述与输出不匹配……但我想我知道你的问题是什么。

正如the docs 解释：

注意：如果您将处理程序附加到记录器及其一个或多个祖先，它可能会多次发出相同的记录。通常，您不需要将处理程序附加到多个记录器 - 如果您只是将其附加到记录器层次结构中最高的适当记录器，那么它将看到所有后代记录器记录的所有事件，前提是它们的传播设置保留为 True。一个常见的场景是只将处理程序附加到根记录器，并让传播处理其余的事情。

“常见场景”通常效果很好，但我假设您需要将自定义处理程序附加到“测试”，而不影响根记录器。

因此，如果您想要在“测试”上使用自定义处理程序，并且您不希望它的消息也发送到根处理程序，答案很简单：关闭它的 propagate 标志：

logger.propagate = False

---

仅当您调用test_b 时才会发生这种情况的原因是，否则，根记录器永远不会被初始化。第一次登录到任何未配置的记录器时，它会在该记录器上有效地执行basicConfig()。因此，调用logging.getLogger().info(msg) 或logging.info(msg) 将配置根记录器。但是从子记录器传播不会。

我相信这在日志记录 HOWTO 或食谱中的某处进行了解释，都在 HOWTOs 下，但在实际的模块文档中，它隐藏在 logging.log 下关于线程的注释中间：

注意： 上述委托给根记录器的模块级函数不应在线程中使用，在 Python 2.7.1 和 3.2 之前的版本中，除非至少有一个处理程序已被在线程启动之前添加到根记录器。 这些便利函数调用 basicConfig() 以确保至少有一个处理程序可用； ;在 Python 的早期版本中，这可能（在极少数情况下）导致处理程序被多次添加到根记录器，这反过来又可能导致同一事件的多条消息。

很容易看出你是怎么错过的！