structlog处理器顺序问题解析：如何正确配置异常日志记录

问题背景

在使用Python日志库structlog时，开发者经常会遇到需要记录异常信息的需求。structlog提供了format_exc_info处理器来格式化异常信息，但如果不注意处理器的配置顺序，可能会导致程序报错。

典型错误场景

一个常见的错误配置如下：

import structlog

structlog.configure(
    processors=[
        structlog.processors.add_log_level,
        structlog.processors.JSONRenderer(),  # 渲染器位置错误
        structlog.processors.format_exc_info,  # 异常处理器
    ]
)

这种配置会导致在调用log.info()时就抛出AttributeError: 'str' object has no attribute 'pop'异常，因为处理器顺序不正确。

问题根源

这个错误的核心原因在于处理器的执行顺序。structlog的处理器是按照配置列表顺序依次执行的：

1. add_log_level处理器正常执行，添加日志级别信息
2. 然后立即执行JSONRenderer()，将日志事件转换为JSON字符串
3. 当轮到format_exc_info处理器时，它期望处理的是一个字典对象，但实际得到的是已经被渲染为字符串的结果

正确配置方式

正确的处理器顺序应该是：

structlog.configure(
    processors=[
        structlog.processors.add_log_level,
        structlog.processors.format_exc_info,  # 先处理异常信息
        structlog.processors.JSONRenderer(),   # 最后才渲染
    ]
)

处理器顺序的重要性

structlog的处理流程可以理解为一条流水线，每个处理器都对日志事件进行特定处理，然后将结果传递给下一个处理器。因此处理器的顺序至关重要：

1. 信息添加处理器：如add_log_level、add_logger_name等，应该在最前面
2. 异常处理处理器：如format_exc_info，需要在渲染前执行
3. 渲染处理器：如JSONRenderer、KeyValueRenderer等，应该放在最后

最佳实践建议

1. 始终将渲染器放在处理器列表的最后
2. 异常处理器应该在渲染器之前
3. 信息添加类处理器通常放在最前面
4. 如果需要添加时间戳，可以使用TimeStamper处理器，通常也放在较前位置

完整示例代码

import structlog

# 正确配置的处理器顺序
structlog.configure(
    processors=[
        structlog.processors.add_log_level,
        structlog.processors.TimeStamper(fmt="iso"),
        structlog.processors.format_exc_info,
        structlog.processors.JSONRenderer(),
    ]
)

log = structlog.stdlib.get_logger()

try:
    result = 1 / 0
except Exception:
    log.exception("计算失败")  # 将正确记录异常堆栈

通过遵循正确的处理器顺序，可以确保structlog能够正确处理异常信息并生成预期的日志输出。