【Python】基础学习&技能提升&代码样例6：日志logging

logging 模块实现了python的日志能力。本文通过几个示例展示一些重点概念与用法。

一、线程安全介绍

logging 模块的目标是使客户端不必执行任何特殊操作即可确保线程安全。它通过使用线程锁来达成这个目标；用一个锁来序列化对模块共享数据的访问，并且每个处理程序也会创建一个锁来序列化对其下层 I/O 的访问。

如果你要使用 signal 模块来实现异步信号处理程序，则可能无法在这些处理程序中使用 logging。这是因为 threading 模块中的锁实现并非总是可重入的，所以无法从此类信号处理程序发起调用。

二、快速使用

2.1 基本流程

python的日志功能由以下三个模块（module）构成（在import的时候，会碰到导入这三个模块）:

logging：模块提供主要的面向客户端的API。
logging.config：模块提供API来配置客户端中的日志记录。
logging.handlers：模块提供不同的处理程序，涵盖常见的处理方式并分发日志记录。

具体的，主要由下面5个类构成：
Logger：日志器，暴露函数给应用程序，基于日志记录器和过滤器级别决定哪些日志有效。
LogRecord：日志记录器，将日志传到相应的处理器处理。
Handler：处理器，将（日志记录器产生的）日志记录发送至合适的目的地。
Filter：过滤器，提供了更好的粒度控制，它可以决定输出哪些日志记录。
Formatter：格式化器，指明了最终输出中日志记录的布局。

其中Logger日志器是分层级的，根部的为根日志器，子日志器会向上调用父日志器的handle（参数propagate确定，该参数默认为True）：
在这里插入图片描述
注意： 博主根据经验推测：A、B和root之间仅是拷贝了root的handler配置，不存在propagate为True时的调用关系，所以用虚线表示（见示例2）

具体流程图如下：
logger为上图中的某一级创建的一个实例，可以是logger、logger1、logger2，为了方便，都写成了logger
在这里插入图片描述
看图即可理解流程，这里不赘述。
注意：

logger.propagate=true时不是调用父记录器Logger，只调用其处理程序(handlers)。这意味着记录器类中的过滤器和其他代码不会在父级上执行。这是向记录器添加过滤器时的常见陷阱。
可以看到，过滤器有两个，一个值在Logger中，一个是在Handler中，在设置时一定要注意。
参数propagate确默认为True，所以父日志器的handler默认全部调用，这也就是为什么通常子日志器能调用根日志器handler输出的愿意。（注意，验证中发现一个例外的点：如果子日志器配置了hanlder，而根日志器的默认handler不做处理，则根日志器的默认handler不再调用，见示例2）
一个日志器可配置多个handler，不同的handler可以配置不同的输出源，比如h1输出到文件，h2通过http输出到某个发送短信的服务提醒运维。

日志级别：

级别	数值	何种含义 / 何时使用
logging.NOTSET	0	当在日志记录器上设置时，表示将查询上级日志记录器以确定生效的级别。如果仍被解析为 NOTSET，则会记录所有事件。在处理器上设置时，所有事件都将被处理。
logging.DEBUG	10	详细的信息，通常只有试图诊断问题的开发人员才会感兴趣。
logging.INFO	20	确认程序按预期运行。
logging.WARNING	30	表明发生了意外情况，或近期有可能发生问题（例如‘磁盘空间不足’）。软件仍会按预期工作。
logging.ERROR	40	由于严重的问题，程序的某些功能已经不能正常执行
logging.CRITICAL	50	严重的错误，表明程序已不能继续执行

若设置了一个level，则只有高于或等于这个level的日志才能展示。比如，logger.setLevel(logging.ERROR)，则只有logging.error('日志信息')和logging.critical('日志信息')才能输出。

默认值是WARNING，即当等级大于等于WARNING才输出。

2.2 使用示例

示例1: 一步配置根日志器

一步配置，在根日志器上配置，默认输出到控制台, 本示例输出到指定生成的filename文件中。
根日志器初始化：logging.basicConfig(**kwargs)

# myapp.py
import logging
import time
logger = logging.getLogger(__name__)

def main():
    logging.basicConfig(filename = time.strftime('my-%Y-%m-%d.log'), level=logging.INFO,format = '%(asctime)s  %(levelname)-10s %(processName)s  %(name)s %(message)s', datefmt =  '%Y-%m-%d-%H-%M-%S')
    logger.info('Started') # 本陈旭创建的__name__ 日志器
    logging.debug('debug')  # 根日志器
    logging.info('info') 
    logging.warning('warning') 
    logging.error('error')
    logging.critical('critical')
    logging.log(logging.WARNING, 'another warning')
    logging.log(40, 'another error')

