Python 日志过滤器如何避免污染上下文：Filter 与 LogRecord 的边界

Python 日志里最容易被忽略的一类问题，是同一条 LogRecord 经过多个 handler 时，前一个过滤器改过的字段被后一个输出端看见了。结果往往不是“日志没打印”，而是控制台、文件和告警通道显示了彼此不该拥有的上下文。处理这类问题的关键，是把“是否放行”和“是否修改记录”分开，并在需要不同字段时复制记录。

如果多个 handler 需要不同的日志上下文，不要在共享的原始 LogRecord 上直接追加字段；先让过滤器只做放行判断，确实要改字段时复制一份记录再交给当前 handler。

先用两个输出端复现字段串扰

假设服务同时把日志写到终端和审计文件。终端需要简短上下文，文件则需要完整的 request_id。如果过滤器直接执行 record.request_id = ...，那么字段会留在同一个对象上，后续 handler 可能无意中复用它。

import logging

logger = logging.getLogger("checkout")
logger.setLevel(logging.INFO)

console = logging.StreamHandler()
console.setFormatter(logging.Formatter("console: %(message)s %(request_id)s"))

audit = logging.FileHandler("audit.log", encoding="utf-8")
audit.setFormatter(logging.Formatter("audit: %(message)s %(request_id)s"))

class AddRequestId(logging.Filter):
    def filter(self, record):
        record.request_id = "req-7f31"
        return True

console.addFilter(AddRequestId())
logger.addHandler(console)
logger.addHandler(audit)
logger.info("payment accepted")

这段代码还有一个更直接的问题：audit 的格式器也读取 request_id，但字段并不是在创建记录时统一注入的。不同 handler 的过滤器执行顺序和挂载位置，会决定它是否碰巧拿到这个字段。先别急着把过滤器移动到 logger 上，下一步要确认对象到底经过了哪一层。

过滤器挂载位置决定你检查什么

挂在 logger 上的过滤器，会在记录交给 handler 之前参与判断；挂在 handler 上的过滤器，则只影响这个 handler 是否处理当前记录。handler 过滤器适合做“审计文件只收某类事件”这类局部筛选，但不适合无条件修改共享记录。

可以给每个输出端加一个只读检查过滤器，记录对象身份和字段是否存在：

class Inspect(logging.Filter):
    def __init__(self, label):
        super().__init__()
        self.label = label

    def filter(self, record):
        print(self.label, id(record), getattr(record, "request_id", None))
        return True

console.addFilter(Inspect("console"))
audit.addFilter(Inspect("audit"))

如果两行输出里的 id(record) 相同，这是正常的：多个 handler 通常处理的是同一个 LogRecord。真正需要关注的是，某个 handler 的检查是否看到了另一个 handler 注入的字段。这个证据比单看最终文本可靠。

只筛选不改写时，Filter 应该保持简单

如果需求只是让审计文件接收 WARNING 以上日志，过滤器只返回布尔值即可。格式器需要的字段应该在创建日志记录时统一提供，或者通过 LoggerAdapter 在调用边界注入，而不是由某一个输出端“顺手补上”。

class WarningOnly(logging.Filter):
    def filter(self, record):
        return record.levelno >= logging.WARNING

audit.addFilter(WarningOnly())
logger.warning("inventory is low", extra={"request_id": "req-7f31"})

这里的核对点有两个：低于 WARNING 的记录不会写入审计端；进入格式器的 request_id 来自调用方的 extra，而不是某个 handler 的副作用。若业务上所有日志都需要该字段，应在 logger 的统一入口校验缺失字段，而不是让不同输出端各自猜。

需要局部改字段时复制 LogRecord

有些场景确实要求不同 handler 输出不同字段，例如终端隐藏内部用户标识，审计文件保留脱敏后的标识。此时可以在当前 handler 的过滤器里复制记录，再返回副本。Python 文档允许过滤器返回 LogRecord；handler 使用返回的新对象，原记录保持不变。

import copy

class WithChannel(logging.Filter):
    def __init__(self, channel):
        super().__init__()
        self.channel = channel

    def filter(self, record):
        local = copy.copy(record)
        local.channel = self.channel
        return local

console.addFilter(WithChannel("terminal"))
audit.addFilter(WithChannel("audit"))

logger.info("payment accepted")

这次两个 handler 可以得到各自的 channel，而不会把终端的值写回原记录。复制是浅拷贝，像字符串、数字这类字段通常足够；如果还要修改记录里的可变字典或列表，必须继续复制这些嵌套对象，否则外层对象分开了，内部数据仍可能共享。

用反向验证确认修复没有留下隐患

修复后不要只看输出长什么样，至少做三项反向验证：两个 handler 的字段值不同；原始记录没有出现局部字段；当过滤器返回 False 时，目标 handler 不再输出。

class Capture(logging.Handler):
    def __init__(self):
        super().__init__()
        self.records = []

    def emit(self, record):
        self.records.append(record)

capture = Capture()
capture.addFilter(WithChannel("test"))
logger.addHandler(capture)
logger.info("health check")

assert capture.records[0].channel == "test"
assert getattr(capture.records[0], "request_id", None) is None

测试时也要覆盖没有 extra 的普通调用。格式器如果假定字段一定存在，会抛出 ValueError: Formatting field not found，这不是过滤器本身的放行问题，而是记录字段契约没有定义清楚。

把这类问题收进排查清单

• 先列出 logger、handler 和每个过滤器的挂载位置。
• 用 id(record) 与字段快照确认是否是同一条 LogRecord。
• 只筛选时返回布尔值，不在共享记录上追加字段。
• 必须局部改写时使用浅拷贝，并检查嵌套可变对象。
• 让测试覆盖缺字段、低级别日志和多个 handler 同时处理。

常见问题

Filter 能不能直接修改 LogRecord？

可以，但要确认这个记录不会被其他 handler 依赖，或者明确接受所有输出端共享该修改。多个输出端需要不同上下文时，应返回副本。

为什么过滤器返回 True 仍然可能没有日志？

还要检查 logger 和 handler 的级别、传播设置以及格式器字段。Filter 只负责自己的过滤结果，不会绕过其他级别门槛。

LoggerAdapter 能替代 handler 过滤器吗？

如果字段属于调用方上下文，LoggerAdapter 通常更合适；如果字段只服务某个输出端，handler 过滤器更局部，但需要避免修改共享记录。

把日志问题拆成“放不放行”和“输出端要不要改字段”两件事，排查会清楚很多。先用证据确认共享对象，再决定统一注入、局部复制或只做筛选，通常比继续调整过滤器执行顺序更稳。