使用 python 日志记录过滤不同记录器的正确方法是什么? [英] What is a correct way to filter different loggers using python logging?

问题描述

我的目的是使用分层过滤进行多模块日志记录

logging 作者 Vinay Sajip 提出的方式，至少我猜是这样;-)

您可以跳到我希望它如何工作"

不幸的是，我很快了解到使用日志工具比我使用该语言的大多数其他经验要复杂得多，而且我已经犯了很多常见的(设计)错误，例如试图为多个模块甚至方案(使用 Python 记录器类为不同的日志级别生成多个日志).但显然还有更好的设计空间，花时间去寻找和学习它可能会更糟.所以，现在我希望我走在正确的轨道上.否则 Vinaj 将不得不澄清其余的 ;-)

我这样安排我的日志记录:

• 每个 python 模块都有自己的自己的记录器
• 每个记录器的名称与定义它的模块相同，例如logger = logging.getLogger(__name__)
• 像这样，每个模块内的代码可以使用自己的(本地定义的)记录器将日志消息(logging.LogRecord)发送到处理程序(logging.Handler)
• 使用logging.config 在配置日志时实现完全的灵活性(注意:在下面的代码中，我只是从 basicConfig 开始)

这种方法是推荐的方法，我同意其可能的优点.例如，我可以使用完全限定的模块名称(代码中已经存在的命名层次结构)打开/关闭外部库的调试.

现在为了获得更高级别的控制，我想使用 logging.Filter 类，以便能够仅过滤(允许)记录器层次结构中的选定子树.

这一切都很好，但是这里描述的过滤

<块引用>

Filter 实例用于对 LogRecords 进行任意过滤.Loggers 和 Handlers 可以选择使用 Filter 实例来过滤根据需要记录.基本过滤器类只允许事件低于记录器层次结构中的某个点.例如，一个过滤器用A.B"初始化将允许记录器A.B"记录事件，A.B.C"、A.B.C.D"、A.B.D"等，但不包括A.BB"、B.A.B"等.如果用空字符串初始化，所有事件都被传递.

仍然不适合我.

我的猜测是我对 LogRecords 传播背后的细节缺乏了解是问题的根源.在跳转到代码之前，我想在这里展示一个流程图(来自 食谱教程，起初我不知何故未能立即发现):

示例代码

我从两个模块示例开始，每个模块都使用自己的命名记录器:

bar.py:

导入日志logger = logging.getLogger(__name__)定义栏():logger.info('hello from ' + __name__)

foo.py:

导入日志从 bar 导入 bar，记录器为 bar_loggerlogger = logging.getLogger('foo')定义 foo():logger.info('hello from foo')如果 __name__ == '__main__':# 简单的日志设置.logging.basicConfig(级别=logging.INFO，format='%(asctime)s %(name)-20s %(levelname)-8s %(message)s',datefmt='%m-%d %H:%M')# 做一些工作.富()酒吧()

Logging 首先用 logging.basicConfig 构建(根记录器，它是在 import logging 由 __main__ 之后创建的，获取附加到它的流处理程序，因此我们有一个控制台)，已启用(相应的 Logger.disabled=False)并且模块记录器 bar 和 foo 都传播到根记录器(因此我们总共有三个记录器).

打印记录器打印 bar_logger打印日志记录.root# 印刷#<logging.Logger 对象在 0x7f0cfd520790>#<logging.Logger 对象在 0x7f0cfd55d710>#<logging.RootLogger 对象在 0x7f0cfd520550>

实际用例是当 bar 是我想要静音(过滤掉)的外部库时.

它是如何运作的，但我"不喜欢它

# 不喜欢bar_logger.addFilter(logging.Filter('foo'))# 做一些工作.富()酒吧()

仅打印

06-24 14:08 foo INFO 来自 foo 的你好

我希望它如何工作

我想集中过滤掉它，即在我的根记录器中，不需要导入所有外部模块的所有记录器.

logging.root.addFilter(logging.Filter('foo'))

印刷品

06-24 14:17 foo INFO 来自 foo 的你好06-24 14:17 bar INFO hello from bar

一定有一些明显/愚蠢的错误让我怀念:我不想要来自 bar 记录器的任何消息.嘿，但是有什么比在 SO 上总结所有更好的方法来找到它呢，伙计们?;-)

我将尝试找出 bar_logger 在发出任何内容之前等待根记录器做出决定的方式.我只是希望这确实是它应该首先工作的方式.

解决方案

解决方案

将过滤器添加到处理程序而不是记录器:

handler.addFilter(logging.Filter('foo'))