if __name__ == '__main__':
    main()

输出到my-2024-07-27.log文件

2024-07-27-14-55-05  INFO       MainProcess  __main__ Started
2024-07-27-14-55-05  INFO       MainProcess  root info
2024-07-27-14-55-05  WARNING    MainProcess  root warning
2024-07-27-14-55-05  WARNING    MainProcess  __main__ warning
2024-07-27-14-55-05  ERROR      MainProcess  root error
2024-07-27-14-55-05  CRITICAL   MainProcess  root critical
2024-07-27-14-55-05  WARNING    MainProcess  root another warning
2024-07-27-14-55-05  ERROR      MainProcess  root another error

更多格式输出可参考：format格式说明
注意：

对basicConfig() 设置的是根日志器的属性，调用应该在debug()， info() 等的前面。因为它被设计为一次性的配置，只有第一次调用会进行操作，随后的调用不会产生有效操作。

示例2：多步配置子日志器

在子日志器上配置，常用配置如下：

# 日志文件固定大小
import logging
from logging.handlers import RotatingFileHandler # logging.handlers 和 logging是两个包

log_file = 'my.log'

logger = logging.getLogger(__name__) # 子日志器，这种写法，方面在日志中展示是哪个脚本调用的
logger.setLevel(logging.DEBUG) # 子日志器的level check
logger.propagate = True # 默认也是True，一般不用写
# logger.addFilter(f) # 添加过滤器f，使用方法，见下面的filter说明

ch = logging.handlers.RotatingFileHandler(log_file, maxBytes=1000, backupCount=1) # 创建handler实例，常用handler见下
ch.setLevel(logging.INFO) # handler的level check
ch.setFormatter(logging.Formatter('%(asctime)s - %(name)s - %(levelname)-10s - %(message)s'))
# ch.addFilter(f) # 添加过滤器f，使用方法同logger
logger.addHandler(ch)

log = logging.getLogger(__name__)
log.debug('debug')
log.info('info')
log.warning('warning')
log.error('error')
log.critical('critical')
logging.critical('xxxxx') # 测试根日志器的handler

my.log文件

2024-07-29 16:28:59,361 - __main__ - INFO       - info
2024-07-29 16:28:59,361 - __main__ - WARNING    - warning
2024-07-29 16:28:59,362 - __main__ - ERROR      - error
2024-07-29 16:28:59,362 - __main__ - CRITICAL   - critical

控制台：

CRITICAL:root:xxxxx

如果子日志器调用时，root的handler也被调用，控制台输出会包含my.log的内容。

Handler

常用的logging.handlers：

Handler	描述
logging.StreamHandler	将日志消息发送到输出到Stream，如std.out, std.err或任何file-like对象。
logging.FileHandler	将日志消息发送到磁盘文件，默认情况下文件大小会无限增长
logging.handlers.RotatingFileHandler	将日志消息发送到磁盘文件，并支持日志文件按大小切割
logging.hanlders.TimedRotatingFileHandler	将日志消息发送到磁盘文件，并支持日志文件按时间切割
logging.handlers.HTTPHandler	将日志消息以GET或POST的方式发送给一个HTTP服务器
logging.handlers.SMTPHandler	将日志消息发送给一个指定的email地址
logging.NullHandler	该Handler实例会忽略error messages，通常被想使用logging的library开发者使用来避免’No handlers could be found for logger XXX’信息的出现。

类之间的继承关系如下：
在这里插入图片描述

Filter

logger.filter(record)
将此记录器的过滤器应用于记录，如果记录能被处理则返回 True。
过滤器会被依次使用，直到其中一个返回假值为止。
如果它们都不返回假值，则记录将被处理（传递给处理器）。

logging标准库只提供了一个base filter，默认的行为是名为name的logger及其子logger（即名为name.xxxd的logger的消息能通过过滤器，其余的被过滤掉。源码如下

