Menu
Article

Python Logging源码解析

NodeKey

NodeKey

• 6 min read

前言

python的logging是python内置打印模块，近期因为需要解决框架里的日志耗时长的问题，所以拜读了一下源码，其基础功能的实现源码并不长，截至今日11.15日，python3.8的logging/init.py 大概有4000+行，再算上一些内置方便的handler与config的话，大概会有6000行，总体来说并不是很多。

basicConfig

basicConfig是快速且简单配置 root logger 的函数，在一个进程中，默认情况下，这个函数它只会生效一次。因为它有如下判断

if len(root.handlers) == 0:
    pass

后来这个只生效一次为人所诟病，就又加了一个force参数，能够对其强制更新。
下面说明一下所有参数

参数名称 参数描述
force 强制更新
filename 日志输出到文件的文件名
format 日志输出的格式
datefat 日志附带日期时间的格式
style 格式占位符，默认为 "%" 和 “{}”
level 设置日志输出级别
stream 定义输出流，用来初始化 StreamHandler 对象，不能 filename 参数一起使用，否则会ValueError 异常
handles 定义处理器，用来创建 Handler 对象，不能和 filename 、stream 参数一起使用，否则也会抛出 ValueError 异常

以下是源码, 非常浅显易懂:

def basicConfig(**kwargs):
    _acquireLock()
    try:
        if len(root.handlers) == 0:
            handlers = kwargs.pop("handlers", None)
            if handlers is None:
                if "stream" in kwargs and "filename" in kwargs:
                    raise ValueError("'stream' and 'filename' should not be "
                                     "specified together")
            else:
                if "stream" in kwargs or "filename" in kwargs:
                    raise ValueError("'stream' or 'filename' should not be "
                                     "specified together with 'handlers'")
            if handlers is None:
                filename = kwargs.pop("filename", None)
                mode = kwargs.pop("filemode", 'a')
                if filename:
                    h = FileHandler(filename, mode)
                else:
                    stream = kwargs.pop("stream", None)
                    h = StreamHandler(stream)
                handlers = [h]
            dfs = kwargs.pop("datefmt", None)
            style = kwargs.pop("style", '%')
            if style not in _STYLES:
                raise ValueError('Style must be one of: %s' % ','.join(
                                 _STYLES.keys()))
            fs = kwargs.pop("format", _STYLES[style][1])
            fmt = Formatter(fs, dfs, style)
            for h in handlers:
                if h.formatter is None:
                    h.setFormatter(fmt)
                root.addHandler(h)
            level = kwargs.pop("level", None)
            if level is not None:
                root.setLevel(level)
            if kwargs:
                keys = ', '.join(kwargs.keys())
                raise ValueError('Unrecognised argument(s): %s' % keys)
    finally:
        _releaseLock()

Logger

上文有说明，basicConfig进行配置配置的是root logger, 其本质上仍然是一个logger。
但使用basicConfig 进行配置 root logger 并不能全面而详细的进行配置。而如果我们需要全面自定义一个logger，其实只要创建一个即可。

这里我们可以先简单看一下Logger的整体架构。

logging arch

其整体流程还是比较简单的。下面我将以源码结合流程图对其进行解析。

  1. 判断调用的level是否被支持。
    这块判断其实并没有代码，而是通过将一个logger会显式地调用与支持的level相对应的函数，然后这个函数去将这个level传进_log函数。

见下代码所示，通过将指定的'宏'（INFO, WARNING，宏需要注册，这些宏在本质上都是数字，如果没有进行注册，会在打印的时候出错）传进_log函数中。而这些显式函数都是可以通过传入与之相应的宏来保证这个调用level是可以被支持的。

    def info(self, msg, *args, **kwargs):
        if self.isEnabledFor(INFO):
            self._log(INFO, msg, args, **kwargs)
            
    def warning(self, msg, *args, **kwargs):
        if self.isEnabledFor(WARNING):
            self._log(WARNING, msg, args, **kwargs)