<小时>

说明

在您发布的流程图中，注意有两个菱形:

• 附加到 logger 的过滤器是否拒绝记录?
• 附加到 hander 的过滤器是否拒绝记录?

因此，您在拒绝 LogRecord 时会有两次波动.如果您将过滤器附加到根记录器，但通过 foo 或 bar 记录器启动 LogRecord，则 LogRecord 不会被过滤，因为 LogRecord 自由地通过 foo 或 bar 记录器并且根记录器过滤器永远不会进入玩.(再看流程图.)

相比之下，basicConfig 定义的 StreamHandler 能够过滤任何传递给它的 LogRecord.

所以:将过滤器添加到处理程序而不是记录器:

# foo.py导入日志进口酒吧logger = logging.getLogger('foo')定义 foo():logger.info('hello from foo')如果 __name__ == '__main__':# 简单的日志设置.logging.basicConfig(级别=logging.INFO，format='%(asctime)s %(name)-20s %(levelname)-8s %(message)s',datefmt='%m-%d %H:%M')对于 logging.root.handlers 中的处理程序:handler.addFilter(logging.Filter('foo'))富()酒吧.酒吧()

收益

06-24 09:17 foo INFO 来自 foo 的你好

<小时>

如果您想允许名称以 foo 或 bar 开头的记录器进行日志记录，但不允许来自任何其他记录器的记录，您可以像这样创建一个白名单过滤器:

导入日志foo_logger = logging.getLogger('foo')bar_logger = logging.getLogger('bar')baz_logger = logging.getLogger('baz')类白名单(日志记录.过滤器):def __init__(self, *whitelist):self.whitelist = [logging.Filter(name) for name in whitelist]def过滤器(自我，记录):返回 any(f.filter(record) for f in self.whitelist)logging.basicConfig(级别=logging.INFO，format='%(asctime)s %(name)-20s %(levelname)-8s %(message)s',datefmt='%m-%d %H:%M')对于 logging.root.handlers 中的处理程序:handler.addFilter(Whitelist('foo', 'bar'))foo_logger.info('你好来自 foo')# 06-24 09:41 foo INFO 来自 foo 的你好bar_logger.info('来自酒吧的你好')# 06-24 09:41 酒吧 INFO 来自酒吧的你好baz_logger.info('你好，来自 baz')# 如果 record.name 不以 'foo' 或 'bar' 开头，则没有输出，因为白名单过滤器

<小时>

同样，您可以使用以下方法将记录器名称列入黑名单:

类黑名单(白名单):def过滤器(自我，记录):返回不是 Whitelist.filter(self, record)

My purpose is to do a multi-module logging with hierarchical filtering

the way it is proposed by logging author Vinay Sajip, at least as far as I guess ;-)

You can skip to "How I want it to work"

Unfortunately, I learned very quickly that working with logging facilities is much more sophisticated than most of my other experience with the language and I already did a lot of common (design) mistakes, e.g. trying to achieve a centralized single Logger class logging for multiple modules or even schemes like (using Python logger class to generate multiple logs for different log levels). But apparently there is room for better design, and it might be worse spending time finding and learning it. So, right now I hope I am on the right track. Otherwise Vinaj will have to clarify the rest ;-)

I arrange my logging as this:

• Each python module has its own logger
• Each logger has a name same as the module where it is defined, e.g. logger = logging.getLogger(__name__)
• Like this, code inside each module can use its own (locally defined) logger to send logging messages (logging.LogRecord) to handlers (logging.Handler)
• Use logging.config to achieve full flexibility in configuring of the logging (Note: in the code below I just start with basicConfig)

Such approach is a recommended approach and I agree with its possible advantages. For example I can turn on/off DEBUG of external libraries using fully qualified module names (the naming hierarchy which already exists in the code).

Now to have a greater level of control I want to use logging.Filter class, to be able to filter (allow) only a selected subtree within the hierarchy of loggers.

This is all fine, but the filtering as described here

Filter instances are used to perform arbitrary filtering of LogRecords.

Loggers and Handlers can optionally use Filter instances to filter
records as desired. The base filter class only allows events which are
below a certain point in the logger hierarchy. For example, a filter
initialized with "A.B" will allow events logged by loggers "A.B",
"A.B.C", "A.B.C.D", "A.B.D" etc. but not "A.BB", "B.A.B" etc. If
initialized with the empty string, all events are passed.

is still not working for me.

My guess is that my lack of understanding the details behind LogRecords propagation is the source of the problem. Before jumping to code I want to show here a flow chart (from the cookbook tutorial which at first I somehow failed to immediately discover):

