如何在Python 3中使用日志记录

介绍

logging 模块是标准 Python 库的一部分,用于跟踪软件运行时发生的事件。您可以向您的代码添加日志调用以指示发生了哪些事件。

logging 模块允许进行诊断日志记录,记录与应用程序操作相关的事件,以及进行审计日志记录,记录用户交易的事件以供分析。它特别用于将事件记录到文件中。

先决条件

您应该已安装 Python 3,并在您的计算机或服务器上设置好编程环境。如果您尚未设置编程环境,您可以参考适用于您操作系统(Ubuntu、CentOS、Debian 等)的 本地编程环境 或 服务器上的编程环境 的安装和设置指南。

为什么使用 logging 模块

logging 模块记录程序中发生的事件,使得能够查看与软件运行期间发生的任何事件相关的输出成为可能。

您可能更熟悉通过在代码中使用 print() 语句来检查事件是否发生。 print() 语句提供了一种基本的方法来调试代码以解决问题。虽然在代码中嵌入 print() 语句可以追踪执行流程和程序的当前状态,但与使用 logging 模块相比,这种解决方案的可维护性较差,原因如下:

  • 很难区分调试输出和正常程序输出,因为两者混合在一起
  • 在代码中分散使用 print() 语句时,没有有效的方法来禁用提供调试输出的语句
  • 当完成调试时,删除所有 print() 语句变得困难
  • 没有包含即时可用诊断信息的日志记录

养成在代码中使用 logging 模块的习惯是一个好主意,因为这对于超出小型 Python 脚本的应用程序更为合适,并提供了一种可持续的调试方法。

因为日志可以显示一段时间内的行为和错误,它们也可以为您提供更好的整体图片,了解应用程序开发过程中正在发生的情况。

将调试消息打印到控制台

信息: 要跟随本教程中的示例代码,请在本地系统上打开 Python 交互式 shell,运行 python3 命令。然后,您可以通过在 >>> 提示后添加示例代码来复制、粘贴或编辑示例。

如果您习惯使用 print() 语句查看程序中发生的情况,您可能已经习惯于看到一个定义了类并实例化对象的程序,生成类似于这样的内容:

pizza.py
class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        print("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        print("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        print("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("artichoke", 15)
pizza_01.make()
pizza_01.eat()

pizza_02 = Pizza("margherita", 12)
pizza_02.make(2)
pizza_02.eat()

上面的代码有一个 __init__ 方法来定义 Pizza 类的 nameprice。然后有两个方法,一个叫做 make() 用于制作披萨,另一个叫做 eat() 用于吃披萨。这两个方法接受参数 quantity,初始化为 1

现在让我们运行程序:

  1. python pizza.py

我们将收到以下输出:

Output
Pizza created: artichoke ($15) Made 1 artichoke pizza(s) Ate 1 pizza(s) Pizza created: margherita ($12) Made 2 margherita pizza(s) Ate 1 pizza(s)

虽然 print() 语句允许我们查看代码是否工作,但我们可以改用 logging 模块来实现这一点。

让我们在整个代码中删除或注释掉 print() 语句,并在文件顶部添加 import logging

pizza.py
import logging


class Pizza():
    def __init__(self, name, value):
        self.name = name
        self.value = value
...

logging 模块的 默认级别WARNING,这是一个高于 DEBUG 的级别。由于我们在这个示例中将使用 logging 模块进行调试,我们需要修改配置,以便将 logging.DEBUG 级别的信息返回到控制台。我们可以在 导入语句 下面添加以下行来实现:

pizza.py
import logging

logging.basicConfig(level=logging.DEBUG)


class Pizza():
...

logging.DEBUG 这个级别是一个常量整数值,我们在上面的代码中引用它来设置一个阈值。 DEBUG 级别是 10。

现在,我们将所有的 print() 语句替换为 logging.debug() 语句。与 DEBUG 是一个常量不同,logging.debug()logging 模块的一个方法。在使用这个方法时,我们可以使用相同的 字符串,如下所示:

pizza.py
import logging

logging.basicConfig(level=logging.DEBUG)


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("artichoke", 15)
pizza_01.make()
pizza_01.eat()

pizza_02 = Pizza("margherita", 12)
pizza_02.make(2)
pizza_02.eat()

到此为止,当我们用 python pizza.py 命令运行程序时,将会收到这样的输出:

Output
DEBUG:root:Pizza created: artichoke ($15) DEBUG:root:Made 1 artichoke pizza(s) DEBUG:root:Ate 1 pizza(s) DEBUG:root:Pizza created: margherita ($12) DEBUG:root:Made 2 margherita pizza(s) DEBUG:root:Ate 1 pizza(s)

日志消息的严重程度为DEBUG,并且其中嵌入了单词root,这指的是您的Python模块的级别。logging模块可以与具有不同名称的日志记录器层次结构一起使用,因此您可以为每个模块使用不同的记录器。

例如,您可以将loggers设置为具有不同名称和不同输出的不同记录器:

logger1 = logging.getLogger("module_1")
logger2 = logging.getLogger("module_2")

logger1.debug("Module 1 debugger")
logger2.debug("Module 2 debugger")
Output
DEBUG:module_1:Module 1 debugger DEBUG:module_2:Module 2 debugger

现在我们了解了如何使用logging模块将消息打印到控制台,让我们继续使用logging模块将消息打印到文件中。

将消息记录到文件中

logging模块的主要目的是将消息记录到文件中,而不是到控制台。保留消息文件可以为您提供随时间变化的数据,您可以查阅和量化数据,以便了解需要对代码进行哪些更改。

要开始记录到文件中,我们可以修改logging.basicConfig()方法以包括一个filename参数。在这种情况下,让我们将文件名命名为test.log

pizza.py
import logging

logging.basicConfig(filename="test.log", level=logging.DEBUG)


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("artichoke", 15)
pizza_01.make()
pizza_01.eat()

pizza_02 = Pizza("margherita", 12)
pizza_02.make(2)
pizza_02.eat()

以上代码与前一部分中的代码相同,只是现在我们添加了要打印日志的文件名。一旦我们使用python pizza.py命令运行代码,我们应该在目录中有一个名为test.log的新文件。

让我们用nano(或您选择的文本编辑器)打开test.log文件:

  1. nano test.log

文件打开后,我们将会收到以下信息:

test.log
DEBUG:root:Pizza created: artichoke ($15)
DEBUG:root:Made 1 artichoke pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: margherita ($12)
DEBUG:root:Made 2 margherita pizza(s)
DEBUG:root:Ate 1 pizza(s)

这与我们在前一节中遇到的控制台输出类似,只是现在它在test.log文件中。

让我们用CTRL + x关闭文件,然后返回到pizza.py文件中,这样我们就可以修改代码了。

我们将保持大部分代码不变,但会修改两个披萨实例pizza_01pizza_02的参数:

pizza.py
import logging

logging.basicConfig(filename="test.log", level=logging.DEBUG)


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

# 修改pizza_01对象的参数
pizza_01 = Pizza("Sicilian", 18)
pizza_01.make(5)
pizza_01.eat(4)

# 修改pizza_02对象的参数
pizza_02 = Pizza("quattro formaggi", 16)
pizza_02.make(2)
pizza_02.eat(2)

有了这些更改,让我们再次用python pizza.py命令运行程序。

程序运行后,我们可以再次用nano打开test.log文件:

  1. nano test.log

当我们查看文件时,会发现添加了几行新内容,并且保留了上次程序运行时的先前行:

test.log
DEBUG:root:Pizza created: artichoke ($15)
DEBUG:root:Made 1 artichoke pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: margherita ($12)
DEBUG:root:Made 2 margherita pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: Sicilian ($18)
DEBUG:root:Made 5 Sicilian pizza(s)
DEBUG:root:Ate 4 pizza(s)
DEBUG:root:Pizza created: quattro formaggi ($16)
DEBUG:root:Made 2 quattro formaggi pizza(s)
DEBUG:root:Ate 2 pizza(s)

虽然这些信息肯定是有用的,但我们可以通过添加额外的LogRecord属性使日志更具信息性。 主要是,我们想添加一个人类可读的时间戳,告诉我们LogRecord是何时创建的。

我们可以将该属性添加到名为format的参数中,并在表中引用它,使用字符串%(asctime)s。此外,为了保留DEBUG级别名称,我们需要包含字符串%(levelname)s,并保留我们要求记录器打印出的字符串消息,我们将包含%(message)s。这些属性中的每一个将由一个colon分隔,如所添加的代码所示:

pizza.py
import logging

logging.basicConfig(
    filename="test.log",
    level=logging.DEBUG,
    format="%(asctime)s:%(levelname)s:%(message)s"
    )


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("Sicilian", 18)
pizza_01.make(5)
pizza_01.eat(4)

pizza_02 = Pizza("quattro formaggi", 16)
pizza_02.make(2)
pizza_02.eat(2)

当我们运行上面的代码,并使用python pizza.py命令添加了属性时,我们将在我们的test.log文件中添加新行,其中包括易读的时间戳以及DEBUG级别名称和传递给记录器的关联消息作为字符串。

test.log
DEBUG:root:Pizza created: Sicilian ($18)
DEBUG:root:Made 5 Sicilian pizza(s)
DEBUG:root:Ate 4 pizza(s)
DEBUG:root:Pizza created: quattro formaggi ($16)
DEBUG:root:Made 2 quattro formaggi pizza(s)
DEBUG:root:Ate 2 pizza(s)
2021-08-19 23:31:34,484:DEBUG:Pizza created: Sicilian ($18)
2021-08-19 23:31:34,484:DEBUG:Made 5 Sicilian pizza(s)
2021-08-19 23:31:34,484:DEBUG:Ate 4 pizza(s)
2021-08-19 23:31:34,484:DEBUG:Pizza created: quattro formaggi ($16)
2021-08-19 23:31:34,484:DEBUG:Made 2 quattro formaggi pizza(s)
2021-08-19 23:31:34,484:DEBUG:Ate 2 pizza(s)

根据您的需求,您可能希望在您的代码中使用其他LogRecord属性,以使您的程序文件日志与您相关。

将调试和其他消息记录到单独的文件中,为您提供了随着时间的推移对您的Python程序的全面理解,使您有机会根据程序的历史工作以及发生的事件和交易进行故障排除和修改。

日志级别表

作为开发人员,您可以通过添加严重性级别来为记录器中捕获的事件指定重要性水平。严重性级别如下表所示。

日志级别在技术上是整数(一个常量),它们都以10的增量开始,从NOTSET开始,其数值初始化为0。

您还可以相对于预定义级别定义自己的级别。如果您定义一个具有相同数值的级别,则将覆盖与该值关联的名称。

以下表格显示了各个级别名称、它们的数值、可以用于调用该级别的函数以及该级别的用途。

Level Numeric Value Function Used to
CRITICAL 50 logging.critical() Show a serious error, the program may be unable to continue running
ERROR 40 logging.error() Show a more serious problem
WARNING 30 logging.warning() Indicate something unexpected happened, or could happen
INFO 20 logging.info() Confirm that things are working as expected
DEBUG 10 logging.debug() Diagnose problems, show detailed information

logging 模块将默认级别设置为WARNING,因此默认情况下会记录WARNINGERRORCRITICAL。在上面的示例中,我们修改了配置以包含DEBUG级别,代码如下:

logging.basicConfig(level=logging.DEBUG)

您可以从官方logging文档中了解更多关于命令和使用调试器的信息。

结论

调试是任何软件开发项目的重要步骤。 logging 模块是标准 Python 库的一部分,它提供了对软件运行时发生的事件进行跟踪,并可以将这些事件输出到单独的日志文件中,以便您在代码运行时跟踪发生的情况。这为您提供了根据对程序随时间运行产生的各种事件的理解来调试代码的机会。

Source:
https://www.digitalocean.com/community/tutorials/how-to-use-logging-in-python-3