使用 Python 日志记录出现两次的日志消息

小开

最佳答案

调用 configure_logging两次(可能在 Boy的 __init__方法中) : getLogger将返回相同的对象，但是 addHandler不检查是否已经向日志记录器添加了类似的处理程序。

尝试跟踪对该方法的调用并消除其中之一。或者在 Boy的 __init__方法中设置一个初始化为 False的 logging_initialized标志，如果 logging_initialized是 True，则将 configure_logging改为不做任何事情，并在初始化日志记录器后将其设置为 True。

如果您的程序创建了几个 Boy实例，那么您必须改变处理方式，使用一个全局 configure_logging函数添加处理程序，而 Boy.configure_logging方法只初始化 self.logger属性。

解决这个问题的另一种方法是检查 logger 的 handlers 属性:

logger = logging.getLogger('my_logger')
if not logger.handlers:
# create the handlers and call logger.addHandler(logging_handler)

小开

每次从外部调用时都会添加处理程序。请在完成工作后删除处理程序:

self.logger.removeHandler(ch)

小开

我是一个 Python 新手，但是这似乎对我有用(Python 2.7)

while logger.handlers:
logger.handlers.pop()

小开

如果您看到这个问题，并且您没有添加处理程序两次，那么可以看到 abarnert 的答案给你

来自医生:

注意: 如果您将一个处理程序附加到一个日志记录器，并且它的一个或多个它可能会多次发出相同的纪录不应该需要附加一个处理程序到多个日志记录器-如果您只需将其附加到适当的日志记录器即可记录器层次结构，然后它将看到所有子代记录的所有事件只要它们的传播设置保留为 True 常见的方案是仅将处理程序附加到根日志记录器，并附加到剩下的就交给繁殖吧。

所以，如果你想在“ test”上有一个自定义的处理程序，并且你不想它的消息也进入根处理程序，答案很简单: 关闭它的 propagate标志:

logger.propagate = False

小开

如果没有安装根处理程序，则对 logging.debug()的调用调用 logging.basicConfig()。在我的测试框架中，我无法控制测试用例触发的顺序。我的初始化代码是安装第二个。默认使用我不想要的 logging.BASIC _ FORMAT。

小开

看起来，如果您输出一些东西给日志记录器(偶然) ，然后配置它，这是为时已晚。例如，在我的代码中

logging.warning("look out)"


...
ch = logging.StreamHandler(sys.stdout)
root = logging.getLogger()
root.addHandler(ch)


root.info("hello")

我会得到类似(忽略格式选项)的内容

look out
hello
hello

所有东西都写了两次。我相信这是因为对 logging.warning的第一个调用自动创建了一个新的处理程序，然后我显式地添加了另一个处理程序。当我删除意外的第一个 logging.warning呼叫时，问题就消失了。

小开

在我的情况下，我会设置 logger.propagate = False，以防止双重打印。

在下面的代码，如果你删除 logger.propagate = False然后你会看到双重打印。

import logging
from typing import Optional


_logger: Optional[logging.Logger] = None


def get_logger() -> logging.Logger:
global _logger
if _logger is None:
raise RuntimeError('get_logger call made before logger was setup!')
return _logger


def set_logger(name:str, level=logging.DEBUG) -> None:
global _logger
if _logger is not None:
raise RuntimeError('_logger is already setup!')
_logger = logging.getLogger(name)
_logger.handlers.clear()
_logger.setLevel(level)
ch = logging.StreamHandler()
ch.setLevel(level)
# warnings.filterwarnings("ignore", "(Possibly )?corrupt EXIF data", UserWarning)
ch.setFormatter(_get_formatter())
_logger.addHandler(ch)
_logger.propagate = False # otherwise root logger prints things again




def _get_formatter() -> logging.Formatter:
return logging.Formatter(
'[%(asctime)s] [%(name)s] [%(levelname)s] %(message)s')

小开

我遇到了一个奇怪的情况，控制台日志增加了一倍，而我的文件日志却没有。经过大量的挖掘，我终于明白了。

请注意，第三方软件包可以注册记录器。这是一个值得注意的问题(在某些情况下是无法避免的)。在许多情况下，第三方代码检查是否存在任何现有的根日志记录器处理程序; 如果没有，则注册一个新的控制台处理程序。

我的解决方案是在根级别注册我的控制台日志记录器:

rootLogger = logging.getLogger()  # note no text passed in--that's how we grab the root logger
if not rootLogger.handlers:
ch = logging.StreamHandler()
ch.setLevel(logging.INFO)
ch.setFormatter(logging.Formatter('%(process)s|%(levelname)s] %(message)s'))
rootLogger.addHandler(ch)

小开

在多个进程的上下文中，我都在为同一个问题而苦苦挣扎。(有关代码，请参阅我几乎一字不差地遵循的医生。)也就是说，来自任何子进程的所有日志消息都得到了复制。

我的错误是打电话给 worker_configurer(),

def worker_configurer(logging_queue):
queue_handler = logging.handlers.QueueHandler(logging_queue)
root = logging.getLogger()
root.addHandler(queue_handler)
root.setLevel(level)

都在主进程的子进程还有中(因为我也希望主进程记录内容)。这导致麻烦(在我的 Linux 机器上)的原因是，在 Linux 上，子进程通过 fork 启动，因此从主进程继承了现有的日志处理程序。也就是说，在 Linux 上 QueueHandler被注册了两次。

现在，阻止 QueueHandler在 worker_configurer()函数中注册两次并不像看起来那么简单:

像根日志记录器 root这样的日志记录器对象具有 handlers属性，但是没有文档记录。
根据我的经验，在分叉后测试 any([handler is queue_handler for handler in root.handlers])(身份)或 any([handler == queue_handler for handler in root.handlers])(相等)是否失败，即使 root.handlers似乎包含相同的 QueueHandler。(显然，前两个表达式可以缩写为 queue_handler in root.handlers，因为 in操作符检查列表的标识和相等性。)
根日志记录器会被类似 pytest 的软件包修改，所以 root.handlers和 root.hasHandlers()从一开始就不是很可靠。(毕竟，它们是全球性的国家。)

因此，干净的解决方案是从一开始就用生成代替 forking，以防止这种多处理 bug (当然，前提是您可以使用额外的内存占用)。或者使用不依赖于全局状态的 logging软件包的替代方案，而是要求你做适当的依赖注入，但是我跑题了... :)