Example code

I start with two modules example, each uses it own named logger:

bar.py:

import logging


logger = logging.getLogger(__name__)


def bar():
    logger.info('hello from ' + __name__)

foo.py:

import logging
from bar import bar, logger as bar_logger


logger = logging.getLogger('foo')


def foo():
    logger.info('hello from foo')


if __name__ == '__main__':
    # Trivial logging setup.
    logging.basicConfig(
        level=logging.INFO,
        format='%(asctime)s %(name)-20s %(levelname)-8s %(message)s',
        datefmt='%m-%d %H:%M'
    )
    # Do some work.
    foo()
    bar()

Logging is first constructed with logging.basicConfig (root logger, which was created after import logging by __main__ gets a stream handler attached to it, so that we have a console), is enabled (respective Logger.disabled=False) and both module loggers bar and foo propagate to the root logger (so we have three loggers in total).

print logger
print bar_logger
print logging.root
# Prints 
#<logging.Logger object at 0x7f0cfd520790>
#<logging.Logger object at 0x7f0cfd55d710>
#<logging.RootLogger object at 0x7f0cfd520550>

The actual usecase is when bar is an external library that I want to silence (filter out).

How it works, but "me" don't like it

# Don't like it
bar_logger.addFilter(logging.Filter('foo'))
# Do some work.
foo()
bar()

prints only

06-24 14:08 foo                  INFO     hello from foo

How I want it to work

I want to filter it out centrally, i.e. at my root logger w/o the need to import all the loggers of all the external modules out there.

logging.root.addFilter(logging.Filter('foo'))

prints

06-24 14:17 foo                  INFO     hello from foo
06-24 14:17 bar                  INFO     hello from bar

There must be some obvious/stupid mistake that I miss: I don't want any messages from bar logger. Hey, but what is a better way to find it than summarizing all on SO, folks? ;-)

I will try to find out the way for bar_logger to wait for decision from the root logger, before emitting anything. I just hope that this is indeed how it is supposed to work in the first place.

解决方案

Solution

Add the filter to the handler rather than the logger:

handler.addFilter(logging.Filter('foo'))

---

Explanation

In the flow chart diagram you posted, notice there are two diamonds:

• Does a filter attached to logger reject the record?
• Does a filter attached to hander reject the record?

Thus, you get two swings at rejecting a LogRecord. If you attach the filter to the root logger, but initiate the LogRecord through, say, the foo or bar loggers, then the LogRecord does not get filtered because the LogRecord passes through the foo or bar loggers freely and the root logger filter never enters into play. (Look at the flow chart again.)

In contrast, the StreamHandler defined by basicConfig is capable of filtering any LogRecord passes to it.

So: add the filter to the handler rather than the logger:

# foo.py
import logging
import bar

logger = logging.getLogger('foo')

def foo():
    logger.info('hello from foo')

if __name__ == '__main__':
    # Trivial logging setup.
    logging.basicConfig(
        level=logging.INFO,
        format='%(asctime)s %(name)-20s %(levelname)-8s %(message)s',
        datefmt='%m-%d %H:%M')
    for handler in logging.root.handlers:
        handler.addFilter(logging.Filter('foo'))

    foo()
    bar.bar()

yields

06-24 09:17 foo                  INFO     hello from foo

---

If you want to allow logging from loggers whose name begins with foo or bar, but not from any other loggers, you could create a whitelist filter like this:

import logging
foo_logger = logging.getLogger('foo')
bar_logger = logging.getLogger('bar')
baz_logger = logging.getLogger('baz')

class Whitelist(logging.Filter):
    def __init__(self, *whitelist):
        self.whitelist = [logging.Filter(name) for name in whitelist]

    def filter(self, record):
        return any(f.filter(record) for f in self.whitelist)

logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s %(name)-20s %(levelname)-8s %(message)s',
    datefmt='%m-%d %H:%M')
for handler in logging.root.handlers:
    handler.addFilter(Whitelist('foo', 'bar'))

foo_logger.info('hello from foo')
# 06-24 09:41 foo                  INFO     hello from foo
bar_logger.info('hello from bar')
# 06-24 09:41 bar                  INFO     hello from bar
baz_logger.info('hello from baz')
# No output since Whitelist filters if record.name not begin with 'foo' or 'bar'

---

And similarly, you could blacklist logger names with this:

class Blacklist(Whitelist):
    def filter(self, record):
        return not Whitelist.filter(self, record)

这篇关于使用 python 日志记录过滤不同记录器的正确方法是什么?的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！