class Filter(object):
    """
    Filter instances are used to perform arbitrary filtering of LogRecords.
    """
    def __init__(self, name=''):
        """
        Initialize a filter.

        Initialize with the name of the logger which, together with its
        children, will have its events allowed through the filter. If no
        name is specified, allow every event.
        """
        self.name = name
        self.nlen = len(name) 

    def filter(self, record):
        """
        Determine if the specified record is to be logged.

        Returns True if the record should be logged, or False otherwise.
        If deemed appropriate, the record may be modified in-place.
        """
        if self.nlen == 0: # name为空时，都可以通过
            return True
        elif self.name == record.name:
            return True
        elif record.name.find(self.name, 0, self.nlen) != 0:
            return False
        return (record.name[self.nlen] == ".") # 子logger可通过

filter可以是一个返回bool值得函数，也可以是logging.Filter的子类并实现了filter方法

class NoParsingFilter(logging.Filter):
    def filter(self, record):
        return record.getMessage().startswith('inf') # 指允许inf开头的日志被记录

def filter_func(record: logging.LogRecord):
    return record.getMessage().startswith('inf')  # 指允许inf开头的日志被记录 

logger.addFilter(filter_func) 
logger.addFilter(NoParsingFilter()) # 等价

filter还有一种常用用法是传递上下文，参考：cookbook-在处理器中传递上下文信息

record的属性可直接获取，如record.msg(等价于 record.getMessage())、record.name，属性列表可查看：LogRecord 属性

实例3：子、父日志器输出

import logging

handler = logging.StreamHandler()

parent = logging.getLogger("parent")
parent.addHandler(handler)
child = logging.getLogger("parent.child")
child.propagate = True # 改为False再运行一遍

child.setLevel(logging.DEBUG)
child.addHandler(handler)

child.info("HELLO")

child.propagate = True时控制台输出：

HELLO
HELLO

child.propagate = False时控制台输出：

HELLO

实例4：多模块记录日志到同一个文件

依赖根日志器

# myapp.py
import logging
import mylib

def main():
    logging.basicConfig(filename='myapp.log', level=logging.INFO)
    logging.info('Started')
    mylib.do_something()
    logging.info('Finished')

if __name__ == '__main__':
    main()

# mylib.py
import logging

def do_something():
    logging.info('Doing something')

运行 myapp.py ，在 myapp.log 中：

INFO:root:Started
INFO:root:Doing something
INFO:root:Finished

注意，这里用的是根日志器来实现的多模块同时记录，在Filter的介绍中你可以发现能够实现的原因是因为logger.name长度为0。

在生产环境中，我们通常会为每个模块设置单独的logger（即类似logger = logging.getLogger(__name__)）。这样，如果主程序中，logger_main.name为A，辅助程序中logger_fu.name为B，则运行主程序的时候，辅助程序中的logger不会被打印。

解决方案1：将辅助程序中logger_fu.name设置为A.xx

# myapp.py
import logging
import mylib

def main():
    logging.basicConfig(filename='myapp.log', level=logging.INFO)
    logger=logging.info('main')
    logger.info('Started')
    mylib.do_something()
    logger.info('Finished')

if __name__ == '__main__':
    main()

# mylib.py
import logging
logger=logging.info('main.mylib')

def do_something():
	logger.info('Doing something')

运行 myapp.py ，在 myapp.log 中：

INFO:root:Started
INFO:root:Doing something
INFO:root:Finished

解决方案2：将辅助程序中就用根日志器输出。公共模块可考虑这种方案。

疑问：logging是线程级别的还是程序级别的？即：如果启动两个程序，用不同的basicConfig，会不会生效两份basicConfig？
答案：程序级别。

示例5：通过文件配置日志参数

以上都是在代码里直接配置日志的参数，但通常生产实践中，是需要通过配置文件配置的。

推荐：使用logging本身提供的fileConfig能力会比较便捷。（dictConfig配合yaml文件，也可以实现相似效果，但不如fileConfig好用）
不推荐：当然也可以稍微复杂点，自己读取配置文件后，按示例1-2中那样写进去（参考Python logging日志模块+读取配置文件）‘’

fileConfig

文件参数具体含义查看：配置文件格式要求
假设logging_config.ini文件

[loggers]
keys=root

[handlers]
keys=stream_handler

[formatters]
keys=formatter

[logger_root]
level=DEBUG
handlers=stream_handler

[handler_stream_handler]
class=StreamHandler
level=DEBUG
formatter=formatter
args=(sys.stderr,)

[formatter_formatter]
format=%(asctime)s %(name)-12s %(levelname)-8s %(message)s

import logging
import logging.config

logging.config.fileConfig('logging_config.ini')
logger = logging.getLogger()
logger.debug('often makes a very good meal of %s', 'visiting tourists')

