前言

对于python脚本来说,运行过程中难免会出现权限、编码、逻辑等各种各样的bug,特别是打包好的python程序,出现报错或者闪退时往往难以排查错误原因,因此有必要在运行python程序时保存一些运行信息到日志文件中,从而记录使用者的操作和出现的错误以及警告信息等。

因此,今天就介绍一下python中最常用的日志处理模块——logging

 

logging模块介绍

logging模块是Python的内置模块,专门用于记录日志,其中最重要的概念是严重级别(level),共有以下5个等级。

日志严重级别 描述
DEBUG 调试信息,通常在排查问题时开启
INFO 普通信息,程序按照预期运行
WARNING 警告信息,表示发生了意想不到的事情或者接下来可能会出现一些问题,但程序仍可以继续运行。
ERROR 错误信息,表示程序运行中出现了一些问题,程序的部分功能不能正常执行。
CRITICAL 危险信息,表示出现了严重的错误,导致程序不能继续运行。

其中由上到下,级别越来越高,打印的日志数量越来越少,最常用的是INFO、WARNING和ERROR三个等级,而DEBUG级别往往会打印大量日志,因此往往在排查问题时才会开启。

当指定一个日志级别之后,会记录大于或等于这个日志级别的日志信息,小于的将会被丢弃, 默认情况下日志会打印大于等于 WARNING 级别的日志。

 

logging模块的使用

最简单的使用方式就是直接调用打印日志函数。

import logging

# 打印日志
logging.debug('Python debug')
logging.info('Python info')
logging.warning('Python warning')
logging.error('%s'%('Python Error'))
logging.critical('Python critical')

类似于print函数,打印日志函数也可以通过%s、%d等占位符将python程序中的变量打印到日志中,运行结果如下:

WARNING:root:Python warning
ERROR:root:Python Error
CRITICAL:root:Python critical

但这样只是将日志打印到控制台,为了方便储存和查看,还是应该输出到日志文件中,使用方式如下。

import logging

logging.basicConfig(filename='yumefx.log',level=logging.INFO)
logging.debug("debug message.")
logging.info("info message.")
logging.warning("warning message.")

其中basicConfig函数中的filename参数用于设置日志文件的保存路径,后面调用的打印日志函数就会自动输出到日志文件中,控制台中则不再输出。

level参数则是设置日志的严重级别,当前日志级别设置为INFO,则大于等于INFO级别的日志会被输出,小于INFO级别的日志会被丢弃,因此生成的日志文件中内容如下:

INFO:root:info message.
WARNING:root:warning message.

basicConfig函数中还有一个filemode参数,默认为a,代表每次输出日志时都追加到日志文件末尾,如果需要改为每次输出日志都覆盖的话,可以改为w。

 

日志格式

可以看到,上面输出的日志很简单,只有root加上日志信息(root的含义后面会介绍),没有日志时间之类的信息,可以在basicConfig函数通过format参数设置输出日志的格式,例如下面的例子。

import logging

logging.basicConfig(filename='yumefx.log', format='%(asctime)s: %(message)s', datefmt='%Y-%m-%d %H:%M:%S')
logging.warning('warning message.')

输出的日志内容如下:

2022-05-04 22:48:07: warning message.

format参数中的asctime字段为日志事件发生时的时间,配合datefmt参数可以设置时间的格式,从而就可以记录每次输出日志的具体时间。

format参数中常用的字段如下:

字段名称 使用格式 描述
asctime %(asctime)s 日志事件发生时的时间
created %(created)f 日志事件发生时的时间戳
relativeCreated %(relativeCreated)d 日志事件发生的时间相对于logging模块加载时间的相对毫秒数(可以用于近似程序运行时间)。
msecs %(msecs)d 日志事件发生时的时间的毫秒
levvelname %(levelname)s 该日志事件所属的严重级别
message %(message)s 日志的文本内容
pathname %(pathname)s 调用日志记录函数的源码文件的路径
filename %(filename)s pathname的文件全名,含文件后缀
module %(module)s filename的文件名部分,不含文件后缀
lineno %(lineno)s 调用日志记录函数的源代码所在的行号
funcName %(funcName)s 调用日志记录函数的函数名
process %(process)d 进程ID
processName %(processName)s 进程名称,Python3.1新增
thread %(thread)d 线程ID
threadName %(threadName)s 线程名称

