[TOC]
背景
https://murphypei.github.io/blog/2019/09/python-logging
Python版本为Python 3.8.8
第一部分 内置Logging
包
1.1 日志级别
等级 | 数值 | |
---|---|---|
CRITICAL |
严重;导致应用无法运行的重大错误; | 50 |
ERROR |
错误 | 40 |
WARNING |
警告 | 30 |
INFO |
信息 | 20 |
DEBUG |
调试 | 10 |
NOTSET |
通知 | 0 |
当然logging
包也提供用户自定义日志级别。日志级别通过数值量化比较。例如:
1 | # 新增格式: |
代码中定义了新的日志级别:POINT
,级别值25,在DEBUG
和INFO
之间。
1.2 日志流
参考官网文档:https://docs.python.org/3/howto/logging.html#logging-basic-tutorial
详细流程如下图,其中涉及角色有:
Logger
:日志对象。定义后供业务程序调用。判断可用性开关参数,日志级别。不满足条件结束。LogRecord
:日志记录器。多于满足过滤器条件,流程结束。否则继续给将日志传到相应的处理器(Handler)处理。Handler
:处理器。将日志记录器产生的日志记录发送至合适的目的地。提供各类处理器配置。Filter
:过滤器。提供了更好的粒度控制,可以决定输出哪些日志记录。Formatter
:格式化器。指明了最终输出中日志记录的格式。
官网中将日志Flow
分为Logger Flow
和Handler Flow
,具体处理如下:
- 判断
Logger
对象对于设置的级别是否可用,如果可用,则往下执行,否则,流程结束。 - 创建
LogRecord
对象,如果注册到Logger
对象中的Filter
对象过滤后返回False
,则不记录日志,流程结束,否则,则向下执行。 LogRecord
对象将Handler
对象传入当前的Logger
对象,(图中的子流程)如果Handler
对象的日志级别大于设置的日志级别,再判断注册到 Handler 对象中的 Filter 对象过滤后是否返回True
而放行输出日志信息,否则不放行,流程结束。- 如果传入的
Handler
大于Logger
中设置的级别,也即Handler
有效,则往下执行,否则,流程结束。 - 判断这个
Logger
对象是否还有父Logger
对象,如果没有(代表当前Logger
对象是最顶层的Logger
对象root Logger
),流程结束。否则将Logger
对象设置为它的父Logger
对象,重复上面的 3、4 两步,输出父类Logger
对象中的日志输出,直到是root Logger
为止。
上述流程我们后面会结合具体配置文件详细说明。
1.3 基本使用
1.3.1 例子
1 | import logging |
basicConfig
定义了日志的各类配置参数,具体如下:
参数名 | 参数说明 |
---|---|
filename |
日志输出到文件的文件名 |
filemode |
文件模式,r[+]、w[+]、a[+] |
format |
日志输出的格式 |
datefmt |
日志附带日期时间的格式 |
style |
格式占位符,默认为 “%” 和 “{}” |
level |
设置日志输出级别 |
stream |
定义输出流,用来初始化 StreamHandler 对象,不能 filename 参数一起使用,否则会ValueError 异常 |
handles |
定义处理器,用来创建 Handler 对象,不能和 filename 、stream 参数一起使用,否则也会抛出 ValueError 异常 |
1.3.2 日志记录
每条日志都是一个LogRecord
对象,record
对象对象的全部属性如下表。例子中,通过format
参数定义日志输出格式,例如:format="%(asctime)s %(name)s:%(levelname)s:%(message)s"
。其中message
参数是用户提供,其他参数有用户自定义选取和组织。
参数名 | 格式 | 描述 |
---|---|---|
args | You shouldn’t need to format this yourself. | The tuple of arguments merged into msg to produce message , or a dict whose values are used for the merge (when there is only one argument, and it is a dictionary). |
asctime | %(asctime)s |
将日志的时间构造成可读的形式,默认情况下是精确到毫秒,如 2018-10-13 23:24:57,832 ,可以额外指定 datefmt 参数来指定该变量的格式 |
created | %(created)f |
Time when the LogRecord was created (as returned by time.time() ). |
exc_info | You shouldn’t need to format this yourself. | Exception tuple (à la sys.exc_info ) or, if no exception has occurred, None. |
filename | %(filename)s |
不包含路径的文件名 |
funcName | %(funcName)s |
日志记录所在的函数名 |
levelname | %(levelname)s |
日志的级别名称 ('DEBUG' , 'INFO' , 'WARNING' , 'ERROR' ,'CRITICAL' ). |
levelno | %(levelno)s |
Numeric logging level for the message (DEBUG , INFO , WARNING , ERROR ,CRITICAL ). |
lineno | %(lineno)d |
日志记录所在的行号 |
module | %(module)s |
Module (name portion of filename ). |
msecs | %(msecs)d |
Millisecond portion of the time when the LogRecord was created. |
message | %(message)s |
具体的日志信息, computed as msg % args . This is set whenFormatter.format() is invoked. |
msg | You shouldn’t need to format this yourself. | The format string passed in the original logging call. Merged with args to produce message , or an arbitrary object (see Using arbitrary objects as messages). |
name | %(name)s |
日志对象的名称 |
pathname | %(pathname)s |
进行日志调用的源文件的完整路径名 |
process | %(process)d |
当前进程ID |
processName | %(processName)s |
当前进程名称 |
relativeCreated | %(relativeCreated)d |
Time in milliseconds when the LogRecord was created, relative to the time the logging module was loaded. |
stack_info | You shouldn’t need to format this yourself. | Stack frame information (where available) from the bottom of the stack in the current thread, up to and including the stack frame of the logging call which resulted in the creation of this record. |
thread | %(thread)d |
当前线程ID |
threadName | %(threadName)s |
当前线程名称 |
如果对于系统自带的参数集合不满足需求。logging
包从Python 3.2
起提供了Factory
函数getLogRecordFactory()
和setLogRecordFactory()
支持用户自定义record属性。例如对于分布式部署的环境,日志需要有程序部署节点和主机名和ip
信息,需要用户自己新增定义。例如下面的案例:
1 | import logging |
这样就可以配置format
的时候就可以引用已经定义的参数hostname
和hostip
。上面的函数相当于在record
中新增两个参数的定义。
1 | format: "%(asctime)s - %(hostname)s - %(hostip)s - %(levelname)s - %(name)s(%(lineno)d) - %(message)s" |
另外还可以继承logging.Formatter
,例如(代码片段放在__ini__.py
中,Python
的模块名为:logTest
):
1 | import socket |
使用yaml
配置文件时,配置如下:
1 | formatters: |
另外也可以通过自定义日志过滤器 filter
方法来实现。filter
实际上既可以过滤日志,也可以添加字段参数和改写record
,具有灵活的表达能力。我们在后文介绍。
1.3.3 日志切割
生产环境程序常驻运行,为了避免日志文件过大,需要有生命周期管理。通常采用日志切割配置,将日志按照规则进行切割,并按照生命周期策略清理历史文件。
logging
包中提供两种方式切割:按照时间和按照大小。
按大小:
logging.handlers.RotatingFileHandler
类;1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18import logging
from logging.handlers import RotatingFileHandler
# logging.basicConfig()
logger = logging.getLogger('test')
logger.setLevel(logging.INFO)
formatter = logging.Formatter('"%(asctime)s - %(filename)s[line:%(lineno)d] - %(levelname)s: %(message)s"')
# 定义一个RotatingFileHandler,最多备份5个日志文件,每个日志文件最大0.01M
rotatingHandler = RotatingFileHandler('test.log', maxBytes=0.01*1024*1024, backupCount=5)
rotatingHandler.setFormatter(formatter)
logger.addHandler(rotatingHandler)
# 下面是测试案例
if "__name__" == "__main__":
while(True):
logger.info("info")
# 会有5个日志文件:test.log test.log.1 test.log.2 test.log.3 test.log.4 test.log.5按时间:
logging.handlers.TimedRotatingFileHandler
类;其中参数:
TimedRotatingFileHandler(filename [,when [,interval [,backupCount]]])
filename
输出文件名前缀;when
时间单位,字典如下:1
2
3
4
5
6“S”: Seconds
“M”: Minutes
“H”: Hours
“D”: Days
“W”: Week day (0=Monday)
“midnight”: Roll over at midnight(半夜)interval
等待多少个单位when
的时间后,Logger
会自动重建文件。backupCount
是保留日志个数,默认的0是不会自动删除掉日志。
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18import logging
from logging.handlers import TimedRotatingFileHandler
logger = logging.getLogger('test')
logger.setLevel(logging.INFO)
formatter = logging.Formatter('"%(asctime)s - %(filename)s[line:%(lineno)d] - %(levelname)s: %(message)s"')
# 定义一个TimedRotatingFileHandler,最多备份5个日志文件,1分钟切割一次
timedRotatingFileHandler = TimedRotatingFileHandler('Test.log', "M", 1, 5)
timedRotatingFileHandler.suffix = "%Y%m%d-%H%M.log"
timedRotatingFileHandler.setFormatter(formatter)
logger.addHandler(timedRotatingFileHandler)
# 下面是测试案例
if __name__ == "__main__":
while(True):
logger.info("info")
# 输出日志:Test.log.20220505-2309.log,文件名为:filename+suffix
1.3.4 handler
类
logging
包提供大量的handler
方法类,其中StreamHandler
、FileHandler
、NullHandler
源码在__init__.py
文件中。其他handler
在handlers.py
中。全部说明如下:
StreamHandler
实例发送消息到流(类似文件对象)。可以是sys.stderr、sys.stdout或者文件。FileHandler
实例将消息发送到硬盘文件。BaseRotatingHandler
是轮换日志文件的处理程序的基类。它并不应该直接实例化。而应该使用RotatingFileHandler
或TimedRotatingFileHandler
代替它。RotatingFileHandler
实例将消息发送到硬盘文件,支持最大日志文件大小和日志文件轮换。TimedRotatingFileHandler
实例将消息发送到硬盘文件,以特定的时间间隔轮换日志文件。SocketHandler
实例将消息发送到TCP/IP
套接字。从 3.4 开始,也支持 Unix 域套接字。DatagramHandler
实例将消息发送到UDP
套接字。从 3.4 开始,也支持 Unix 域套接字。SMTPHandler
实例将消息发送到指定的电子邮件地址。SysLogHandler
实例将消息发送到Unix syslog
守护程序,可能在远程计算机上。NTEventLogHandler
实例将消息发送到Windows NT/2000/XP
事件日志。MemoryHandler
实例将消息发送到内存中的缓冲区,只要满足特定条件,缓冲区就会刷新。HTTPHandler
实例使用GET
或POST
方法将消息发送到HTTP
服务器。WatchedFileHandler
实例会监视他们要写入日志的文件。如果文件发生更改,则会关闭该文件并使用文件名重新打开。此处理程序仅在类Unix
系统上有用;Windows
不支持依赖的基础机制。QueueHandler
实例将消息发送到队列,例如在queue
或multiprocessing
模块中实现的队列。NullHandler
实例对错误消息不执行任何操作。它们由想要使用日志记录的库开发人员使用,但是想要避免如果库用户没有配置日志记录,则显示 “无法找到记录器XXX
的消息处理器” 消息的情况。有关更多信息,请参阅 配置库的日志记录 。
另外用户也可以自己实现logging.Handler
方法,定义自己的Handler
方法。然后在配置中引用使用即可。
1.3.5 日志开关
在特殊场景下,如果不需要输出日志。logging也提供响应的参数开关。例如对于定义的logger可以进行关闭,如下:
1 | logger = logging.getLogger("FileLogger") |
这样就关闭了。如果是配置文件中,可以将handlers
的list
置为空,即可。
1 | FileLogger: |
如果需要禁用某个级别以下所有日志输出,可以使用下面的参数:
1 | logging.disable(logging.INFO) |
注:这个参数会限制所有的logger
的日志输出级别。
1.3.5 日志过滤器
业务代码产生的日志通常并不是都要作为日志输出的。所以在打印日志的时候我们对每条日志紧要程度进行了量化划分等级,即INFO
、DEBUG
等。但是一些特殊的需求,这种粗粒度的等级划分并不能满足需求。能否提供可编程自定义的过滤函数filter(record)
?
logging
并没有像Handler
一样,为用户提供丰富的filter
工具类。建议项目组可以像java
中日志框架 logback
一样提供部分常用的filter
工具类。
logging没有现成可用的filter
工具,就需要用户自己继承实现(logging.Filter
)。例如下面的案例:
1 | class NoStringFilter(logging.Filter): |
定义 filter
方法,日志记录 record 作为唯一参数,返回值为 0
或 False
表示日志记录将被抛弃,1
或 True
则表示记录别放过。
上面的案例实现了过滤message
中以user
开头的日志消息。对于yaml
文件配置方式,我们在后文介绍。
另外从Python3.2
起,用户自定义filter
也可以不继承logging.Filter
,只需要定义一个实现函数,logger.addFilter
方法引入即可。例如我们在打印日志的时候,需要对于日志中一些敏感信息进行脱敏处理,例如密码信息。
下面的代码片段放在__ini__.py
中,Python
的模块名为:logTest
。
1 | class CustomFilter(logging.Filter): |
对于msg
中的字符串进行关键字替换脱密,对于含有password
和pwd
的字段。
在yaml
配置文件中配置如下,在handlers
中console
应用该过滤器。
1 | filters: |
这样对于日志中还有相关关键字的日志将被过滤。
1 | logger.error("user:admin and password") |
1.4 最佳实践
1.4.1 yaml
配置文件
对于生产环境Python
项目运行,最佳实践当然是日志相关参数需要配置化,而不是耦合在业务代码中。所以首先是日志配置参数配置文件化。通常有几种方式:ini
格式、yaml
格式、JSON
格式、Python
文件等,建议使用yaml
格式。
例如下面的配置文件(logConfig.yaml
):
1 | version: 1 |
配置文件中参数说明如下:
version
,版本参数,目前限定为1(或者1.0);disable_existing_loggers
,参数值默认为True。关于这个参数需要重点讲解一下,因为网上各类文章解释均有出入,笔者做了实验并查看了代码,解释如下。首先从字面意思来看,是否禁止已经存在的
loggers
。那么怎么理解已经存在的loggers
?有下面的例子,我们有两个配置文件中分别定义了日志配置(Config.yaml
和logConfig.yaml
):1
2
3
4
5
6
7with open('Config.yaml', 'r') as f:
config = yaml.safe_load(f.read())
logging.config.dictConfig(config)
with open('logConfig.yaml', 'r') as f:
config = yaml.safe_load(f.read())
logging.config.dictConfig(config)两个配置文件中均定义了名称为
TestLogger
的loggers
(但是配置定义不同,例如Handler
参数不同)。但是配置文件Config.yaml
和logConfig.yaml
有加载先后顺序,那么哪个loggers
是有效的呢?这时候配置文件
logConfig.yaml
中disable_existing_loggers
参数值为True
,那么旧的配置失效,否则新的配置失效。incremental
,中文是增加的意思。是否将此配置文件解释为现有配置的增量, 默认为False
。该参数True
是有不明错误,暂未研究参数用途。formatters
,日志格式化器。可以定义多个日志格式类型,供handler
配置使用。filters
,日志过滤器。配置handlers
,日志处理器。例如配置文件中我们定义了:console
、file
、TimedRotatingfile
、RotatingFileHandler
。供后续loggers
配置使用。举个例子,其他handler
不在展开讲了。1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20# handler名称标签
TimedRotatingfile:
# handler实现类,也可以配置用户自己实现的Handler方法
class: logging.handlers.TimedRotatingFileHandler
# 日志过滤级别
level: DEBUG
# 日志格式化方式而error,配置文件中配置使用
formatter: error
# 过滤器选择,配置文件中需要已配置
filters: [require_debug_false]
# 日志切割时间,M为分钟切割
when: M
# 日志切割保存的文件数量
backupCount: 5
# 日志文件名称,注意这里的绝对路径
filename: ./logs/timedRotating.log
# 日志输出编码,utf8支持中文
encoding: utf8
# 注意配置文件方式不支持自定义suffix值,目前只支持在代码中basicConfig配置
# suffix: "%Y-%m-%d_%H-%M"loggers
,日志对象。配置文件中可以定义多个loggers
。程序中使用下面方式调用:1
logger = logging.getLogger("FileLogger")
另外
logger
有一个重要的概念:父子logger
。每个用户自定义的logger
默认都是root
的子logger
,这时候,子logger
的日志会发送给父级的Logger
。当其中的参数propagate
为no
时候,则不再发送给父。例如下面的配置。1
2
3
4FileLogger:
handlers: [TimedRotatingfile]
level: DEBUG
propagate: no另外除了默认的
root
作为父logger
,用户也可以自己定义,例如:1
logger = logging.getLogger("FileLogger.SampleLogger")
这时候
FileLogger.SampleLogger
的父logger
为FileLogger
,并且默认FileLogger
的父logger
是root
(如果有配置和定义)。即关系为:FileLogger.SampleLogger---->FileLogger--->root
。那么对于
FileLogger.SampleLogger.TestLogger
,是否有多重父子传递呢?经过测试验证是不支持的,也就是说最多就2层。root
,终极父logger
,接受所有子logger
的日志发送,属于兜底处理。例如下面的配置:1
2
3
4root:
level: DEBUG
handlers: []
# handlers: [console]root
属于可选配置项。另外handlers
配置为空,并且所有的子logger
的handlers
配置也为空,这时候会有默认输出,输出格式较为简单只有%(message)s
信息。如果一个日志对象没有指定具体的
logger
,那么就是root
,例如:1
2print(logging.getLogger() == logging.root)
# True查看一下
root
的配置:1
2
3
4
5
6print(logging.root.handlers)
print(logging.lastResort)
print(logging.root.filters)
# []
# <_StderrHandler <stderr> (WARNING)>
# []所以root默认的Handler是StderrHandler,并且日志级别是warning,输出到stderr(默认显示的字体是红色)。如果是shell脚本运行可以配置日志重定向:
1
python log.py 2> /dev/null
业务代码中如下加载配置:
1
2
3
4
5
6
7
8
9
10
11
12import logging.config
import yaml
with open('logConfig.yaml', 'rb') as f:
config = yaml.safe_load(f.read())
logging.config.dictConfig(config)
logger = logging.getLogger("FileLogger")
logger1 = logging.getLogger("SampleLogger")
logger.debug("debug")
logger1.debug("debug")
1.4.2 其他配置文件
对于yaml
文件读取,使用了yaml
包方式先将配置文件解释成字典对象,然后再通过下面的方法解析配置信息。
1 | logging.config.dictConfig() |
其实logging
提供原生接口直接读取配置文件的解析方法(如下)。
1 | logging.config.fileConfig() |
方式该方法目前只支持configparser
类型的文件,即下面的ini
格式的配置文件(截取片段):
1 | [loggers] |
fileConfig()
是一个较老的接口,不支持配置Filter。官方建议后续尽量使用dictConfig()
接口,后续新功能都将增加到dictConfig()
接口。
对于json
文件,logConfig.json
。
1 | { |
文件解析代码案例:
1 | import logging.config |
1.5 线程安全和进程不安全
1.5.1 线程安全
logging
库是线程安全的。
1 | class Handler(Filterer): |
1.5.2 进程安全
1.6 总结
参考文献及资料
1、Logging
包,链接:https://docs.python.org/3.9/library/logging.html
2、日志介绍,链接:https://rmcomplexity.com/article/2020/12/01/introduction-to-python-logging.html
3、日志介绍,链接:https://coralogix.com/blog/python-logging-best-practices-tips/