更 Pythonic 的方式来记录日志 ( logging )

我不知道大家看到这个标题的时候第一时间想到的是什么？对，我第一时间想到的，到底什么是 Pythonic 啊！

Pythonic

然后我就疯狂的百度和谷歌了一把，发现说的都是模凌两可

介绍的都是什么「 Python 禅」从某些方面说，就是

>>> import this
The Zen of Python, by Tim Peters

Beautiful is better than ugly.
Explicit is better than implicit.
Simple is better than complex.
Complex is better than complicated.
Flat is better than nested.
Sparse is better than dense.
Readability counts.
Special cases aren't special enough to break the rules.
Although practicality beats purity.
Errors should never pass silently.
Unless explicitly silenced.
In the face of ambiguity, refuse the temptation to guess.
There should be one-- and preferably only one --obvious way to do it.
Although that way may not be obvious at first unless you're Dutch.
Now is better than never.
Although never is often better than *right* now.
If the implementation is hard to explain, it's a bad idea.
If the implementation is easy to explain, it may be a good idea.
Namespaces are one honking great idea -- let's do more of those!

可即使我们知道了，记牢了，就是 Pythonic 了吗？我不知道

我自己对 Pythonic 的理解就是： 使用 Python 的方式编写 Python 代码

怎么理解这句话呢

比如，如果要遍历输出 10 以内的偶数, 不是

>>> i = 0
>>> while i < 10:
...     if i % 2 == 0:
...             print(i)
...     i +=1
... 
0
2
4
6
8

也不是

>>> for i in range(10):
...     if i % 2 == 0:
...             print(i)
... 
0
2
4
6
8

而是

for i in range(10,2):
    print(x)

虽然这几种方式都能达到效果，但最 Pythonic 的方式应该是最后一个

更 Pythonic 的方式来记录日志 ( logging )

说回正题，我们来看看什么是 Pythonic 的方式记录日志

如果使用正确，日志是我们的可观察性套件的重要组成部分。日志讲述了应用程序中数据如何变化的故事，日志可以帮助我们回答以下问题：为什么 John Doe 在结账时收到错误？他到底输入了什么？

日志记录的历史可以从丰富的结构化数据事件追溯到非常简单的静态字符串语句

在本文中，我们将探讨如何使用Python 进行日志记录可以更好地了解应用程序中发生的情况，此外，我们将探索一些最佳实践，这些实践将帮助我们使用内置的Python 模块从日志中获得最大价值

Print('Why Not Just Use The Print Statement?')

为什么不使用 print() 语句？

许多 Python 教程都向读者样式了如何使用 print() 语句来作为调试工具

例如下面的示例，使用 print() 打印异常

>>> import sys
>>>
>>> def captureException():
...     return sys.exc_info()
...
>>> try:
...     1/0
... except:
...     print(captureException())
...
(<class 'ZeroDivisionError'>, ZeroDivisionError('division by zero',), <traceback object at 0x101acb1c8>)
None

虽然这在较小的脚本中很有用，但随着应用程序和操作要求的增长，print() 成为一种不太可行的解决方案。它不能为我们提供供关闭整个输出语句类别的灵活性，它只允许我们输出到标准输出 stdout 。它还会错过生成的行号和时间等信息，这些信息可以帮助调试

虽然 print() 是最简单的方法，因为它不需要设置，它可以很快的回应我们，但将某个包的日志直接输出到 stdout 却是一个不好的做法，因为它删除了用户控制消息的能力

Logging.Info("Hello World To Logging")

从版本 2.3 开始，日志记录模块 logging 就成为 Python 标准库中的一部分，它会自动将日志 ( 例如行号和时间戳 ) 添加到日志中

该模块可以轻松的分门别类日志信息和添加严重性级别，以便我们可以更好地控制输出的位置和内容

我相信最好的学习方法就是去做，所以我鼓励你使用 Python 交互式解释器 ( Python REPL ) 来学习它们

开始使用日志记录模块 logging 很简单，下面这些就是所需要做的

>>> import logging
>>> logging.basicConfig()
>>> logger = logging.getLogger(__name__)

>>> logger.critical('使用 `logging` 记录日志比我想象的要简单')
CRITICAL:__main__:使用 `logging` 记录日志比我想象的要简单

刚刚发生了什么？

getLogger() 为我们提供了一个记录器实例，然后，我们给了它一个事件 使用logging记录日志比我想象的要简单 和日志记录级别 critical

日志记录级别

logging 这个 Python 模块允许我们根据事件的严重性级别区分事件。日志记录级别使用 0 到 50 之间的整数来表示。logging 模块定义了五个常量，便于区分消息

每个级别都附有意义，你应该批判性地考虑正在记录的级别

>>> logger.critical("this better be bad")
CRITICAL:root:this better be bad
>>> logger.error("more serious problem")
ERROR:root:more serious problem
>>> logger.warning("an unexpected event")
WARNING:root:an unexpected event
>>> logger.info("show user flow through program")
>>> logger.debug("used to track variables when coding")

