在python 3.9.4中，日志记录似乎无法正常工作

Question

目标：

在python项目的多个文件/模块中使用日志模块。这些日志都应该放在一个日志文件中

问题：

Python3.9.4中的日志记录模块似乎只对一个文件中的日志记录对象起作用。命名过程，即模块命名似乎不起作用

问题

在“示例”部分中，日志模块是否应该以这种方式工作？我可以理解您是否需要定义“根”或“初始”记录器（最后一个示例不是问题）。这对我来说似乎不正确。我错了吗

示例

我完全按照日志记录手册here中的代码处理代码。我使用了第一个示例“使用多模块登录”

当我剪切和粘贴代码时，代码运行没有错误。我添加了一个新文件只是为了测试，代码运行良好。请参阅下面与原始运行匹配的结果

2021-05-18 20:13:56,270 - spam_application - INFO - creating an instance of auxiliary_module.Auxiliary
2021-05-18 20:13:56,270 - spam_application.auxiliary.Auxiliary - INFO - creating an instance of Auxiliary
2021-05-18 20:13:56,270 - spam_application - INFO - created an instance of auxiliary_module.Auxiliary
2021-05-18 20:13:56,270 - spam_application - INFO - calling auxiliary_module.Auxiliary.do_something
2021-05-18 20:13:56,270 - spam_application.auxiliary.Auxiliary - INFO - doing something
2021-05-18 20:13:56,270 - spam_application.auxiliary.Auxiliary - INFO - done doing something
2021-05-18 20:13:56,270 - spam_application - INFO - finished auxiliary_module.Auxiliary.do_something
2021-05-18 20:13:56,270 - spam_application - INFO - calling auxiliary_module.some_function()
2021-05-18 20:13:56,270 - spam_application.auxiliary - INFO - received a call to "some_function"
2021-05-18 20:13:56,270 - spam_application - INFO - done with auxiliary_module.some_function()

下面是new_file.py->；中的代码

import logging

nf_logger = logging.getLogger('spam_application.new_file')

def test_logging():
    nf_logger.info('in test_logging()')

下面是使用new_file.py获得的良好结果

2021-05-18 20:13:56,270 - spam_application - INFO - creating an instance of auxiliary_module.Auxiliary
2021-05-18 20:13:56,270 - spam_application.auxiliary.Auxiliary - INFO - creating an instance of Auxiliary
2021-05-18 20:13:56,270 - spam_application - INFO - created an instance of auxiliary_module.Auxiliary
2021-05-18 20:13:56,270 - spam_application - INFO - calling auxiliary_module.Auxiliary.do_something
2021-05-18 20:13:56,270 - spam_application.auxiliary.Auxiliary - INFO - doing something
2021-05-18 20:13:56,270 - spam_application.auxiliary.Auxiliary - INFO - done doing something
2021-05-18 20:13:56,270 - spam_application - INFO - finished auxiliary_module.Auxiliary.do_something
2021-05-18 20:13:56,270 - spam_application - INFO - calling auxiliary_module.some_function()
2021-05-18 20:13:56,270 - spam_application.auxiliary - INFO - received a call to "some_function"
2021-05-18 20:13:56,270 - spam_application - INFO - done with auxiliary_module.some_function()
2021-05-18 20:13:56,270 - spam_application - INFO - before test_logging
2021-05-18 20:13:56,270 - spam_application.new_file - INFO - in test_logging()
2021-05-18 20:13:56,270 - spam_application - INFO - after test_logging

这就是奇怪的部分。如果我将辅助_module.py中的代码从module_logger = logging.getLogger('spam_application.auxiliary')替换为module_logger = logging.getLogger('__name__')，我将得到以下结果->

2021-05-18 20:20:02,233 - spam_application - INFO - creating an instance of auxiliary_module.Auxiliary
2021-05-18 20:20:02,233 - spam_application.auxiliary.Auxiliary - INFO - creating an instance of Auxiliary
2021-05-18 20:20:02,233 - spam_application - INFO - created an instance of auxiliary_module.Auxiliary
2021-05-18 20:20:02,233 - spam_application - INFO - calling auxiliary_module.Auxiliary.do_something
2021-05-18 20:20:02,233 - spam_application.auxiliary.Auxiliary - INFO - doing something
2021-05-18 20:20:02,233 - spam_application.auxiliary.Auxiliary - INFO - done doing something
2021-05-18 20:20:02,234 - spam_application - INFO - finished auxiliary_module.Auxiliary.do_something
2021-05-18 20:20:02,234 - spam_application - INFO - calling auxiliary_module.some_function()
2021-05-18 20:20:02,234 - spam_application - INFO - done with auxiliary_module.some_function()
2021-05-18 20:20:02,234 - spam_application - INFO - before test_logging
2021-05-18 20:20:02,234 - spam_application.new_file - INFO - in test_logging()
2021-05-18 20:20:02,234 - spam_application - INFO - after test_logging

