Python日志记录：一个深入的教程

前言

本周的推荐来啦，一篇关于python的logging日志模块使用的文章。 原文：Python Logging: An In-Depth Tutorial 作者：SON NGUYEN KIM

正文

随着应用程序变得越来越复杂，拥有良好的日志将会非常有用，不仅在调试时，而且为应用程序/性能问题提供数据分析的洞察力。 Python标准库附带一个 *logging*模块，它提供了大部分基本的记录功能。通过正确设置，日志消息可以提供有关日志何时何地被触发以及日志上下文（如正在运行的进程/线程）的大量有用信息。 尽管有这些优点，日志记录模块经常被忽略，因为它需要一些时间才能正确设置，并且在我看来，尽管完整，但官方日志记录文档位于https://docs.python.org/3/library/logging.html并没有真正给日志记录的最佳实践或突出一些日志记录的惊喜点。 这个Python日志教程并不意味着是日志模块上的完整文档，而是一个“入门指南”，它介绍了一些日志记录概念以及一些需要注意的“疑难杂症”。这篇文章将以最佳实践目的，并包含一些指向更高级日志记录主题的建议。 请注意，文章中的所有代码片段都假设您已经导入了日志记录模块：

import logging

Python日志的概念

本节概述了日志记录模块中经常遇到的一些概念。

Python日志级别

日志级别对应于给出日志的“重要性（importance）”：“error”日志应该比“warn”日志更紧急，而“debug”日志应该仅在调试应用程序时使用。 Python中有六个日志级别; 每个级别与指示日志严重性的整数相关联：NOTSET = 0，DEBUG = 10，INFO = 20，WARN = 30，ERROR = 40和CRITICAL = 50。 除NOTSET之外，所有级别都非常简单（DEBUG <INFO <WARN），其特殊性将在下面讨论。

Python日志记录格式

日志格式化程序基本上通过向其添加上下文信息来丰富日志消息。知道何时发送日志，何处（Python文件，行号，方法等）以及诸如线程和进程之类的附加上下文（在调试多线程应用程序时可能非常有用）可能很有用。 例如，当通过日志格式化程序发送日志“hello world”时：

"%(asctime)s — %(name)s — %(levelname)s — %(funcName)s:%(lineno)d — %(message)s"

它会变成

2018-02-07 19:47:41,864 - a.b.c - WARNING - <module>:1 - hello world

Python记录处理程序

日志处理程序是有效写入/显示日志的组件：在控制台console （通过StreamHandler），文件file （通过FileHandler）或通过SMTPHandler发送电子邮件等方式显示它。 每个日志处理程序有两个重要的字段

• 一种将上下文信息添加到日志的格式化程序。
• 日志级别，用于过滤掉级别较低的日志。所以具有INFO级别的日志处理程序不会处理DEBUG日志。

标准库提供了一些处理程序，这些处理程序应该足够用于常见用例：https://docs.python.org/3/library/logging.handlers.html#module-logging.handlers。最常见的是StreamHandler和FileHandler：

console_handler = logging.StreamHandler()
file_handler = logging.FileHandler("filename")

Python记录器

记录器可能是代码中最经常使用的记录器，也是最复杂的记录器。新的记录器可以通过以下方式获得：

toto_logger = logging.getLogger("toto")

记录器有三个主要领域：

• 传播(Propagate)：决定是否应将日志传播到记录器的父级。默认情况下，其值为True。
• 级别(A leve)：与日志处理程序级别一样，日志级别用于过滤掉“不太重要”的日志。除了日志处理程序以外，只能在“子”记录程序中检查级别; 一旦日志传播给其父母，级别将不会被检查。这是一种不直观的行为。
• 处理程序(Handlers)：日志在到达记录器时将被发送到的处理程序列表。这允许灵活的日志处理 - 例如，您可以拥有一个文件日志处理程序，用于记录所有的DEBUG日志和仅用于CRITICAL日志的电子邮件日志处理程序。在这方面，记录器处理程序关系类似于发布者 - 消费者关系：一旦通过日志记录程度检查，日志将被广播给所有处理程序。

记录器的名称是唯一的，这意味着如果创建了名称为“toto”的记录器，随后的调用logging.getLogger("toto")将返回相同的对象：

assert id(logging.getLogger("toto")) == id(logging.getLogger("toto"))

正如你可能猜到的，记录器有一个层次结构。在层次结构之上是根记录器，可以通过logging.root访问它。这个记录器在使用类似方法时被调用logging.debug()。默认情况下，根日志级别为WARN，因此每个具有较低级别的日志（例如通过logging.info("info")）都将被忽略。根记录器的另一个特殊之处在于，它会在首次记录级别大于WARN的日志时创建其默认处理程序。logging.debug()一般不建议直接或间接使用根记录器。 默认情况下，当创建一个新的记录器时，其父项将被设置为根记录器：

lab = logging.getLogger("a.b")
assert lab.parent == logging.root # lab's parent is indeed the root logger

但是，记录器使用“点符号”，这意味着名为“ab”的记录器将成为记录器“a”的孩子。但是，只有在创建了记录器“a”的情况下，才会发生这种情况，否则“ ab“父母仍然是根。

la = logging.getLogger("a")
assert lab.parent == la # lab's parent is now la instead of root

