Python root logger 解密

前言

本文主要讲解Python3logging模块中root logger的一些小知识. 在阅读本文之前希望读者了解logging模块的基本用法.

正文

root logger是logging 模块中最主要的部分, 也是无需配置可以直接使用的logger, 今天主要讲解一下root logger的默认配置.

1. 如何访问root logger?

在Python中, root logger是一个Logger对象, 而所有的配置都是其属性, 所以了解root logger的第一步就是访问这个对象, 有以下两种作法:

# 这是访问所有logger的通用方法, 当没有参数时, 默认访问`root logger`
In [1]: import logging
In [6]: logging.getLogger()
Out[6]: <RootLogger root (WARNING)>


# root logger 也是 logging 模块的属性, 我们也可以直接点选
In [12]: logging.root
Out[12]: <RootLogger root (WARNING)>

# 二者等效
In [15]: logging.getLogger() == logging.root
Out[15]: True

2. 如何访问root logger 的Handler?

Handler的主要作用是将我们的LogRecord发送到指定位置, 而我们在使用root logger时, 默认是显示在终端中的, 那么这个默认值是在哪里设置的? 终端中显示的是stdout 还是 stderr?

首先做测试:

In [16]: logging.root.handlers
Out[16]: []

我们可以看到, Handler是存放在一个列表中, 但是root logger的默认值没有任何Handler, 那么是谁处理的我们的LogRecordne呢?

The event is output using a ‘handler of last resort’, stored in logging.lastResort. This internal handler is not associated with any logger, and acts like a StreamHandler which writes the event description message to the current value of sys.stderr (therefore respecting any redirections which may be in effect). No formatting is done on the message - just the bare event description message is printed. The handler’s level is set to WARNING, so all events at this and greater severities will be output.

查文档之后发现, 默认的Handler是存放在logging.lastResort属性中, 我们可以访问一下:

In [17]: logging.lastResort
Out[17]: <_StderrHandler <stderr> (WARNING)>

这样我们就知道了在我们未配置root logger时, 我们使用的Handler是StderrHandler, 级别为 warning, 输入到stderr.

原理懂了, 那么有什么用呢??

logging 重定向失败问题

我们在运行Python脚本时, 需要把其logging信息重定向到其他文件, 这时候我们就要注意需要使用stderr重定向, 而不是stdout重定向:

# 测试文件内容
lihongjie@Lenovo-G505 ~ $ cat log.py 
import logging

logging.warning('this is warning.')
# stdout 重定向
lihongjie@Lenovo-G505 ~ $ python log.py > /dev/null
WARNING:root:this is warning.
# stderr 重定向
lihongjie@Lenovo-G505 ~ $ python log.py 2> /dev/null
lihongjie@Lenovo-G505 ~ $ 

Pycharm满屏红字

当我们在Pycharm中运行Python脚本时, 它的默认设置stderr显示是红色字体:

logging_red.png

特别是我们在使用Scrapy框架时, log 信息全是红色的, 不方便查看. 解决方法也很简单, 因为我们没有设置任何Handler, 所以root logger才会使用默认的Handler, 我们只需要添加一个Handler就可以了:

import sys

logging.root.addHandler(logging.StreamHandler(sys.stdout))

# 或者使用basicConfig来设置

logging.basicConfig(stream=sys.stdout)

这里, 我们添加一个stdout的 StreamHandler, 这样信息就可以显示在stdout中了.

接下来让我们看一下默认Handler的底层实现:

class _StderrHandler(StreamHandler):
    """
    This class is like a StreamHandler using sys.stderr, but always uses
    whatever sys.stderr is currently set to rather than the value of
    sys.stderr at handler construction time.
    """
    def __init__(self, level=NOTSET):
        """
        Initialize the handler.
        """
        Handler.__init__(self, level)

    @property
    def stream(self):
        return sys.stderr

我们可以看出, _StderrHandler是StreamHandler的子类, 这里的stream属性是当前全局变量中sys.stderr的值.

基于这个原理, 我们可以对上述方法做出如下改进:

import sys

sys.stderr = sys.stdout

对比之前手动添加Handler的作法, 这个方法的好处是:

我们只是将stderr的信息重定向至stdout, 并不需要添加和配置Handler, 因为在类似Scrapy的框架中, log信息是格式化过的, 你必须手动再次配置一次, 比较繁琐. 这就类似于bash中的:

some command 2>&1 

3. 默认的Formater是在哪里设置的?

在默认情况下, 我们看到的log信息是这样的:

WARNING:root:this is warning

那么, 默认的Formatter是在哪里设置的呢?

In [17]: logging.BASIC_FORMAT
Out[17]: '%(levelname)s:%(name)s:%(message)s'

默认的Formatter保存在全局变量BASIC_FORMAT, 当我们不带任何参数实例化一个Formatter时, 这个参数就会被使用.

4. 默认的Filter是什么?

我们之前讲了Logger, Formatter以及Handler, 接下来将一下Filter.

Filter类似于Handler, 存放在列表中:

In [24]: logging.root.filters
Out[24]: []

可以看到默认的filters为空, 也就是说没有过滤任何log信息, 它的实现原理如下:

def filter(self, record):

    rv = True
    for f in self.filters:
        if hasattr(f, 'filter'):
            result = f.filter(record)
        else:
            result = f(record) # assume callable - will raise if not
        if not result:
            rv = False
            break
    return rv

filter函数会遍历所有的filters列表, 使用filter.filter(record)对其进行判定, 并返回bool值, 如果返回False, 那么这个log信息就会被拒绝. 当所有的filters都返回True, 那么这个log信息就会被接受.

5. propagate有什么作用?

从官方文档中提供的流程图可以看出,propagate会把当前的logger设置为其parent, 并将record传入parent的Handler, 这就会导致一个有趣的现象:

# 给root logger 添加一个Handler
In [42]: import sys

In [43]: logging.basicConfig(stream=sys.stdout, level=logging.DEBUG)

In [44]: logging.root.handlers
Out[44]: [<StreamHandler <stdout> (NOTSET)>]


# 新建一个child logger

In [5]: child = logging.getLogger('child')

In [6]: child.parent
Out[6]: <RootLogger root (DEBUG)>

In [7]: child.handlers
Out[7]: []


# log 信息
In [8]: child.debug('this is a debug message')
DEBUG:child:this is a debug message

我们的child logger 是没有Handler的, 但是我们的record还是被发送到了终端, 这就是propagate的作用, 它把子代的所有record都发送给了父代, 循环往复, 最终到达root, 如果我们在子代中设置了hander, 那么一个record就会被发送两次:

In [9]: child.addHandler(logging.StreamHandler())

In [10]: child.debug('this message will be handled twice')
this message will be handled twice
DEBUG:child:this message will be handled twice

第一次是子代发送到stderr(默认), 第二次是使用root的Handler.

所以在文档中提到:

Child loggers propagate messages up to the handlers associated with their ancestor loggers. Because of this, it is unnecessary to define and configure handlers for all the loggers an application uses. It is sufficient to configure handlers for a top-level logger and create child loggers as needed.

我们没必要配置子代的Handler, 因为最终虽有的record都会被转发到root, 我们只需要配置它就可以了.

总结

本文主要讲解了root logger的默认配置方法以及一些常见的问题, 其实root logger只是一个普通的Logger对象而已, 这里将的方法都适用于其他自定义的logger, 希望这篇文章可以帮助到大家.