循序渐进学习 Python logging (1) - 入门

循序渐进学习 Python logging (1) - 入门

1. Logging 基础教程

记录日志是跟踪软件运行中所发生事件的一种方法。软件开发者在代码中加入 logging 调用，以表明某些事件发生了。事件由一串描述性的消息来说明，这串消息可以包含可变数据（例如，数据的值可以随着事件的每次发生而不同）。事件有不同的重要性，这种重要性是开发者指定的，一般也称为：级别或严重性。

1.1 何时使用 logging

logging 模块提供了一系列方便使用的函数，如：debug()，info()，warning()，error()，critical()。那么，什么情况下要使用 logging 呢？下表列出了一些常见的任务，以及完成这些任务最好的工具：

任务	最好工具
普通命令行脚本或程序，显示控制台输出	print()
报告在程序正常操作过程中发生的事件（例如，状态监视 或 错误检查）	logging.info() （或 logging.debug() 来输出非常详细的诊断信息）
发出关于某个特殊的运行时事件的警告	warning.warn() ：如果问题是可避免的并且应该修改客户端应用程序来消除警告 logging.warning()：如果客户端应用程序处理不了这种情况，但是事件仍然应该引起注意
报告关于某个特殊的运行时事件的错误	抛出异常
报告抑制了某个错误而没有抛出异常（例如，在一个长期运行的服务器进程中的错误处理）	根据出现的具体错误，选择 logging.error()，logging.exception() 或 logging.critical() 这三者中合适的一个

上面的 logging 函数是根据他们各自所跟踪的事件的基本或严重性来命名的。标准的级别和他们的适用场景见下表（按严重性增大顺序）：

级别	用途
DEBUG	输出详细信息，一般只有在诊断问题时才会关注这些信息
INFO	确认一切都按照预期的方式在进行工作
WARNING	表明出现了一些意外情况，或暗示在不久的将来会出问题（例如：磁盘空间不足）。但目前软件仍然按预期的方式在工作
ERROR	出现了更严重的问题，软件的部分功能已经无法正常工作
CRITICAL	严重的错误，软件自身可能已经没法继续运行下去

1.2 简单示例

下面是一个非常简单的示例：

import logging
logging.warning('Watch out!')  # will print a message to the console
logging.info('I told you so')  # will not print anything

如果你把上面的代码写到一个脚本并运行，你会在控制台得到下面输出：

WARNING:root:Watch out!

INFO 级别的消息没有打印出来，因为默认的日志级别是 WARNING。打印出的消息中包含日志级别，函数调用时提供的描述信息 （如，Watch out），还有个叫做 root 的部分。实际上输出可以很灵活的格式化，这些都在下面介绍。

1.3 将日志写到文件

将日志写到文件是个很常见的需求，接下来我们就来看看如何将日志写到文件。请在一个新打开的解释器中测试如下代码：

import logging
logging.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 file
INFO:root:So should this
WARNING:root:And this, too

这个例子也向你展示了如何设置日志的级别，日志级别相当于日志跟踪的阈值。在这个例子中，我们将阈值设置成了 DEBUG，因此所有的消息都被打印出来了。如果你想通过命令行选项来设置日志级别，例如，像下面这样：

--log=INFO

并且你把这个命令行参数的值存在了某个变量（如，loglevel）中，你就可以使用下面的语法来获得你想传递给 baseConfig() 中 level 这个参数对应的整型值，从而达到设置日志级别的目的。

getattr(logging, loglevel.upper(), None)

你可能还想对用户输入的值进行错误检测，也许，就像下面的代码一样：

# 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=debug
numeric_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() 等之前。因为它是作为一次性的简单配置工具，仅有第一次调用才会真正起作用，随后的调用不会起作用，相当于空操作。如果你多次运行上面的脚本，随后运行产生的消息都会被追加到 example.log 中，如果你想每次运行时都将日志清空重写，你可以通过指定 filemode 参数，就像下面这样设置：

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

这样得到的输出就和前面的一样，但是日志文件不再被追加，先前运行时产生的信息都将丢掉。

1.4 从多个模块记录日志

如果你的程序由多个模块组成，下面这个例子展现了在这种情况下如何在你的程序中组织 logging ：

# 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

这应该正是你想要看到的。你可以参照 mylib.py 里面的用法，在多个模块中这样使用 logging。但是请注意，在这种简单的用法下，当你查看日志文件的时候，你不会知道这些消息是你应用中的哪个部分发过来的，除非你看具体事件的描述信息。如果你想追踪日志消息是从哪个模块发出来的，你应该查看高级 logging 教程。

1.5 记录可变数据

如果想记录可变数据，可以在事件的描述信息中使用格式化字符串，并且将变量数据放在后面作为参数。如下：

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

输出如下：

WARNING:root:Look before you leap!

如你所见，可以通过在事件描述信息中使用老式的 % 语法，将可变数据合并进来。这是为了向后兼容：因为 logging 包出现的时期比新式格式化语法（如：str.format()，str.Template）要早。当然这些新的格式化语法也是 logging 所支持的，但是这些不在本文讨论之列。

1.6 改变显示信息的格式

为了改变显示信息的格式，那么你就得显式指明你想使用的格式：

import logging
logging.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 console
INFO:So should this
WARNING:And this, too

你会发现在前面例子中出现的 root 不见了。如果想得到完整的可用格式化字符串列表，请参考下面连接：https://docs.python.org/2.7/library/logging.html#logrecord-attributes ，如果只是简单使用的话，你只需要 levelname （日志级别），message（事件描述信息，包括可变数据）。或许你还想显示事件是什么时候发生的，这就是下面要讲的。

1.7 在消息中显示日期/时间

为了显示一个事件发生的日期和时间，你需要在格式化字符串中放入：%(asctime)s 这个参数：

import logging
logging.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。如果你想对时间和日期的显示格式进行控制，那么就得像下面这样在 basicConfig() 中，提供 datefmt 参数：

import logging
logging.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() 所支持的格式一样。

1.8 下一步

到此，初级教程就结束了。这应该可以让你使用 logging 工作了。logging 软件包还包含许多其他内容，但是如果想更有效的使用 logging 包，你需要再花一点时间来读下一篇文章，如果你已经准备好了，那么现在区找瓶你喜欢的汽水，然后接着开始阅读吧。