dictConfig

dictConfig配合yaml文件，也可以实现fileConfig相似效果，但某些场景可能不如fileConfig方便。
fileConfigAPI 比 dictConfigAPI 更旧，如果你想要在你的日志记录配置中包含 Filter 的实例，你将必须使用 dictConfig()
文件参数具体含义查看：dictConfig配置格式要求

# 一个使用dictConfig的示例
# config也可以自己写dict
with open('logging.yml', 'r') as f_config:
	config= yaml.load(f_config)

import logging.config
logging.config.dictConfig(config)

注意，使用dictConfig的话，会disable所有存在的loggers，除非把参数disable_existing_loggers设置为False。
一个yaml文件样例：

version:1
root:
	level:DEBUG
	handlers:[filehandler, ]
loggers:
	console:
		level:WARNING
		handlers:[consolehandler,]
		propagate:1
handlers:
	filehandler:
		class:logging.FileHandler
		filename:logs/sys.log
		level:WARNING
		formatter:fileformatter
	consolehandler:
		class:logging.StreamHandler
		stream:ext://sys.stdout
		level:DEBUG
		formatter:consoleformatter
formatters:
	fileformatter:
		format:'%(asctime)s [%(name)s][%(levelname)s]：%(message)s'
	consoleformatter:
		format:'%(asctime)s[%(levelname)s]:%(message)s'

一个自行编写的dict样例：

config = {
    'disable_existing_loggers': False,
    'version': 1,
    'formatters': {
        'short': {
            'format': '%(asctime)s %(levelname)s %(name)s: %(message)s'
        },
    },
    'handlers': {
        'console': {
            'level': 'INFO',
            'formatter': 'short',
            'class': 'logging.StreamHandler',
        },
    },
    'loggers': {
        '': {
            'handlers': ['console'],
            'level': 'ERROR',
        },
        'plugins': {
            'handlers': ['console'],
            'level': 'INFO',
            'propagate': False
        }
    },
}

参数简介：

key名称	描述
version	必选项，整数值，表示配置格式版本，当前唯一可用值是1
formatters	可选项，其值是字典对象，该字典对象每个元素的key为要定义的格式器名称，value为格式器的配置信息组成的dict。一般会配置format，用于指定输出字符串的格式，datefmt用于指定输出的时间字符串格式，默认为%Y-%m-%d %H:%M:%S。
filters	可选项，其值是字典对象，该字典对象每个元素的key为要定义的过滤器名称，value为过滤器的配置信息组成的dict。
handlers	可选项，其值是字典对象，该字典对象每个元素的key为要定义的处理器名称，value为处理器的配置信息组成的dict。如class（必选项）, formatter, filters。其他配置信息将会传递给class所指定的处理器类的构造函数。如使用logging.handlers.RotatingFileHandler，使用maxBytes, backupCount等参数。
loggers	可选项，其值是字典对象，该字典对象每个元素的key为要定义的日志器名称，value为日志器的配置信息组成的dict。如level, handler, filter等
root	可选项，这是root logger的配置项，其值是字典对象。除非在定义其它logger时明确指定propagate值为no，否则root logger定义的handlers都会被作用到其它logger上。
incremental	可选项，默认值为False。该选项的意义在于，如果这里定义的对象已经存在，那么这里对这些对象的定义是否应用到已存在的对象上。值为False表示，已存在的对象将会被重新定义。
disable_existing_loggers	可选项，默认值为True。是否要禁用任何现有的非根日志记录器。该设置对应于 fileConfig() 中的同名形参。如果 incremental 为 True 则该值会被忽略。

实例6: 通过命令行控制日志级别

if __name__ == '__main__':
    scriptname = os.path.basename(__file__)
    parser = argparse.ArgumentParser(scriptname)
    levels = ('DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL')
    parser.add_argument('--log-level', default='INFO', type=str.upper, choices=levels) # str.upper可让输入转换成大写
    options = parser.parse_args()
    logging.basicConfig(level=options.log_level, format='%(levelname)s %(name)s %(message)s')

使用

 python testhao hao .py --log-level debug

参考

官方-logging
官方-基础教程
 官方-进阶教程
 官方-cookbook
中文logging使用详解
 官方-dictConfig
Python Logging: An In-Depth Tutorial
Python Logging: A Stroll Through the Source Code
Logging
Logging in Python like a PRO
不错 A guide to logging in Python
Python logging: do’s and don’ts
Python logging: propagate messages of level below current logger level