Python 日志级别已关闭：debug 没有输出，昂贵函数为什么仍然被调用
服务把日志级别设为 WARNING，调试输出已经消失，生成大型诊断摘要的函数却仍然运行。代码写的是 logger.debug("summary=%s", build_summary())，看起来采用了延迟格式化。问题在于，延迟的是日志文字的格式化，而 build_summary() 必须先执行，函数调用才能把返回值作为实参传给 debug。
下面不使用计时排名，而用明确计数器观察究竟发生了什么。保存为 demo.py 后运行 python demo.py。示例把日志写入内存字符串，并关闭向父日志器传播，避免终端配置或其他处理器影响验证结果。
关闭输出不能撤销已经求值的参数
AI概念示意图：输出扬声器安静下来，前置准备齿轮仍在转动，级别门控制另一份准备动作。图片不是运行截图。
import io
import logging
counts = {"build": 0, "str": 0}
stream = io.StringIO()
logger = logging.getLogger("tutorial.argument-evaluation")
logger.handlers.clear()
logger.propagate = False
handler = logging.StreamHandler(stream)
handler.setFormatter(logging.Formatter("%(message)s"))
logger.addHandler(handler)
logger.setLevel(logging.WARNING)
def build_summary():
counts["build"] += 1
return "payload"
class Probe:
def __str__(self):
counts["str"] += 1
return "probe"
probe = Probe()
logger.debug("summary=%s", build_summary())
assert counts["build"] == 1 and stream.getvalue() == ""
if logger.isEnabledFor(logging.DEBUG):
logger.debug("summary=%s", build_summary())
assert counts["build"] == 1
logger.debug("object=%s", probe)
assert counts["str"] == 0
logger.debug(f"object={probe}")
assert counts["str"] == 1 and stream.getvalue() == ""
print("disabled counts:", counts)
logger.setLevel(logging.DEBUG)
if logger.isEnabledFor(logging.DEBUG):
logger.debug("summary=%s", build_summary())
logger.debug("object=%s", probe)
assert counts == {"build": 2, "str": 2}
assert stream.getvalue().splitlines() == ["summary=payload", "object=probe"]
print("enabled counts:", counts)
print("log lines:", stream.getvalue().splitlines())
logger.removeHandler(handler)
handler.close()第一条 debug 被级别过滤，没有进入内存日志，但 build 的计数已经变成一。因为 Python 在调用方法前先计算实参，这个行为不依赖最终有无输出。若函数访问数据库、扫描目录或修改状态，关闭日志同样不会自动阻止这些动作。
修复把 isEnabledFor(DEBUG) 放在昂贵调用之前。WARNING 级别下条件为假，第二段代码没有再次生成摘要，计数仍为一。这个判断适合只为诊断而准备的数据；如果函数还承担业务计算，不能为了省日志开销把必要业务行为一起藏进条件分支。
传对象与先转字符串不是同一步
Probe 对象的 __str__ 会增加另一个计数。直接把现有对象作为 %s 参数交给被关闭的日志调用，没有触发它的字符串转换。换成 f-string 后，字符串必须在 debug 调用之前形成，因此 __str__ 立即执行，计数变成一，即使那条日志仍然没有输出。
这种对照说明，占位符写法能推迟格式化，但不能推迟你已经写在参数位置的函数调用。把 build_summary() 改成 str(build_summary()) 或放入 f-string 都不会解决问题。需要先分析成本发生在哪一步，再选择延迟构造、级别判断或复用现成数据。
重新启用后验证内容，而不只验证次数
示例将级别改为 DEBUG，再次通过判断生成摘要，build 计数变成二。随后输出 Probe，字符串转换次数也变成二。内存日志恰好有 summary=payload 和 object=probe 两行，既确认关闭时没有写出，也确认启用后仍然保留诊断内容。
isEnabledFor 反映日志器是否会为该级别接受事件，不保证某个处理器最终一定写出。处理器自己的级别、过滤器和输出配置仍可能进一步丢弃记录。因此不要用这个结果证明日志已经送到文件或远端，更不要把日志的持久化成功当成业务事务已经完成。
先用最小副作用样本定位成本来源
调试真实系统时，可以先将昂贵函数替换为只计数的测试替身，分别测关闭级别、启用级别以及格式化对象的调用次数。确认原因后再用代表性数据测性能，避免把磁盘写入、字符串构造和上游查询的时间混在一起，得出一个无法解释的总耗时。
日志配置若会在运行时改变，不宜长期缓存一次级别判断后永不更新。本例每次都读取当前有效状态，便于看清切换行为。诊断函数也应尽量没有业务副作用，并避免为了打印摘要收集不必要的敏感内容；这与是否使用占位符是需要分别处理的问题。
资料核对日期：2026年10月2日（北京时间）。代码在 CPython 3.12.14 中独立运行。
