cover_image

【译】Python3.8官方Logging文档--基础部分

武当张三丰 魔笛手CTO
2020年02月08日 06:39

图片

在《后端问题如何快速定位?》中老张强调了日志的重要性,也提到了使用日志需要的注意的一些问题。但是并没有提到实践方式,其实掌握一个工具最快的方法就是阅读官方文档,老张试着翻译了Python3.8官方Logging文档,由于官方文档实在是长,所以会分成两到三篇文章。官方文档给出了非常详细的设计思想、实践方式,相信你读完肯定会非常受用。

日志是用来的记录程序运行事件的工具。当程序员可以通过添加日志打印的代码来记录程序运行过程中发生的某些事件时。这些事件包含了诸如变量数据在内的描述信息,当然也包括开发人员认为重要的诸如日志级别等信息。


什么时候使用Loggin包

针对简单的场景,Loggin包提供了一系列方便的函数。其中包括debug()、info()、warning()、error()以及 critical()。下面的表格列举了什么函数适用于什么场景。


需求场景

适用工具

在命令行场景下,需要在控制台打印输出信息

print()

需要记录一些程序正常运行的事件信息(例如运行状态或者调试信息)

logging.info() (为了记录非常详细的调试信息也可以使用 logging.debug() )

担心程序运行时可能发生的某些告警

  • warnings.warn() 适用于可以通过调整代码主动避免问题的场景

  • logging.warning() 适用于不需要调整代码仅记录问题信息的场景

记录特定的错误信息

抛异常

记录那些不需要抛异常的错误信息(例如捕捉服务进程长时间运行期间的错误信息)

logging.error(), logging.exception() 或者 logging.critical() 都可以适用


日志函数的命名依据于约定俗成的事件级别。不同事件级别的适用范围可以参考下面的这个表格(按照级别的严重程度升序排列):

事件级别

适用范围

DEBUG

通常用在调试程序时输出详细信息

INFO

确认程序在正常运行

WARNING

在程序依旧能够正常运行的情况下:记录某个期望外的运行事件;记录一些达到临界值的运行信息(例如磁盘空间不足)

ERROR

因为某些严重的运行错误,影响程序的某些功能使用

CRITICAL

运行错误存在导致程序不能继续运行的场景

缺省的事件级别为WARNING,也就是说只有WARNING级别已经高于WARNING级别的事件可以被捕捉到。如果需要其他级别的信息,可以显式的设置日志级别。

针对捕捉到的运行事件有多种的处理措施,最简单的措施就是在控制台打印出来,当然也可以把这些事件信息记录到磁盘。


简单演示

下面是一个非常简单的用例:

import logginglogging.warning('Watch out!')  # 信息会被输出到控制台logging.info('I told you so')  # 这时不会打印任何信息

运行上述代码,执行结果如下:

WARNING:root:Watch out!

INFO级别的消息没有输出是因为缺省的日志级别是WARNING级别。观察输出信息,其中包含了日志级别以及调用日志函数时的入参信息(示例中为‘Watch out!’)。你可能会对中间的root有些疑惑,稍后会解释的。实际使用时,你可以根据需要灵活调整输出格式,对于输出格式稍后也会进一步解释。


把日志写入文件

这一部分是介绍比较实用的一种形式——是把日志记录在文件中。如果你打算运行下面的代码示例,记得新打开一个Python运行界面,而不是继续使用上面运行过的。

import logginglogging.basicConfig(filename='example.log',level=logging.DEBUG)logging.debug('This message should go to the log file')logging.info('So should this')logging.warning('And this, too')

执行完这段代码之后,打开日志文件就会发现多了这些日志内容:

DEBUG:root:This message should go to the log fileINFO:root:So should thisWARNING:root:And this, too

上面的实例也展示了可以在一开始通过配置改变日志级别。因为一开始就把日志级别设置为了DEBUG,所以对应的日志也被记录了下来。


如果你你希望通过以下方式在命令行配置日志级别:

--log=INFO

如果向--log传递了符合规范的变量值,可以使用:

getattr(logging, loglevel.upper())

来获取入参,进而传递给basicConfig()函数。或许你也想到了需要对入参进行校验,下面提供了一个校验入参的示例:

# assuming loglevel is bound to the string value obtained from the# command line argument. Convert to upper case to allow the user to# specify --log=DEBUG or --log=debugnumeric_level = getattr(logging, loglevel.upper(), None)if not isinstance(numeric_level, int):    raise ValueError('Invalid log level: %s' % loglevel)logging.basicConfig(level=numeric_level, ...)


basicConfig()函数的调用必须在debug()、info()以及其他日志输出函数之前。必须指出的是,baiscConfig()函数仅在第一次调用的时候生效,再次调用将不会产生任何作用。


如果你多次运行了上面的代码,你会发现日志文件里保存了多次运行的日志信息。可能你不需要把每次运行的日志信息都记录下来,而是仅保留最新的一次,那么你可以通过改变filemode 入参来实现,下面是一个示例:

logging.basicConfig(filename='example.log', filemode='w', level=logging.DEBUG)

这样话,虽然多次运行都是一样的日志,但是只有最新一次的运行日志被保留下来,之前的都会被刷掉。


在多个模块中使用Logging

如果你的程序包含多个模块,你可以参考下面的示例来组织你的代码:

# myapp.pyimport loggingimport 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.pyimport logging
def do_something(): logging.info('Doing something')

运行myapp.py后,你会发现myapp.log记录的日志信息如下:

INFO:root:StartedINFO:root:Doing somethingINFO:root:Finished

实际结果和你期望的一样。mylib.py的示例你可以灵活运用在你自己的多模块程序中。不过,需要注意的是,在这个简单的示例中,不同py文件的日志被穿插保存。《高级部分》(老张后面的推送会更新)部分会提供给你进一步的区分不同py文件日志信息的方法。


记录变量信息

通过格式化字符串的方式可以将想要保存的描述信息以及变量方便的保存下来。举个例子:

import logginglogging.warning('%s before you %s', 'Look', 'leap!')

运行结果如下:

WARNING:root:Look before you leap!

和你看到的一样,将变量格式化到描述信息的方式是使用的%这种旧的形式。这是为了向后兼容:logging包比新的格式化方式(比如str.format()、string.Template)诞生的要早。虽然logging也支持新的格式化方式,但是这里不做介绍。


自定义日志信息的格式

如果有需要,你可以自定义日志消息的格式:

import logginglogging.basicConfig(format='%(levelname)s:%(message)s', level=logging.DEBUG)logging.debug('This message should appear on the console')logging.info('So should this')logging.warning('And this, too')

运行结果如下:

DEBUG:This message should appear on the consoleINFO:So should thisWARNING:And this, too

可以看到之前一直在日志消息里面出现的“root”消失了。还有其他好多配置项,但是在简单场景下,你需要也许仅是levelname(级别),message(事件描述、变量信息),以及事件的发生时间。下面一章介绍时间配置。


展示时间信息

你可以通过增加‘%(asctime)s’来让你的程序输出时间信息:

import logginglogging.basicConfig(format='%(asctime)s %(message)s')logging.warning('is when this event was logged.')

运行结果如下:

2010-12-12 11:41:42,612 is when this event was logged.

如上所示,默认的时间输出格式是ISO8601或者RFC 3339标准。如果你需要自定义时间格式,可以在调用basicConfig显示传入参数datefmt,示例如下:

import logginglogging.basicConfig(format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p')logging.warning('is when this event was logged.')

运行结果如下:

12/12/2010 11:46:36 AM is when this event was logged.

datefmt的格式配置信息同time.strftime()一样。


总结

通过对《基础部分》的学习,你应该掌握了如何在程序里添加日志代码。logging还提供了高阶用法,为了能够掌握高阶用法,你应该继续阅读《高级部分》(老张这里顺道挖个坑)。

但是如果你仅仅是想跟上面介绍一样,简单的在程序里面使用日志,并且你有什么不明白的地方,可以把问题发在:

https://groups.google.com/forum/#!forum/comp.lang.python

你会很快收到回复的。

图片

图片
在看点这里
图片
阅读原文
修改于2020年02月08日
继续滑动看下一个
魔笛手CTO
向上滑动看下一个