需要注意的是 info 和 debug 并不会输出任何消息。默认情况下，记录器仅打印警告 warning，错误 error 或关键消息 critical。我们可以自定义此行为，甚至可以在运行时对其进行修改以动态激活更详细的日志记录

>>> # 降低显示级别，info 的级别比 debug 高
>>> logger.setLevel(logging.DEBUG)
>>> logger.info(1)
INFO:root:1
>>>
>>> # 提高显示级别，info 的级别比 warning 低
... logger.setLevel(logging.WARNING)
>>> logger.info(2)

格式化日志

默认的格式化程序并不会格式化日志，因为它不包含关键信息。但 logging 模块提供了一些函数可以轻松的添加格式化信息

>>> import logging
>>> logFormatter = '%(asctime)s - %(levelname)s - %(message)s'
>>> logging.basicConfig(format=logFormatter, level=logging.DEBUG)
>>> logger = logging.getLogger(__name__)
>>> logger.info("test")
2018-06-19 17:42:38,134 - INFO - test

其中一些数据 ( 如 time 和 levelname ) 可以自动捕获，但我们可以 ( 且应该 ) 将 extra 的上下文推送到日志中

添加上下文信息

通用日志消息提供的信息几乎与没有日志消息一样少

想象一下，如果你必须通过你的日志，当你看到 removed from cart。这种日志信息，使得很难回答以下问题：项目什么时候删除？谁删除了它？他们删除了什么？

因此，最好是将结构化数据添加到日志中，而不是使用 string-ifying 对象来丰富它。如果没有结构化数据，将来很难破译日志流

处理此问题的最佳方法是将重要元数据推送到 extra 对象，使用此功能，我们将能够在流中丰富我们的日志消息

>>> import logging
>>> logFormatter = '%(asctime)s - %(user)s - %(levelname)s - %(message)s'
>>> logging.basicConfig(format=logFormatter, level=logging.DEBUG)
>>> logger = logging.getLogger(__name__)
>>> logger.info('purchase completed', extra={'user': 'Sid Panjwani'})
2018-06-19 17:44:10,276 - Sid Panjwani - INFO - purchase completed

性能

日志记录会引入了需要与我们编写的软件的性能要求相平衡的开销。虽然开销通常可以忽略不计，但不良做法和错误可能导致不幸的情况

以下是一些有用的小技巧

记录日志前先检查日记级别

Python 模块 logging 文档中推荐记录日志前先检查日记级别，这样可以延迟评估

if logger.isEnabledFor(logging.INFO):
    logger.debug('%s', expensive_func())

这样，仅当日志记录级别大于或等于 INFO 时才会调用 expensive_func

避免在热路径中记录日志

热路径是对性能至关重要的代码，因此经常执行。最好避免在这里记录，因为它可能成为 IO 瓶颈，除非有必要，比如要记录的数据在热路径之外不可用

存储和访问记录的日志

现在你已经学会了如何生成这些 ( 漂亮的 ) 日志，接下来你必须确定如何处理它们

默认情况下，日志会写入标准输出设备 ( 可能是您的终端窗口 )，但 Python 的日志记录模块 logging 提供了一组丰富的选项来自定义输出处理

推荐的做法是将日志记录输出到标准输出，因为 Heroku，Amazon Elastic Beanstalk 和 Docker 等平台通过捕获标准输出并重定向到平台级别的其他日志记录工具中

记录到文件中

logging 模块可以使用「处理程序 ( handler ) 」将日志写入本地文件，以便长期保留

>>> import logging
>>> logger = logging.getLogger(__name__)
>>>
>>> handler = logging.FileHandler('myLogs.log')
>>> handler.setLevel(logging.INFO)
>>>
>>> logger.addHandler(handler)
>>> logger.info('You can find this written in myLogs.log')

如果你一直在跟踪观察日志 ( 您应该这样做 )，你会注意到您的日志不会显示在你的文件中，因为默认的级别是 info ，所以需要确保使用 setLevel() 来更改它

当把日志记录到文件后，就可以轻松的使用 grep 搜索日志文件

grep critical myLogs.log

现在，我们就可以搜索那些包含了 critical 关键字或 warning 关键字的信息

轮转日志 ( 分割日志 )

Python logging 日志记录模块可以在一段时间后或日志文件达到特定大小后轻松将日志记录到其它文件

如果你想要自动删除旧日志，或者要按日期搜索日志，这将变得非常有用，因为你不必搜索大文件来查找已经分组的一组日志

要创建每天生成新日志文件并自动删除超过五天的日志的处理程序，可以使用 TimedRotatingFileHandler

logger = logging.getLogger('Rotating Log by Day')

# writes to pathToLog
# creates a new file every day because `when="d"` and `interval=1`
# automatically deletes logs more than 5 days old because `backupCount=5`
handler = TimedRotatingFileHandler(pathToLog, when="d", interval=1,  backupCount=5)