Python禁用日志记录会导致脚本变慢

Question

我在我的脚本中使用内置的Python“logging”模块。当我将详细程度调整为“info”时，似乎我的“debug”消息会显著减慢脚本运行速度。

我的一些“debug”消息打印大型字典，我猜测Python会在意识到“debug”消息被禁用之前先展开文本。例如：

import pprint
pp = pprint.PrettyPrinter(indent=4)
logger.debug(f"Large Dict Object: {pp.pformat(obj)}")

我该如何提升性能？我希望继续使用Python内置的日志记录模块，但需要找出一个“干净”的方法来解决这个问题。

- user1334858

Answer 1

已经存在与 dankal444 提到的功能相关的日志记录特性，这个特性稍微更为整洁。具体信息请参考 日志记录文档。

if logger.isEnabledFor(logging.DEBUG):
    logger.debug(f"Large Dict Object: {pp.pformat(obj)}")

另一种可能的方法是使用百分号格式化（%-formatting），只有在实际需要时才进行格式化（日志事件必须由处理程序和记录器一起处理才能到达该点）。我知道f-strings是新近流行的且性能良好，但这完全取决于具体情况，哪种方法能提供最佳结果。

利用惰性百分号格式化的示例：

class DeferredFormatHelper:
    def __init__(self, func, *args, *kwargs):
        self.func = func  # assumed to return a string
        self.args = args
        self.kwargs = kwargs

    def __str__(self):
        # This is called because the format string contains
        # a %s for this logging argument, lazily if and when
        # the formatting needs to happen
        return self.func(*self.args, **self.kwargs)

if logger.isEnabledFor(logging.DEBUG):
    arg = DeferredFormatHelper(pp.pformat, obj)
    logger.debug('Large Dict Object: %s', arg)

- Vinay Sajip

---

它更懒惰，因为如果需要的话，百分号格式化会在日志调用之后一段时间应用。即使由于记录器或处理程序级别或过滤器阻止它而消息从未传递出去，f-string格式化也会在日志调用之前发生。 - Vinay Sajip

我在谈论例如 logger.debug('foo %i', n) 这样的代码 - 注意微妙的差别。 - Vinay Sajip

那个“Deferred”东西在那个“if”保护下是否有意义？如果你到达那里，似乎你一定会记录它。 - Kelly Bundy

这是有道理的。你会进行日志记录调用，但这并不一定意味着它会被输出。你看过所有的文档了吗？ - Vinay Sajip

所以即使 logger.isEnabledFor(logging.DEBUG) 为真，logger.debug 可能不会记录日志吗？文档似乎表明后者确实意味着 logger.debug 会记录日志（尽管不，抱歉，该页面很长，我没有全部阅读）。 - Kelly Bundy

Answer 2

检查当前级别是否足够好：

if logger.getEffectiveLevel() <= logging.DEBUG:
    logger.debug(f"Large Dict Object: {pp.pformact(obj)}")
    

这不是非常干净的代码，但是我能想到的最好的方法。如果性能瓶颈，请使用此方法。

- dankal444

Answer 3

我无法确定您的瓶颈在哪里，但如果是由于pprint库，那么您的记录器将永远没有机会对其进行任何处理。需要重写以澄清。

from pprint import PrettyPrinter
import logging

logger = logging.getLogger()

large_object = {"very": "large container"}
pp = PrettyPrinter(indent=4)

# This is done first.
formatted_msg = pp.pformat(large_object)
# It's already formatted when it's sent to your logger.
logger.debug(f"Large dict object: {formatted_msg}")

- Kristoffer Ottosson