当记录器根据级别检查决定日志是否应该通过时（例如，如果日志级别低于记录器级别，日志将被忽略），它使用其“有效级别”而不是实际级别。如果级别不是NOTSET，则有效级别与记录器级别相同，也就是说，从DEBUG到CRITICAL的所有值; 然而，如果记录器级别是NOTSET，则有效级别将是具有非NOTSET级别的第一个祖先级别。 默认情况下，新的记录器具有NOTSET级别，并且由于根记录器具有WARN级别，记录器的有效级别将为WARN。所以即使新的记录器附加了一些处理程序，这些处理程序也不会被调用，除非日志级别超过WARN：

toto_logger = logging.getLogger("toto")
assert toto_logger.level == logging.NOTSET # new logger has NOTSET level
assert toto_logger.getEffectiveLevel() == logging.WARN # and its effective level is the root logger level, i.e. WARN

# attach a console handler to toto_logger
console_handler = logging.StreamHandler()
toto_logger.addHandler(console_handler)
toto_logger.debug("debug") # nothing is displayed as the log level DEBUG is smaller than toto effective level
toto_logger.setLevel(logging.DEBUG)
toto_logger.debug("debug message") # now you should see "debug message" on screen

默认情况下，记录器级别将用于决定日志传递：如果日志级别低于记录器级别，则日志将被忽略。

Python日志记录最佳实践

日志记录模块确实非常方便，但它包含一些怪癖，即使是最好的Python开发人员也可能导致长时间的头痛。以下是我认为使用此模块的最佳实践：

• 配置根记录器，但从不在代码中使用它 - 例如，从不调用像这样的函数 logging.info()，实际上它会调用场景后面的根记录器。如果您想从您使用的库中捕获错误消息，请确保将根记录器配置为写入文件，例如，以使调试更容易。默认情况下，根记录器只输出到stderr，所以日志很容易丢失。
• 要使用日志记录，请确保使用创建新的日志记录器logging.getLogger(logger name)。我通常 __name__用作记录器名称，但只要一致，任何东西都可以使用。要添加更多的处理程序，我通常会有一个返回记录器的方法（可以在https://gist.github.com/nguyenkims/e92df0f8bd49973f0c94bddf36ed7fd0中找到要点）。

import logging
import sys
from logging.handlers import TimedRotatingFileHandler
FORMATTER = logging.Formatter("%(asctime)s — %(name)s — %(levelname)s — %(message)s")
LOG_FILE = "my_app.log"

def get_console_handler():
   console_handler = logging.StreamHandler(sys.stdout)
   console_handler.setFormatter(FORMATTER)
   return console_handler
def get_file_handler():
   file_handler = TimedRotatingFileHandler(LOG_FILE, when='midnight')
   file_handler.setFormatter(FORMATTER)
   return file_handler
def get_logger(logger_name):
   logger = logging.getLogger(logger_name)
   logger.setLevel(logging.DEBUG) # better to have too much log than not enough
   logger.addHandler(get_console_handler())
   logger.addHandler(get_file_handler())
   # with this pattern, it's rarely necessary to propagate the error up to parent
   logger.propagate = False
   return logger

之后可以创建新的记录器并使用它：

my_logger = get_logger("my module name")
my_logger.debug("a debug message")

• 使用RotatingFileHandler类（如本例中使用的TimedRotatingFileHandler而不是FileHandler），因为它会在文件达到大小限制时自动为您旋转文件，或者每天都执行该操作。
• 使用Sentry，Airbrake，Raygun等工具自动为您捕捉错误日志。这在Web应用程序的上下文中特别有用，在该应用程序中，日志可能非常冗长，并且错误日志可能很容易丢失。使用这些工具的另一个优点是，您可以获取有关错误中变量值的详细信息，以便您知道哪些URL会触发错误，哪位用户担心等等。

如果您对更多最佳实践感兴趣，请阅读由Toptaler Martin Chikilian撰写的Python开发人员制作的10个最常见错误。

理解基础知识

什么是调试工具？

调试工具是一种工具，它允许开发人员发现错误并调查问题。它可以是一个命令行工具，如gdb，pdb（用于Python）或可以嵌入IDE（Visual Studio， idea suites等）

什么是调试日志？

这仅仅是该计划的输出，是通俗的说法中的“印刷版”的更好版本。在Web应用程序的上下文中，该日志通常包含传入的请求信息，例如请求路径，请求时间，HTTP状态等。

什么是Python中的“日志记录”？

日志记录是Python标准库中的一个模块，它提供了一个带有灵活过滤器的格式丰富的日志，并且可以将日志重定向到其他源，如系统日志或电子邮件。

什么是Python调试器？

最流行的python调试器是pdb。目前有一些项目通过提供制表符完成，颜色语法，代码浏览或远程调试来改善pdb的可用性。这些项目包括ipdb，pudb和wdb。还有一些IDE特定的调试器，如pydev引擎或PTVS。

关于作者

Son 对软件工程和ML算法非常熟练，并且总是尽力用简单而高效的方法解决问题，从而使代码长期可维护。作为一名企业家，他致力于他的工作，充分理解责任和主动性的重要性。他可以与商业和技术双方高效沟通。