前言

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
        # 省略部分无关代码

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