我漏了这一行<date-time stamp> - spam_application.auxiliary - INFO - received a call to "some_function"

如果我用nf_logger = logging.getLogger(__name__)替换nf_logger = logging.getLogger('spam_application.new_file')，我会得到以下结果->

2021-05-18 20:23:09,820 - spam_application - INFO - creating an instance of auxiliary_module.Auxiliary
2021-05-18 20:23:09,820 - spam_application.auxiliary.Auxiliary - INFO - creating an instance of Auxiliary
2021-05-18 20:23:09,820 - spam_application - INFO - created an instance of auxiliary_module.Auxiliary
2021-05-18 20:23:09,820 - spam_application - INFO - calling auxiliary_module.Auxiliary.do_something
2021-05-18 20:23:09,820 - spam_application.auxiliary.Auxiliary - INFO - doing something
2021-05-18 20:23:09,820 - spam_application.auxiliary.Auxiliary - INFO - done doing something
2021-05-18 20:23:09,820 - spam_application - INFO - finished auxiliary_module.Auxiliary.do_something
2021-05-18 20:23:09,820 - spam_application - INFO - calling auxiliary_module.some_function()
2021-05-18 20:23:09,820 - spam_application - INFO - done with auxiliary_module.some_function()
2021-05-18 20:23:09,820 - spam_application - INFO - before test_logging
2021-05-18 20:23:09,820 - spam_application - INFO - after test_logging

我缺少日志行<datetime stamp> - spam_application - INFO - done with auxiliary_module.some_function()

如果我用logger = logging.getLogger(__name__)替换logger = logging.getLogger('spam_application')，我会得到以下结果->

2021-05-18 20:24:50,729 - __main__ - INFO - creating an instance of auxiliary_module.Auxiliary
2021-05-18 20:24:50,729 - __main__ - INFO - created an instance of auxiliary_module.Auxiliary
2021-05-18 20:24:50,729 - __main__ - INFO - calling auxiliary_module.Auxiliary.do_something
2021-05-18 20:24:50,729 - __main__ - INFO - finished auxiliary_module.Auxiliary.do_something
2021-05-18 20:24:50,729 - __main__ - INFO - calling auxiliary_module.some_function()
2021-05-18 20:24:50,729 - __main__ - INFO - done with auxiliary_module.some_function()
2021-05-18 20:24:50,729 - __main__ - INFO - before test_logging
2021-05-18 20:24:50,729 - __main__ - INFO - after test_logging

我少了5行日志。未调用类对象中的日志记录

在高级日志教程here中，一个好的约定是使用logger = logging.getLogger(__name__)。这在Python3.9.4中似乎不起作用

Answer 1

记录器存在于一个层次结构中。每个记录器都有自己的级别。根记录器的默认级别为WARNING

hierarchy的工作原理是，以点分隔的名称告诉您记录器在其中的位置。名为x.y.z的记录器可以被认为是名为z的记录器，它是y的子级，而x本身就是x的子级。默认情况下，当记录器接收到日志时，它会将日志沿层次结构向上传播到其所有父级。因此，名为'spam_application.auxiliary'的记录器正在将其日志发送到spam_application记录器。如果您将名称更改为不再是该名称的子项的名称，则日志将不会发送到该名称。但是，所有记录器都是根记录器的子级，但这对您没有帮助，因为它的默认级别是WARNING，并且高于INFO

如果模块也组织在层次结构中，__name__约定很有用，因为在这种情况下，记录器层次结构将与模块和子模块的层次结构完全匹配

该文档还提供了一个有用的图表来帮助确定何时记录日志：https://docs.python.org/3/howto/logging.html#logging-flow

Answer 2

我建议使用contextlib而不是日志模块。我个人觉得日志模块很难使用。contextlib非常简单直观，您可以将输出重定向到您指定的日志文件：

with open("log_file.log", "w") as log, contextlib.redirect_stdout(log), contextlib.redirect_stderr(log):

将其放在函数或python文件的开头，下面打印的所有内容都将重定向到日志文件，包括stdout和stderr