python - 为什么日志记录在 python 中以这种方式运行

Question

所以，最近，我在我的项目中遇到了一些奇怪的行为，所以我做了一个小测试来重现该行为。这是一个完整的代码:

import logging
from logging import config

config.dictConfig({
    'version': 1,
    'formatters': {
        'fmt_root':    {'format': '[ /        ] - %(levelname)s - %(name)s - %(message)s'},
        'fmt_pkg':     {'format': '[ /pkg     ] - %(levelname)s - %(name)s - %(message)s'},
        'fmt_pkg_sub': {'format': '[ /pkg/sub ] - %(levelname)s - %(name)s - %(message)s'},
    },
    'handlers': {
        'hnd_root': {
            'class': 'logging.StreamHandler',
            'level': logging.DEBUG,
            'stream': 'ext://sys.stdout',
            'formatter': 'fmt_root',
        },
        'hnd_pkg': {
            'class': 'logging.StreamHandler',
            'level': logging.DEBUG,
            'stream': 'ext://sys.stdout',
            'formatter': 'fmt_pkg',
        },
        'hnd_pkg_sub': {
            'class': 'logging.StreamHandler',
            'level': logging.DEBUG,
            'stream': 'ext://sys.stdout',
            'formatter': 'fmt_pkg_sub',
        },
    },
    'root': {
        'handlers': ['hnd_root'],
        'level': logging.DEBUG,
    },
    'loggers': {
        'pkg': {
            'handlers': ['hnd_pkg'],
            'level': logging.WARNING,
            'propagate': True,
        },
        'pkg.sub': {
            'handlers': ['hnd_pkg_sub'],
            'level': logging.INFO,
            'propagate': True,
        },
    },
})

logging.getLogger().info('message 1')
logging.getLogger('pkg').info('message 2')
logging.getLogger('pkg.sub').info('message 3')

这个小程序的输出是:

[ /        ] - INFO - root - message 1
[ /pkg/sub ] - INFO - pkg.sub - message 3
[ /pkg     ] - INFO - pkg.sub - message 3
[ /        ] - INFO - pkg.sub - message 3

现在，这不是我自然期望的输出。为什么“消息 2”没有记录在根记录器上(消息级别是信息，根接受调试级别)，为什么“消息 3”记录在“pkg”记录器上(消息级别是信息，pkg 接受警告)？

我做了一些研究，我发现消息级别只根据消息直接发布到的记录器进行检查 - 所有父记录器级别直到根都没有检查，只检查它们的处理程序级别。 这对我来说似乎很奇怪。对此有解释吗？为什么会这样？这有哪些用例？

PS:如果我切换处理程序和记录器级别，我从这段代码中得到的行为正是我所期望的行为:

[ /        ] - INFO - root - message 1
[ /        ] - INFO - pkg - message 2
[ /pkg/sub ] - INFO - pkg.sub - message 3
[ /        ] - INFO - pkg.sub - message 3

Answer 1

首先使用记录器的级别，作为通过/不通过检查。这是因为一个记录器可以有多个处理程序。例如，您可以有一个 FileHandler写入磁盘 INFO 及以上和 SMTPHandler仅发送电子邮件 CRITICAL。
如果通过该检查，则日志将发送到记录器处理程序，并且当传播设置为 True 时，它还会发送到您调用的日志的父记录器的处理程序，忽略级别检查在那些记录器中。

这样，message 2根本不会打印，因为它没有通过logger的级别检查，但是message 3会打印3次，因为那个logger设置为低于 INFO' 的级别，\、pkg 和 pgk.sub 的处理程序是设置在低于 INFO 的级别。

简而言之，记录器级别意味着“我应该将它发送给处理程序吗？”处理程序级别意味着“我应该将其写入磁盘/控制台/套接字等吗？”。

示例 1。

Logger  | Logger level | Handler Level
/       | CRITICAL     | DEBUG
pkg     | CRITICAL     | DEBUG
pkg.sub | DEBUG        | DEBUG

使用 logging.getLogger('pkg.sub').debug('message 3') 将打印:

[ /pkg/sub ] - DEBUG - pkg.sub - message 3
[ /pkg     ] - DEBUG - pkg.sub - message 3
[ /        ] - DEBUG - pkg.sub - message 3

示例 2。

Logger  | Logger level | Handler Level
/       | CRITICAL     | INFO
pkg     | CRITICAL     | DEBUG
pkg.sub | DEBUG        | DEBUG

使用 logging.getLogger('pkg.sub').debug('message 3') 将打印:

[ /pkg     ] - DEBUG - pkg.sub - message 3
[ /        ] - DEBUG - pkg.sub - message 3

示例 3。

Logger  | Logger level | Handler Level
/       | CRITICAL     | DEBUG
pkg     | CRITICAL     | INFO
pkg.sub | DEBUG        | DEBUG

使用 logging.getLogger('pkg.sub').debug('message 3') 将打印:

[ /pkg/sub ] - DEBUG - pkg.sub - message 3
[ /        ] - DEBUG - pkg.sub - message 3

为了得到你想要的结果，你需要这样的设置:

Logger  | Logger level | Handler Level
/       | DEBUG        | DEBUG
pkg     | INFO         | WARNING
pkg.sub | INFO         | DEBUG