而如果真的有人会在info函数中，传入WARNING宏，那也是没问题的……
而又如果真的有人会在info函数中，传入一个没有注册过的参数，其实也不会有问题，看下调用栈

    def info(self, msg, *args, **kwargs):
        if self.isEnabledFor(INFO):
            self._log(INFO, msg, args, **kwargs)
         
        
    def _log(self, level, msg, args, exc_info=None, extra=None, stack_info=False):
        # 省略部分无关代码
        record = self.makeRecord(self.name, level, fn, lno, msg, args,
                                 exc_info, func, extra, sinfo)
        self.handle(record)


    def makeRecord(self, name, level, fn, lno, msg, args, exc_info,
                   func=None, extra=None, sinfo=None):

        rv = _logRecordFactory(name, level, fn, lno, msg, args, exc_info, func,sinfo)
        # 省略部分无关代码
        return rv
        
        
        _logRecordFactory = LogRecord # 本质上默认使用 LogRecord


class LogRecord(object):
    def __init__(self, name, level, pathname, lineno,
                 msg, args, exc_info, func=None, sinfo=None, **kwargs):
        # 省略部分无关代码
        self.levelname = getLevelName(level) #此处
        self.levelno = level 
        # 省略部分无关代码
        
def getLevelName(level):
    result = _levelToName.get(level)
    if result is not None:
        return result
    result = _nameToLevel.get(level)
    if result is not None:
        return result
    return "Level %s" % level

后面的调用栈就不展开了，在最后调用getLevelName的时候，会根据level找到注册表中对应注册字符串，如果没有则会反向查找，如果还是没有，就会返回一个固定格式字符串。

  1. 创建 LogRecord 对象, 将 LogRecord 对象传给当前的 logger, 如果注册到 Logger 对象中的 Filter 对象过滤后返回 False，则不记录日志，流程结束，否则，则向下执行。
    调用栈如下：

    def _log(self, level, msg, args, exc_info=None, extra=None, stack_info=False):
        # 省略部分无关代码
        record = self.makeRecord(self.name, level, fn, lno, msg, args,
                                 exc_info, func, extra, sinfo)
        self.handle(record)
        

    def handle(self, record):
        if (not self.disabled) and self.filter(record): 
            self.callHandlers(record)

在Logger源码中，并没有关于filter的定义，但仔细观察发现，Logger 是Filterer的子类，Filterer中会有filter函数，会对每一个注册的Filter进行遍历对其过滤。

    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

Filterer中的filter数组默认为空，需要自行注册。

  1. logger 再将其传递给其所有的 handler，在图中右边的子流程中，经过该 handler 注册的所有filter对象过滤后，会将日志信息输出到对应的日志文件中，否则不进行任何操作。
    调用栈如下：
    def handle(self, record):
        if (not self.disabled) and self.filter(record):
            self.callHandlers(record)
            
    def callHandlers(self, record):
        c = self
        found = 0
        while c:
            for hdlr in c.handlers:
                found = found + 1
                if record.levelno >= hdlr.level:
                    hdlr.handle(record)
            # 省略部分无关代码
        # 省略部分无关代码

    def handle(self, record):
        rv = self.filter(record)
        if rv:
            self.acquire()
            try:
                self.emit(record)
            finally:
                self.release()
        return rv

其中emit函数就是实际操作打印日志的函数，默认为空，必须对其重写！！！

  1. OK,现在已经有一个Logger结束了，后面还会对该 Logger 对象进行判断，是否还有父 Logger 对象，如果没有（代表当前 Logger 对象是最顶层的 Logger 对象 root Logger），流程结束。否则将 Logger 对象设置为它的父 Logger 对象，重复上面的操作，输出父类 Logger 对象中的日志输出，直到是 root Logger 为止。其源码在callHanlder中。
    def callHandlers(self, record):
        c = self
        found = 0
        while c:
            for hdlr in c.handlers:
                found = found + 1
                if record.levelno >= hdlr.level:
                    hdlr.handle(record)
            if not c.propagate:
                c = None    #break out
            else:
                c = c.parent
        # 省略部分无关代码

多加了两个判断，非常通俗易懂。

Share