生产日志里出现一行:Error: KeyError: 'user_id'。没有堆栈、没有请求 ID、没有上游调用信息。排查时只能猜:这个 'user_id' 是从哪个 dict 取的?哪条请求触发的?于是加日志、重新部署、等再次出现——而它三天才出现一次。
错误信息看不全,通常不是"日志级别不够",而是异常被吞掉再抛出的过程中丢了上下文。
这层丢失有个常见的连锁后果:同一个根因在不同层被包装成不同异常,最终在日志里表现为"多个不相关的错误"。于是排查从"找一个根因"变成"逐个解释五个现象"。
而 Python 的异常链(__cause__ / __context__)本来就是为了携带这层信息存在,只是默认输出里它被折叠了。
1. 异常信息的三层
| 层 | 内容 |
|---|---|
| 类型与消息 | KeyError: 'user_id' |
| 堆栈 | 出错的调用路径 |
| 链 | 这个异常由哪个异常引起 |
第三层最常被丢掉:raise NewError(...) from e 会保留链,而 raise NewError(...) 在异常处理块中会隐式设置 __context__——但如果日志只打印 str(e),三层全部丢失。
所以第一个问题不是"日志记多少",而是**"记录的方式会不会把链打出来"**。
2. 三种抛出方式的信息量
| 写法 | 保留的信息 |
|---|---|
raise NewError("x") |
类型+消息(在 except 内有隐式 context) |
raise NewError("x") from e |
显式链(cause) |
raise NewError("x") from None |
主动切断链 |
from e 还有一个"因果方向"的作用:它声明"新异常由旧异常引起",而不是"在旧异常之后又发生了新异常"。这个区别在日志里体现为 direct cause 与 during handling 两种措辞。
第二种是默认该用的:它把"为什么失败"与"怎么失败的"连起来。日志里会出现 The above exception was the direct cause of...。
第三种有正当用途:把内部实现细节对使用者隐藏(如库的公开 API),但此时应当保留一条内部日志,否则排查时完全没有线索。
// 三种写法的差别
try:
cfg["db"]["host"]
except KeyError as e:
raise ConfigError("数据库配置缺失") from e # 保留链:能看到是 host 缺
# raise ConfigError("数据库配置缺失") # 隐式 context,也会打出来
# raise ConfigError("数据库配置缺失") from None # 切断链,日志里只剩一句
3. 日志该怎么记录异常
| 方式 | 输出 |
|---|---|
log.error(str(e)) |
只有消息 |
log.error("%s", e) |
只有消息 |
log.exception("...") |
消息 + 完整堆栈(在 except 内) |
log.error("...", exc_info=e) |
消息 + 指定异常的堆栈 |
log.error("...", exc_info=True) |
消息 + 当前异常的堆栈 |
第二项("%s", e)看起来无害,实际与 str(e) 等价:日志的消息部分是格式化后的字符串,堆栈并没有被记录,只是"看起来用了异常对象"。
第三项最常用,但有个前提:必须在 except 块内调用。在块外调用时 exc_info=True 拿不到异常,只打一行消息——这类"日志没堆栈"的问题,多数源于此。
第一项与第二项在结构化日志里更糟:它们把异常压成一个字符串,于是无法按异常类型过滤、无法聚合。
// 结构化日志:异常作为字段,而不是拼进消息
try:
handle(req)
except Exception:
log.error("request_failed", exc_info=True,
extra={"path": req.path, "uid": req.uid, "trace_id": req.trace_id})
// 效果:日志里有 error.type、error.stack、error.message 三个独立字段
4. 上下文该带什么
| 字段 | 用途 |
|---|---|
| trace_id | 串起一次请求的所有日志 |
| 关键业务 ID | 定位到具体对象 |
| 失败的操作名 | 知道哪一步 |
| 输入的关键参数 | 复现条件 |
第四项要谨慎:参数可能包含敏感信息,应当只记"参与判断的那几个字段",而不是整个对象。
第四项(输入的关键参数)还有一个"最小化"原则:只记"参与判断的字段"。比如余额校验失败,记"账户 ID + 请求金额 + 当时余额"三个数就够了,不需要整个账户对象。
第一项是必需项:没有 trace_id 的日志在分布式系统里几乎无法串起来,而它通常由框架注入,异常日志最容易漏掉它——因为异常处理路径常常绕过了正常的请求上下文。
// 用 contextvars 让 trace_id 自动进入每条日志
import contextvars, logging
trace_id: contextvars.ContextVar[str] = contextvars.ContextVar("trace_id", default="-")
class TraceFilter(logging.Filter):
def filter(self, record):
record.trace_id = trace_id.get()
return True
// 之后任何 log.error 都自带 trace_id,不必逐处传参
异常日志还有一个"位置"问题:在哪一层记录决定了堆栈的深度。在底层记录会得到"最原始的位置",但看不到这次失败整体属于哪个业务动作;在顶层记录能看到业务上下文,但栈里已经叠了几层包装。所以常见做法是"顶层记一次,底层只加字段"。
// 分层记录:底层加字段,顶层记异常
def fetch(uid):
try:
return repo.get(uid)
except DBError as e:
e.add_note(f"fetch user uid={uid}") # 3.11+:给异常加注记,不记录
raise # 原样抛出,由顶层记录
// 顶层
except Exception:
log.error("fetch_user_failed", exc_info=True) # 唯一一处记录
5. 异常聚合:从"很多行"到"一个问题"
| 手段 | 效果 |
|---|---|
| 按异常类型 + 位置聚合 | 一个错误一行 |
| 按消息模板聚合(去参数) | 合并同类 |
| 采样(保留首末与抽样) | 控制量 |
| 首见/末见时间 | 判断是否持续 |
第二项的前提是消息要模板化:f"用户 {uid} 不存在" 每次都不同,无法聚合;而 "user_not_found" 加 uid 字段可以。
第四项是判断"是否还在发生"的关键:没有首末见时间,就无法回答"现在还有吗",而这正是值班最关心的问题。
还有一个"异常与返回值"的边界问题:不是所有失败都该用异常。批量处理里"第 37 行校验失败"是正常输出的一部分,用异常表达会让整批失败;用结果对象逐项记录,才是可聚合的。
// 批量:逐项结果,而不是抛出
results = []
for i, row in enumerate(rows, 1):
try:
save(row); results.append({"line": i, "ok": True})
except ValidationError as e:
results.append({"line": i, "ok": False, "error": e.code, "field": e.field})
// 日志里只记一行汇总:ok=97 fail=3 codes={required:2,range:1}
// 明细进结果对象,不进日志(否则日志被批量明细淹没)
6. 排错:五种"日志里看不出原因"
| 现象 | 成因 | 处理方向 |
|---|---|---|
| 只有一行消息 | 用了 str(e) |
改 exc_info |
| 有堆栈但没有 trace_id | 异常路径绕过上下文 | 用 filter 注入 |
| 同一种错误成千上万行 | 消息带参数无法聚合 | 消息模板化 |
| 看不到上游原因 | from None 切断链 |
保留链或补内部日志 |
| 复现不了 | 缺关键输入 | 记参与判断的字段 |
第五项(缺关键输入)在"校验失败"类错误里最普遍:日志只写"字段非法",不写非法值是什么,于是只能猜用户到底提交了什么。这类日志的信息量接近零。
第四项不是"永远不能切断":对外的错误信息应当干净,但对内的日志必须有链。这是两个不同的输出,不该用同一个字符串。
7. 边界:什么情况不必追异常链
| 场景 | 为什么 | 做法 |
|---|---|---|
| 明确的业务校验失败 | 原因已知 | 一行消息即可 |
| 批量任务的逐项失败 | 用结果对象而非异常 | 记结构 |
| 短期脚本 | 不长期 | 随意 |
| 已在上层统一记录 | 避免重复 | 下层不记 |
第四项与"每层都 log.exception"是同一个问题的两面:同一次失败产生四条日志,排查时无法判断是一个问题还是四个。约定是"只在最外层记录一次"。
最后一条与"成本"有关的边界:堆栈不是免费的——它包含代码路径与参数快照,量大的时候会显著增加日志体积。所以"所有日志都带堆栈"不可行,正确的做法是"错误带堆栈、信息级不带"。
判断口径一句话:这条日志能不能让另一个人在不知道上下文的情况下复现。能,够了;不能,就要补字段或补链。
8. 自测
- 异常信息的三层分别是什么?哪一层最常被丢掉?
from e与from None各适用什么场景?为什么切断链时要补内部日志?log.exception为什么必须在 except 块内调用?块外调用会发生什么?- 为什么"把异常压成字符串"在结构化日志里更糟?
- 消息模板化为什么是异常聚合的前提?没有"首见/末见时间"会缺什么能力?
- 判断"日志是否足够"的那个问题是什么?