通过灵活使用这些字段设置format参数,就可以让输出的日志包含所需的运行信息,再出现问题时方便排查。

 

标准使用

大多数情况下像前面那样通过basicConfig函数配置好参数和格式后,就可以直接使用,不过这只是最简易的用法。

标准的用法,可以参考以下代码:

import logging

#创建logger对象
log=logging.getLogger("example")
log.setLevel(logging.DEBUG)

#创建handler,用于定义输出目的地
handler1=logging.StreamHandler()
handler2=logging.FileHandler('yumefx.log',mode='w')
handler1.setLevel(logging.INFO)
handler2.setLevel(logging.DEBUG)

#定义handler的输出格式
formatter1=logging.Formatter("%(asctime)s-%(name)s-%(levelname)s-%(message)s")
formatter2=logging.Formatter("%(levelname)s : %(message)s")
handler1.setFormatter(formatter1)
handler2.setFormatter(formatter2)

#将handler添加到对应的logger对象
log.addHandler(handler1)
log.addHandler(handler2)
log.info("info message.")
log.debug("debug message.")
log.warning("warnning message.")

实现的效果是一次调用输出日志函数,控制台和日志文件里都会输出日志,并且日志的参数和格式各不相同,控制台信息如下:

2022-05-04 23:39:37,421-example-INFO-info message.
2022-05-04 23:39:37,421-example-WARNING-warnning message.

日志文件中输出如下:

INFO : info message.
DEBUG : debug message.
WARNING : warnning message.

示例代码中,logging.getLogger(name=“example”)返回一个logger的对象,name参数如果为空则默认使用的是root logger(这就是最前面的示例中日志信息里面root的由来),否则即为使用自己定义的logger。所有调用日志的接口,如果logger name一样则都是调用同一个logger实例。

StreamHandler函数和FileHandler函数则是定义将logger对象的日志输出到什么样的位置,统称为Handler。一个logger中可以添加多个Handler,将同一条日志记录输出到不同的位置。其他可用的handler还有SocketHandler、SMTPHandler、SysLogHandler、MemoryHandler、HTTPHandler等等,但使用频率并不高。

Formatter函数则与basicConfig函数的format参数类似,都是用于定义日志的输出格式,需要添加到Handler上才能生效。

另外一个可用的函数则是Filter,定义后加到Handler上可以用于实现日志过滤,一个Handler上可以添加多个Filter,一条日志记录必须所有过滤器都通过才能正常输出,否则就会被丢弃,这里就不详细说了。

除了上面这样的显式定义配置参数外,logging还支持通过dictConfig(字典参数)、fileConfig(配置文件)等方式来定义配置参数。

因此,前面的简易用法的实质是logging模块在导入时自动生成一个root logger,这个root logger的实例可以通过logging.getLogger() 得到,之后的basicConfig配置函数和日志打印函数都是在这个root logger的实例上执行的,即logging.debug等价于rootLogger.debug,并且basicConfig配置函数是一个一次性方法,只有第一次设置时会生效,后面就不能修改了,所以应该尽量使用标准用法。

 

logger的树形结构

logger是有树形结构的,默认生成的root logger就是树形结构的根,通过 getLogger(loggername) 方法获得的 logger 对象都是从 root logger 伸展出来的枝叶。

层次结构用.分隔

logger = logging.getLogger('mod1.mod2.mod3')

上面的代码实际上创建了三个 logger,名称分别是 mod1、mod1.mod2 和 mod1.mod2.mod3,mod1 为根,mod1.mod2 为子,mod1.mod2.mod3 为孙。

如果在 mod1 上设置了Handler,那么其他两个的日志对象都会使用这个Handler,这样记录的日志更清晰,并且可以为同一个根的日志对象设置可以共享的日志处理方式。。

 

logging的一些特点

一次定义,随处使用

配置好日志输出的参数和格式后,后面所有调用输出日志的代码,都按照这个参数和格式进行输出,不需要在不同的模块或函数中传输logger对象实例,大大提升了使用的便捷性。

 

线程安全

logging模块不需要用户再做其他的安全操作避免文件读写冲突和提高线程调用安全,它内部已经实现了线程锁,每一个模块调用的时候是锁定了共享数据区域,每一个handler也对IO进行加锁操作。

 


不要只注重形式上的修辞而放弃了实质上的思考。

《沉思录》
——马克·奥勒留