话虽如此，我最终还是做了一个相当琐碎的检查:

def worker_configurer(logging_queue):
queue_handler = logging.handlers.QueueHandler(logging_queue)
root = logging.getLogger()


for handler in root.handlers:
if isinstance(handler, logging.handlers.QueueHandler):
return


root.addHandler(queue_handler)
root.setLevel(level)

显然，当我决定在其他地方注册第二个队列处理程序时，这将产生讨厌的副作用。

小开

如果使用任何配置进行日志记录，例如 log.conf

在. conf 文件中，可以通过在 [logger_myLogger]部分中添加这一行: propagate=0来完成

[logger_myLogger]
level=DEBUG
handlers=validate,consoleHandler
qualname=VALIDATOR
propagate=0

小开

如果您试图从父文件中创建一个日志对象，也会发生这种情况。这是主应用程序文件 test.py

import logging


# create logger
logger = logging.getLogger('simple_example')
logger.setLevel(logging.DEBUG)


# create console handler and set level to debug
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)


# create formatter
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')


# add formatter to ch
ch.setFormatter(formatter)


# add ch to logger
logger.addHandler(ch)


def my_code():
# 'application' code
logger.debug('debug message')
logger.info('info message')
logger.warning('warn message')
logger.error('error message')
logger.critical('critical message')

下面是父文件 main.py

import test


test.my_code()

此命令的输出将只打印一次

2021-09-26 11:10:20,514 - simple_example - DEBUG - debug message
2021-09-26 11:10:20,514 - simple_example - INFO - info message
2021-09-26 11:10:20,514 - simple_example - WARNING - warn message
2021-09-26 11:10:20,514 - simple_example - ERROR - error message
2021-09-26 11:10:20,514 - simple_example - CRITICAL - critical message

但是如果我们有一个父日志对象，那么它将被打印两次。例如，如果这是父文件

import test
import logging
logging.basicConfig(level=logging.DEBUG,format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')




test.my_code()

输出将是

2021-09-26 11:16:28,679 - simple_example - DEBUG - debug message
2021-09-26 11:16:28,679 - simple_example - DEBUG - debug message
2021-09-26 11:16:28,679 - simple_example - INFO - info message
2021-09-26 11:16:28,679 - simple_example - INFO - info message
2021-09-26 11:16:28,679 - simple_example - WARNING - warn message
2021-09-26 11:16:28,679 - simple_example - WARNING - warn message
2021-09-26 11:16:28,679 - simple_example - ERROR - error message
2021-09-26 11:16:28,679 - simple_example - ERROR - error message
2021-09-26 11:16:28,679 - simple_example - CRITICAL - critical message
2021-09-26 11:16:28,679 - simple_example - CRITICAL - critical message

小开

来自文件:

”记录器具有以下属性和方法。注意，Loggers 永远不应该直接实例化，而应该始终通过模块级函数 logging.getLogger (name)实例化。 对同一名称的 getLogger ()的多个调用将总是返回对同一 Logger 对象的引用”。

请确保不要使用相同的名称初始化日志记录器我建议你用 __name__作为参数名来初始化日志记录器，即:

import logging
logger = logging.getLogger(__name__)

注意: 即使您从其他具有相同名称的模块初始化日志记录器，您仍然会得到相同的日志记录器，因此调用即 logger.info('somthing')将与您初始化日志记录器类的次数一样多。

小开

如果您使用标准结构 logger = logging.getLogger('mymodule')，然后意外地错误键入 loggger作为 logging即。

logger = logging.getLogger('mymodule')


# configure your handlers


logger.info("my info message")  # won't make duplicate
logging.info("my info message")  # will make duplicate logs

然后这将导致出现重复的消息，因为对 logging的调用将创建一个新的日志记录器。

小开

我也有同样的问题。在我的情况下，这不是由于处理程序或重复的初始配置，而是一个愚蠢的输入错误。在 main.py中，我使用的是 logger对象，但在 my_tool.py中，我错误地直接调用了 logging模块，因此在从 my_tool模块调用函数之后，一切都乱套了，消息看起来是重复的。

这是密码:

main.py

import logging
import my_tool


logger_name = "cli"
logger = logging.getLogger(logger_name)


logger.info("potato")
logger.debug("potato)
my_tool.function()
logger.info("tomato")

my_tool.py

import logging
logger_name = "cli"
logger = logging.getLogger(logger_name)
# some code
logging.info("carrot")

以及结果

terminal

>> potato
>> potato
>> carrot
>> tomato
>> tomato