日志记录的重要性
在开发过程中,如果程序运行出现了问题,我们是可以使用我们自己的 Debug 工具来检测到到底是哪一步出现了问题,如果出现了问题的话,是很容易排查的。但程序开发完成之后,我们会将它部署到生产环境中去,这时候代码相当于是在一个黑盒环境下运行的,我们只能看到其运行的效果,是不能直接看到代码运行过程中每一步的状态的。在这个环境下,运行过程中难免会在某个地方出现问题,甚至这个问题可能是我们开发过程中未曾遇到的问题,碰到这种情况应该怎么办? 如果我们现在只能得知当前问题的现象,而没有其他任何信息的话,如果我们想要解决掉这个问题的话,那么只能根据问题的现象来试图复现一下,然后再一步步去调试,这恐怕是很难的,很大的概率上我们是无法精准地复现这个问题的,而且 Debug 的过程也会耗费巨多的时间,这样一旦生产环境上出现了问题,修复就会变得非常棘手。但这如果我们当时有做日志记录的话,不论是正常运行还是出现报错,都有相关的时间记录,状态记录,错误记录等,那么这样我们就可以方便地追踪到在当时的运行过程中出现了怎样的状况,从而可以快速排查问题。 因此,日志记录是非常有必要的,任何一款软件如果没有标准的日志记录,都不能算作一个合格的软件。作为开发者,我们需要重视并做好日志记录过程。
日志记录的流程框架
那么在 Python 中,怎样才能算作一个比较标准的日志记录过程呢?或许很多人会使用 print 语句输出一些运行信息,然后再在控制台观察,运行的时候再将输出重定向到文件输出流保存到文件中,这样其实是非常不规范的,在 Python 中有一个标准的 logging
模块,我们可以使用它来进行标注的日志记录,利用它我们可以更方便地进行日志记录,同时还可以做更方便的级别区分以及一些额外日志信息的记录,如时间、运行模块信息等。 接下来我们先了解一下日志记录流程的整体框架。
整个日志记录的框架可以分为这么几个部分:
-
Logger
:即 Logger Main Class,是我们进行日志记录时创建的对象,我们可以调用它的方法传入日志模板和信息,来生成一条条日志记录,称作 Log Record。'loggers': { 'main.core': { 'level': 'DEBUG', 'handlers': ['console', 'file', 'error'] } },
-
Log Record
:就代指生成的一条条日志记录。 -
Handler
:即用来处理日志记录的类,它可以将 Log Record 输出到我们指定的日志位置和存储形式等,如我们可以指定将日志通过 FTP 协议记录到远程的服务器上,Handler 就会帮我们完成这些事情。'handlers': { 'console': { 'class': 'logging.StreamHandler', 'formatter': 'brief', 'level': 'INFO', 'stream': 'ext://sys.stdout' }, 'file': { 'class': 'logging.FileHandler', 'formatter': 'simple', 'level': 'DEBUG', 'filename': 'debug.log' }, 'error': { 'class': 'logging.handlers.RotatingFileHandler', 'level': 'ERROR', 'formatter': 'simple', 'filename': 'error.log', 'maxBytes': 10485760, 'backupCount': 20, 'encoding': 'utf8' } },
-
Formatter
:实际上生成的 Log Record 也是一个个对象,那么我们想要把它们保存成一条条我们想要的日志文本的话,就需要有一个格式化的过程,那么这个过程就由 Formatter 来完成,返回的就是日志字符串,然后传回给 Handler 来处理。'formatters': { 'brief': { 'format': '%(asctime)s - %(message)s' }, 'simple': { 'format': '%(asctime)s - %(name)s - %(levelname)s - %(message)s' } },
-
Filter
:另外保存日志的时候我们可能不需要全部保存,我们可能只需要保存我们想要的部分就可以了,所以保存前还需要进行一下过滤,留下我们想要的日志,如只保存某个级别的日志,或只保存包含某个关键字的日志等,那么这个过滤过程就交给Filter
来完成。 -
Parent Handler:Handler 之间可以存在分层关系,以使得不同 Handler 之间共享相同功能的代码。
以上就是整个 logging 模块的基本架构和对象功能,了解了之后我们详细来了解一下 logging 模块的用法。
为什么要使用日志
在开发项目时,我们不可能将所有的信息都打印在控制台中。我们可以使用Python标准库提供的logging API来处理。相比print,logging模块提供了许多强大而灵活的功能。比如:可以通过设置不同的日志等级,只输出重要信息,而不必显示大量的调式信息;print将所有信息都输出到标准输出中,严重影响开发者从标准输出中查看其他数据,而logging则可以由开发者决定将信息输出到什么地方,以及怎么输出。
日志记录的基本信息
日志等级
-
logging函数默认定义了5个日志等级,它允许开发人员自定义日志等级,但是并不推荐。
日志等级(level) 描述 DEBUG 最详细的日志信息,典型应用场景是 问题诊断 INFO 信息详细程度仅次于DEBUG,通常只记录关键节点信息,用于确认一切都是按照我们预期的那样进行工作 WARNING 当某些不期望的事情发生时记录的信息(如,磁盘可用空间较低),但是此时应用程序还是正常运行的 ERROR 由于一个更严重的问题导致某些功能不能正常运行时记录的信息 CRITICAL 当发生严重错误,导致应用程序不能继续运行时记录的信息
注:日志等级从上到下依次升高 DEBUG < INFO < WARNING < ERROR < CRITICAL,而日志信息依次减少;当指定一个日志级别之后,会记录大于或等于这个日志级别的日志信息,小于的将会被丢弃;默认打印的日志等级是 WARNING ,当日志等级设置为 WARNING 或之上时才被跟踪。
日志字段信与格式
一条日志信息对应的是一个事件的发生,而一个事件通常需要包括以下几个内容:
- 事件发生时间
- 事件发生位置
- 事件的严重程度
- 日志级别、事件内容等其他内容
注:输出一条日志时,日志内容和日志级别是需要开发人员明确指定的;对于而其它字段信息,只需要是否显示在日志中就可以了。
日志logging和print进行比较
- 可以在 logging 模块中设置日志等级,在不同的版本(如开发环境、生产环境)上通过设置不同的输出等级来记录对应的日志,非常灵活。
- print 的输出信息都会输出到标准输出流中,而 logging 模块就更加灵活,可以设置输出到任意位置,如写入文件、写入远程服务器等。
- logging 模块具有灵活的配置和格式化功能,如配置输出当前模块信息、运行时间等,相比 print 的字符串格式化更加方便易用。
logging模块的使用方式
两种记录日志方式
- 使用logging提供的模块级别函数
- 使用logging日志系统的四大组件
使用logging提供的模块级别函数详细说明
函数 | 描述 |
---|---|
logging.debug(msg, args, *kwargs) | 创建一条严重级别为DEBUG的日志记录 |
logging.info(msg, args, *kwargs) | 创建一条严重级别INFO的日志记录 |
logging.warning(msg, args, *kwargs) | 创建一条严重级别为WARNING的日志记录 |
logging.error(msg, args, *kwargs) | 创建一条严重级别为ERROR的日志记录 |
logging.critical(msg, args, *kwargs) | 创建一条严重级别为CRITICAL的日志记录 |
logging.log(level, args, *kwargs) | 创建一条严重级别为level的日志记录 |
logging.basicConfig(**kwargs) | 对root logger进行一次性配置 |
注:其中logging.basicConfig(**kwargs)函数用于指定“要记录的日志级别”、“日志格式”、 “日志输出位置”、“日志文件的打开模式”等信息,其他几个都是用于记录各个级别日志的函数。
使用logging日志系统的四大组件
组件描述:
组件名称 | 类名 | 描述 |
---|---|---|
日志器 | loggers | 提供应用程序代码直接使用的接口 |
处理器 | handlers | 用于将日志记录发送到指定的目的位置 |
过滤器 | filters | 提供更细粒度的日志过滤功能,用于决定哪些日志记录将会被输出(其他的日志记录将会被忽略) |
格式器 | formatters | 用于控制日志信息的最终输出格式 |
日志器 - Logger
Logger是一个树形层级结构,在使用接口debug、info、warning、error、critical之前必须创建Logger实例;
创建方式
logger = logging.getLogger(logger_name)
创建Logger实例后,可以使用以下方法进行日志级别设置,增加处理器Handler:
logger.setLevel(logging.ERROR) # 设置日志级别为 ERROR,即只有日志级别大于等于 ERROR 的日志才会输出
logger.addHandler(handler_name) # 为Logger实例增加一个处理器
logger.removeHandler(handler_name) # 为 Logger 实例删除一个处理器
处理器 - Handler
Handler 处理器类型有很多种,比较常用的有三个:StreamHandler、FileHandler、NullHandler.
创建方式:
# StreamHandler创建方式
sh = logging.StreamHandler(stream=None)
# FileHandler创建方式
# fh = logging.FileHandler(filename, mode='a', encoding=None, delay=False)
# NullHandler:NullHandler类位于核心logging包,不做任何的格式化或者输出。本质上它是个“什么都不做”的handler,由库开发者使用。
创建 StreamHandler 之后,可以通过使用以下方法设置日志级别,设置格式化器 Formatter,增加或删除过滤器 Filter。
sh.setLevel(logging.WARN) # 指定日志级别,低于WARN级别的日志将被忽略
sh.setFormatter(formatter_name) # 设置一个格式化器formatter
sh.addFilter(filter_name) # 增加一个过滤器,可以增加多个
sh.removeFilter(filter_name) # 删除一个过滤器
过滤器 - filters
Filter过滤器基类,它只允许某个logger层级下的日志事件通过过滤。
一条日志信息被输出要经过以下几次过滤:日志器等级过滤、日志器的过滤器过滤、日志器的处理器等级过滤、日志器的处理器的过滤器过滤。
创建方式:
filter = logging.Filter(name='')
格式化器 - Formatter
使用Formatter对象设置日志信息最后的规则、结构和内容,默认的时间格式为%Y-%m-%d %H:%M:%S。
创建方法:
formatter = logging.Formatter(fmt=None, datefmt=None)
# fmt是消息的格式化字符串,datefmt是日期字符串。如果不指明fmt,将使用'%(message)s'。如果不指明datefmt,将使用ISO8601日期格式。
组件之间的关系
-
日志器(logger)需要通过处理器(handler)将日志信息输出到目标位置,不同的处理器(handler)可以将日志输出到不同的位置。
-
日志器(logger)可以设置多个处理器(handler)将同一条日志记录输出到不同的位置。
-
每个处理器(handler)都可以设置自己的过滤器(filter)实现日志过滤,从而只保留感兴趣的日志。
-
每个处理器(handler)都可以设置自己的格式器(formatter)实现同一条日志以不同的格式输出到不同的地方。
总结以上内容:Logger 可以包含一个或多个 Handler 和 Filter,即:LoggerFilter,即:Logger 与 Handler 或 Fitler 是一对多的关系;一个 Logger 实例可以新增多个 Handler,一个 Handler 可以新增多个格式化器或多个过滤器,而且日志级别将会继承。
代码的实现与具体应用
可以通过以下3种方法来配置logging:使用python代码创建loggers,handlers和formatters并分别调用它们的配置函数,创建一个日志配置文件,然后使用fileConfig()
函数来读取该文件的内容,创建一个包含配置信息的dict,然后把它传递给dictConfig()
函数;
使用python代码实现日志配置
Python代码展示:
import logging
import sys
# 创建日志器logger并将其日志级别设置为DEBUG
logger = logging.getLogger("python_config_logger")
logger.setLevel(logging.DEBUG)
# 创建一个流处理器handler并将其日志级别设置为DEBUG
handler = logging.StreamHandler(sys.stdout)
handler.setLevel(logging.DEBUG)
# 创建一个格式化器formatter并将其添加到处理器handler中
formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")
handler.setFormatter(formatter)
# 为日志器logger添加上面创建好的处理器handler
logger.addHandler(handler)
# 将日志打印在控制台
logger.debug('打印日志级别:debug')
logger.info('打印日志级别:info')
logger.warning('打印日志级别:warning')
logger.error('打印日志级别:error')
logger.critical('打印日志级别:critical')
实际结果:
2021-02-24 17:13:44,644 - python_config_logger - DEBUG - 打印日志级别:debug
2021-02-24 17:13:44,644 - python_config_logger - INFO - 打印日志级别:info
2021-02-24 17:13:44,644 - python_config_logger - WARNING - 打印日志级别:warning
2021-02-24 17:13:44,645 - python_config_logger - ERROR - 打印日志级别:error
2021-02-24 17:13:44,645 - python_config_logger - CRITICAL - 打印日志级别:critical
使用配置文件和fileConfig()函数实现日志配置
Python代码展示:
import logging.config
# 读取日志配置文件内容
logging.config.fileConfig('logging.conf')
# 创建一个日志器logger
logger = logging.getLogger('simpleExample')
# 将日志打印在控制台
logger.debug('打印日志级别:debug')
logger.info('打印日志级别:info')
logger.warning('打印日志级别:warning')
logger.error('打印日志级别:error')
logger.critical('打印日志级别:critical')
logging.conf配置文件内容:
[loggers]
keys=root,simpleExample
# 测试
[handlers]
keys=fileHandler,consoleHandler
[formatters]
keys=simpleFormatter
[logger_root]
level=DEBUG
handlers=fileHandler
[logger_simpleExample]
level=DEBUG
handlers=consoleHandler
qualname=simpleExample
propagate=0
[handler_consoleHandler]
class=StreamHandler
args=(sys.stdout,)
level=DEBUG
formatter=simpleFormatter
[handler_fileHandler]
class=FileHandler
args=('logging.log', 'a')
level=ERROR
formatter=simpleFormatter
[formatter_simpleFormatter]
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s
datefmt=
实际结果:
2021-02-25 15:04:50,644 - simpleExample - DEBUG - 打印日志级别:debug
2021-02-25 15:04:50,646 - simpleExample - INFO - 打印日志级别:info
2021-02-25 15:04:50,646 - simpleExample - WARNING - 打印日志级别:warning
2021-02-25 15:04:50,646 - simpleExample - ERROR - 打印日志级别:error
2021-02-25 15:04:50,646 - simpleExample - CRITICAL - 打印日志级别:critical
使用dict配置信息和dictConfig()函数实现日志配置
Python代码展示:
import logging.config
import logging
import yaml
# 读取日志配置文件内容
with open('logging.yml', 'r') as file_logging:
dict_conf = yaml.load(file_logging, Loader=yaml.FullLoader)
logging.config.dictConfig(dict_conf)
# 创建一个日志器logger
logger = logging.getLogger('simpleExample')
# 将日志打印在控制台
logger.debug('打印日志级别:debug')
logger.info('打印日志级别:info')
logger.warning('打印日志级别:warning')
logger.error('打印日志级别:error')
logger.critical('打印日志级别:critical')
logging.yml配置文件内容:
version: 1
formatters:
simple:
format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
handlers:
console:
class: logging.StreamHandler
level: DEBUG
formatter: simple
loggers:
simpleExample:
level: DEBUG
handlers: [console]
propagate: no
root:
level: DEBUG
handlers: [console]
实际结果:
2021-02-25 15:14:28,822 - simpleExample - DEBUG - 打印日志级别:debug
2021-02-25 15:14:28,822 - simpleExample - INFO - 打印日志级别:info
2021-02-25 15:14:28,822 - simpleExample - WARNING - 打印日志级别:warning
2021-02-25 15:14:28,822 - simpleExample - ERROR - 打印日志级别:error
2021-02-25 15:14:28,823 - simpleExample - CRITICAL - 打印日志级别:critical
上面只是简单的介绍了python中logging模块的基本使用方法,下面是一些比较详细的介绍。
崔庆才相关教程
下面我们初步来了解下 logging 模块的基本用法,先用一个实例来感受一下:
import logging
logging.basicConfig(level=logging.INFO, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
logger = logging.getLogger(__name__)
logger.info('this is a log info')
logger.debug('Debugging')
logger.warning('Warning exists')
logger.info('Finish')
在这里我们首先引入了 logging
模块,然后进行了一下基本的配置,这里通过 basicConfig
配置了 level
信息和 format
信息,这里 level 配置为 INFO
信息,即只输出 INFO
级别的信息,另外这里指定了 format
格式的字符串,包括 asctime、name、levelname、message 四个内容,分别代表运行时间、模块名称、日志级别、日志内容,这样输出内容便是这四者组合而成的内容了,这就是 logging 的全局配置。
接下来声明了一个 Logger
对象,它就是日志输出的主类,调用对象的 info () 方法就可以输出 INFO 级别的日志信息,调用 debug () 方法就可以输出 DEBUG 级别的日志信息,非常方便。
在初始化的时候我们传入了模块的名称,这里直接使用 name 来代替了,就是模块的名称,如果直接运行这个脚本的话就是 main,如果是 import 的模块的话就是被引入模块的名称,这个变量在不同的模块中的名字是不同的,所以一般使用 name 来表示就好了,再接下来输出了四条日志信息,其中有两条 INFO、一条 WARNING、一条 DEBUG 信息,我们看下输出结果:
2022-04-13 21:36:19,857 - __main__ - INFO - this is a log info
2022-04-13 21:36:19,857 - __main__ - WARNING - Warning exists
2022-04-13 21:36:19,857 - __main__ - INFO - Finish
可以看到输出结果一共有三条日志信息,每条日志都是对应了指定的格式化内容,另外我们发现 DEBUG 的信息是没有输出的,这是因为我们在全局配置的时候设置了输出为 INFO 级别,所以 DEBUG 级别的信息就被过滤掉了。 这时如果我们将输出的日志级别设置为 DEBUG,就可以看到 DEBUG 级别的日志输出了:
logging.basicConfig(level=logging.DEBUG, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
2022-04-13 21:37:58,119 - __main__ - INFO - this is a log info
2022-04-13 21:37:58,119 - __main__ - DEBUG - Debugging
2022-04-13 21:37:58,119 - __main__ - WARNING - Warning exists
2022-04-13 21:37:58,119 - __main__ - INFO - Finish
由此可见,相比 print 来说,通过刚才的代码,我们既可以输出时间、模块名称,又可以输出不同级别的日志信息作区分并加以过滤,是不是灵活多了? 当然这只是 logging 模块的一小部分功能,接下来我们首先来全面了解一下 basicConfig
的参数都有哪些:
-
filename
:即日志输出的文件名,如果指定了这个信息之后,实际上会启用 FileHandler,而不再是 StreamHandler,这样日志信息便会输出到文件中了。 -
filemode
:这个是指定日志文件的写入方式,有两种形式,一种是 w,一种是 a,分别代表清除后写入和追加写入。 -
format
:指定日志信息的输出格式,即上文示例所示的参数,详细参数可以参考:部分参数如下所示:
- %(levelno) s:打印日志级别的数值。
- %(levelname) s:打印日志级别的名称。
- %(pathname) s:打印当前执行程序的路径,其实就是 sys.argv [0]。
- %(filename) s:打印当前执行程序名。
- %(funcName) s:打印日志的当前函数。
- %(lineno) d:打印日志的当前行号。
- %(asctime) s:打印日志的时间。
- %(thread) d:打印线程 ID。
- %(threadName) s:打印线程名称。
- %(process) d:打印进程 ID。
- %(processName) s:打印线程名称。
- %(module) s:打印模块名称。
- %(message) s:打印日志信息。
-
datefmt
:指定时间的输出格式。 -
style
:如果 format 参数指定了,这个参数就可以指定格式化时的占位符风格,如 %、{、$ 等。 -
level
:指定日志输出的类别,程序会输出大于等于此级别的信息。 -
stream
:在没有指定 filename 的时候会默认使用 StreamHandler,这时 stream 可以指定初始化的文件流。 -
handlers
:可以指定日志处理时所使用的 Handlers,必须是可迭代的。
下面我们再用一个实例来感受一下:
import logging
logging.basicConfig(level=logging.DEBUG,
filename='output.log',
datefmt='%Y/%m/%d %H:%M:%S',
format='%(asctime)s - %(name)s - %(levelname)s - %(lineno)d - %(module)s - %(message)s')
logger = logging.getLogger(__name__)
logger.info('This is a log info')
logger.debug('Debugging')
logger.warning('Warning exists')
logger.info('Finish')
这里我们指定了输出文件的名称为 output.log,另外指定了日期的输出格式,其中年月日的格式变成了 % Y/% m/% d,另外输出的 format 格式增加了 lineno、module 这两个信息,运行之后便会生成一个 output.log 的文件,内容如下:
2022/04/13 21:50:20 - __main__ - INFO - 9 - test - This is a log info
2022/04/13 21:50:20 - __main__ - DEBUG - 10 - test - Debugging
2022/04/13 21:50:20 - __main__ - WARNING - 11 - test - Warning exists
2022/04/13 21:50:20 - __main__ - INFO - 12 - test - Finish
可以看到日志便会输出到文件中,同时输出了行号、模块名称等信息。 以上我们通过 basicConfig 来进行了一些全局的配置,我们同样可以使用 Formatter、Handler 进行更灵活的处理,下面我们来了解一下。
Level
首先我们来了解一下输出日志的等级信息,logging 模块共提供了如下等级,每个等级其实都对应了一个数值,列表如下:
等级 | 数值 |
---|---|
CRITICAL | 50 |
FATAL | 50 |
ERROR | 40 |
WARNING | 30 |
WARN | 30 |
INFO | 20 |
DEBUG | 10 |
NOTSET | 0 |
这里最高的等级是 CRITICAL 和 FATAL,两个对应的数值都是 50,另外对于 WARNING 还提供了简写形式 WARN,两个对应的数值都是 30。 我们设置了输出 level,系统便只会输出 level 数值大于或等于该 level 的的日志结果,例如我们设置了输出日志 level 为 INFO,那么输出级别大于等于 INFO 的日志,如 WARNING、ERROR 等,DEBUG 和 NOSET 级别的不会输出。
import logging
logger = logging.getLogger(__name__)
logger.setLevel(level=logging.WARN)
# Log
logger.debug('Debugging')
logger.critical('Critical Something')
logger.error('Error Occurred')
logger.warning('Warning exists')
logger.info('Finished')
这里我们设置了输出级别为 WARN,然后对应输出了五种不同级别的日志信息,运行结果如下:
Critical Something
Error Occurred
Warning exists
可以看到只有 CRITICAL、ERROR、WARNING 信息输出了,DEBUG、INFO 信息没有输出。
Handler
下面我们先来了解一下 Handler 的用法,看下面的实例:
import logging
logger = logging.getLogger(__name__)
logger.setLevel(level=logging.INFO)
handler = logging.FileHandler('output.log')
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
handler.setFormatter(formatter)
logger.addHandler(handler)
logger.info('This is a log info')
logger.debug('Debugging')
logger.warning('Warning exists')
logger.info('Finish')
这里我们没有再使用 basicConfig 全局配置,而是先声明了一个 Logger 对象,然后指定了其对应的 Handler 为 FileHandler
对象,然后 Handler 对象还单独指定了 Formatter 对象单独配置输出格式,最后给 Logger 对象添加对应的 Handler 即可,最后可以发现日志就会被输出到 output.log 中,内容如下:
2022-04-13 22:04:00,269 - __main__ - INFO - This is a log info
2022-04-13 22:04:00,269 - __main__ - WARNING - Warning exists
2022-04-13 22:04:00,269 - __main__ - INFO - Finish
另外我们还可以使用其他的 Handler 进行日志的输出,logging 模块提供的 Handler 有:
- StreamHandler:
logging.StreamHandler
;日志输出到流,可以是 sys.stderr,sys.stdout 或者文件。 - FileHandler:
logging.FileHandler
;日志输出到文件。 - BaseRotatingHandler:
logging.handlers.BaseRotatingHandler
;基本的日志回滚方式。 - RotatingHandler:
logging.handlers.RotatingHandler
;日志回滚方式,支持日志文件最大数量和日志文件回滚。 - TimeRotatingHandler:
logging.handlers.TimeRotatingHandler
;日志回滚方式,在一定时间区域内回滚日志文件。 - SocketHandler:
logging.handlers.SocketHandler
;远程输出日志到 TCP/IP sockets。 - DatagramHandler:
logging.handlers.DatagramHandler
;远程输出日志到 UDP sockets。 - SMTPHandler:
logging.handlers.SMTPHandler
;远程输出日志到邮件地址。 - SysLogHandler:
logging.handlers.SysLogHandler
;日志输出到 syslog。 - NTEventLogHandler:
logging.handlers.NTEventLogHandler
;远程输出日志到 Windows NT/2000/XP 的事件日志。 - MemoryHandler:
logging.handlers.MemoryHandler
;日志输出到内存中的指定 buffer。 - HTTPHandler:
logging.handlers.HTTPHandler
;通过”GET” 或者”POST” 远程输出到 HTTP 服务器。
下面我们使用三个 Handler 来实现日志同时输出到控制台、文件、HTTP 服务器:
import logging
from logging.handlers import HTTPHandler
import sys
logger = logging.getLogger(__name__)
logger.setLevel(level=logging.DEBUG)
# StreamHandler 日志输出到流
stream_handler = logging.StreamHandler(sys.stdout)
stream_handler.setLevel(level=logging.DEBUG)
logger.addHandler(stream_handler)
# FileHandler 日志输出到文件
file_handler = logging.FileHandler('output.log')
file_handler.setLevel(level=logging.INFO)
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
file_handler.setFormatter(formatter)
logger.addHandler(file_handler)
# HTTPHandler 通过”GET” 或者”POST” 远程输出到 HTTP 服务器
http_handler = HTTPHandler(host='localhost:8001', url='log', method='POST')
logger.addHandler(http_handler)
# Log
logger.info('This is a log info')
logger.debug('Debugging')
logger.warning('Warning exists')
logger.info('Finish')
运行之前我们需要先启动 HTTP Server,并运行在 8001 端口,其中 log 接口是用来接收日志的接口。 运行之后控制台输出会输出如下内容:
python -m http.server 8001
This is a log info
Debugging
Warning exists
Finish
output.log 文件会写入如下内容:
2018-06-03 15:13:44,895 - __main__ - INFO - This is a log info
2018-06-03 15:13:44,947 - __main__ - WARNING - Warning exists
2018-06-03 15:13:44,949 - __main__ - INFO - Finish
HTTP Server 会收到控制台输出的信息。 这样一来,我们就通过设置多个 Handler 来控制了日志的多目标输出。 另外值得注意的是,在这里 StreamHandler 对象我们没有设置 Formatter,因此控制台只输出了日志的内容,而没有包含时间、模块等信息,而 FileHandler 我们通过 setFormatter () 方法设置了一个 Formatter 对象,因此输出的内容便是格式化后的日志信息。 另外每个 Handler 还可以设置 level 信息,最终输出结果的 level 信息会取 Logger 对象的 level 和 Handler 对象的 level 的交集。
Formatter
在进行日志格式化输出的时候,我们可以不借助于 basicConfig 来全局配置格式化输出内容,可以借助于 Formatter 来完成,下面我们再来单独看下 Formatter 的用法:
import logging
logger = logging.getLogger(__name__)
logger.setLevel(level=logging.WARN)
formatter = logging.Formatter(fmt='%(asctime)s - %(name)s - %(levelname)s - %(message)s', datefmt='%Y/%m/%d %H:%M:%S')
handler = logging.StreamHandler()
handler.setFormatter(formatter)
logger.addHandler(handler)
# Log
logger.debug('Debugging')
logger.critical('Critical Something')
logger.error('Error Occurred')
logger.warning('Warning exists')
logger.info('Finished')
在这里我们指定了一个 Formatter,并传入了 fmt 和 datefmt 参数,这样就指定了日志结果的输出格式和时间格式,然后 handler 通过 setFormatter () 方法设置此 Formatter 对象即可,输出结果如下:
2022/04/13 22:18:37 - __main__ - CRITICAL - Critical Something
2022/04/13 22:18:37 - __main__ - ERROR - Error Occurred
2022/04/13 22:18:37 - __main__ - WARNING - Warning exists
捕获 Traceback
如果遇到错误,我们更希望报错时出现的详细 Traceback 信息,便于调试,利用 logging 模块我们可以非常方便地实现这个记录,我们用一个实例来感受一下:
import logging
logger = logging.getLogger(__name__)
logger.setLevel(level=logging.DEBUG)
# Formatter
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
# FileHandler 日志输出到文件
file_handler = logging.FileHandler('result.log')
file_handler.setFormatter(formatter)
logger.addHandler(file_handler)
# StreamHandler 日志输出到流
stream_handler = logging.StreamHandler()
stream_handler.setFormatter(formatter)
logger.addHandler(stream_handler)
# Log
logger.info('Start')
logger.warning('Something maybe fail.')
try:
result = 10 / 0
except Exception:
logger.error('Faild to get result', exc_info=True)
logger.info('Finished')
这里我们在 error () 方法中添加了一个参数,将 exc_info
设置为了 True,这样我们就可以输出执行过程中的信息了,即完整的 Traceback 信息。 运行结果如下:
2022-04-13 22:21:57,576 - __main__ - INFO - Start
2022-04-13 22:21:57,577 - __main__ - WARNING - Something maybe fail.
2022-04-13 22:21:57,577 - __main__ - ERROR - Faild to get result
Traceback (most recent call last):
File "D:/pycharm/project/test/test.py", line 23, in <module>
result = 10 / 0
ZeroDivisionError: division by zero
2022-04-13 22:21:57,577 - __main__ - INFO - Finished
Process finished with exit code 0
可以看到这样我们就非常方便地记录下来了报错的信息,一旦出现了错误,我们也能非常方便地排查。
配置共享
在写项目的时候,我们肯定会将许多配置放置在许多模块下面,这时如果我们每个文件都来配置 logging 配置那就太繁琐了,logging 模块提供了父子模块共享配置的机制,会根据 Logger 的名称来自动加载父模块的配置。 例如我们这里首先定义一个 test.py 文件:
import logging
import core
logger = logging.getLogger('test')
logger.setLevel(level=logging.DEBUG)
# Handler
handler = logging.FileHandler('result.log')
handler.setLevel(logging.INFO)
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
handler.setFormatter(formatter)
logger.addHandler(handler)
logger.info('Main Info')
logger.debug('Main Debug')
logger.error('Main Error')
core.run()
这里我们配置了日志的输出格式和文件路径,同时定义了 Logger 的名称为 test,然后引入了另外一个模块 core,最后调用了 core 的 run () 方法。 接下来我们定义 core.py,内容如下:
import logging
logger = logging.getLogger('test.core')
def run():
logger.info('Core Info')
logger.debug('Core Debug')
logger.error('Core Error')
这里我们定义了 Logger 的名称为 test.core,注意这里开头是 test,即刚才我们在 test.py 里面的 Logger 的名称,这样 core.py 里面的 Logger 就会复用 test.py 里面的 Logger 配置,而不用再去配置一次了。 运行之后会生成一个 result.log 文件,内容如下:
2022-04-13 22:26:30,718 - test - INFO - Main Info
2022-04-13 22:26:30,718 - test - ERROR - Main Error
2022-04-13 22:26:30,718 - test.core - INFO - Core Info
2022-04-13 22:26:30,718 - test.core - ERROR - Core Error
可以看到父子模块都使用了同样的输出配置。 如此一来,我们只要在入口文件里面定义好 logging 模块的输出配置,子模块只需要在定义 Logger 对象时名称使用父模块的名称开头即可共享配置,非常方便。
文件配置
在开发过程中,将配置在代码里面写死并不是一个好的习惯,更好的做法是将配置写在配置文件里面,我们可以将配置写入到配置文件,然后运行时读取配置文件里面的配置,这样是更方便管理和维护的,下面我们以一个实例来说明一下,首先我们定义一个 config.yaml 配置文件:
version: 1
formatters:
brief:
format: "%(asctime)s - %(message)s"
simple:
format: "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
handlers:
console:
class : logging.StreamHandler
formatter: brief
level : INFO
stream : ext://sys.stdout
file:
class : logging.FileHandler
formatter: simple
level: DEBUG
filename: debug.log
error:
class: logging.handlers.RotatingFileHandler
level: ERROR
formatter: simple
filename: error.log
maxBytes: 10485760
backupCount: 20
encoding: utf8
loggers:
main.core:
level: DEBUG
handlers: [console, file, error]
root:
level: DEBUG
handlers: [console]
这里我们定义了 formatters、handlers、loggers、root 等模块,实际上对应的就是各个 Formatter、Handler、Logger 的配置,参数和它们的构造方法都是相同的。 接下来我们定义一个主入口文件,main.py,内容如下:
import logging
import core
import yaml
import logging.config
import os
def setup_logging(default_path='config.yaml', default_level=logging.INFO):
path = default_path
if os.path.exists(path):
with open(path, 'r', encoding='utf-8') as f:
config = yaml.load(f)
logging.config.dictConfig(config)
else:
logging.basicConfig(level=default_level)
def log():
logging.debug('Start')
logging.info('Exec')
logging.info('Finished')
if __name__ == '__main__':
yaml_path = 'config.yaml'
setup_logging(yaml_path)
log()
core.run()
这里我们定义了一个 setup_logging () 方法,里面读取了 yaml 文件的配置,然后通过 dictConfig () 方法将配置项传给了 logging 模块进行全局初始化。 另外这个模块还引入了另外一个模块 core,所以我们定义 core.py 如下:
import logging
logger = logging.getLogger('main.core')
def run():
logger.info('Core Info')
logger.debug('Core Debug')
logger.error('Core Error')
这个文件的内容和上文是没有什么变化的。 观察配置文件,主入口文件 main.py 实际上对应的是 root 一项配置,它指定了 handlers 是 console,即只输出到控制台。另外在 loggers 一项配置里面,我们定义了 main.core 模块,handlers 是 console、file、error 三项,即输出到控制台、输出到普通文件和回滚文件。 这样运行之后,我们便可以看到所有的运行结果输出到了控制台:
2022-04-13 22:33:03,014 - Exec
2022-04-13 22:33:03,014 - Finished
2022-04-13 22:33:03,014 - Core Info
2022-04-13 22:33:03,014 - Core Info
2022-04-13 22:33:03,014 - Core Error
2022-04-13 22:33:03,014 - Core Error
在 debug.log 文件中则包含了 core.py 的运行结果:
2022-04-13 22:34:11,901 - test.core - INFO - Core Info
2022-04-13 22:34:11,901 - test.core - DEBUG - Core Debug
2022-04-13 22:34:11,901 - test.core - ERROR - Core Error
可以看到,通过配置文件,我们可以非常灵活地定义 Handler、Formatter、Logger 等配置,同时也显得非常直观,也非常容易维护,在实际项目中,推荐使用此种方式进行配置。 以上便是 logging 模块的基本使用方法,有了它,我们可以方便地进行日志管理和维护,会给我们的工作带来极大的方便。
日志记录使用常见误区
在日志输出的时候经常我们会用到字符串拼接的形式,很多情况下我们可能会使用字符串的 format () 来构造一个字符串,但这其实并不是一个好的方法,因为还有更好的方法,下面我们对比两个例子:
import logging
logging.basicConfig(level=logging.DEBUG, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
# bad
logging.debug('Hello {0}, {1}!'.format('World', 'Congratulations'))
# good
logging.debug('Hello %s, %s!', 'World', 'Congratulations')
这里有两种打印 Log 的方法,第一种使用了字符串的 format () 的方法进行构造,传给 logging 的只用到了第一个参数,实际上 logging 模块提供了字符串格式化的方法,我们只需要在第一个参数写上要打印输出的模板,占位符用 % s、% d 等表示即可,然后在后续参数添加对应的值就可以了,推荐使用这种方法。 运行结果如下:
2022-04-13 22:35:05,766 - root - DEBUG - Hello World, Congratulations!
2022-04-13 22:35:05,766 - root - DEBUG - Hello World, Congratulations!
另外在进行异常处理的时候,通常我们会直接将异常进行字符串格式化,但其实可以直接指定一个参数将 traceback 打印出来,示例如下:
import logging
logging.basicConfig(level=logging.DEBUG, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')
try:
result = 5 / 0
except Exception as e:
# bad
logging.error('Error: %s', e)
# good
logging.error('Error', exc_info=True)
# good
logging.exception('Error')
如果我们直接使用字符串格式化的方法将错误输出的话,是不会包含 Traceback 信息的,但如果我们加上 exc_info 参数或者直接使用 exception () 方法打印的话,那就会输出 Traceback 信息了。 运行结果如下:
2018-06-03 22:24:31,927 - root - ERROR - Error: division by zero
2018-06-03 22:24:31,927 - root - ERROR - Error
Traceback (most recent call last):
File "/private/var/books/aicodes/loggingtest/demo9.py", line 6, in <module>
result = 5 / 0
ZeroDivisionError: division by zero
2018-06-03 22:24:31,928 - root - ERROR - Error
Traceback (most recent call last):
File "/private/var/books/aicodes/loggingtest/demo9.py", line 6, in <module>
result = 5 / 0
ZeroDivisionError: division by zero
以上便是整个对 logging 模块的介绍。
参考文献
- https://cuiqingcai.com/6080.html
- https://juejin.cn/post/6937240397424885796