生产日志要带上下文:只打印错误不够
日志要能回答问题
线上问题发生时,日志如果只有 error 和一段堆栈,我能做的事情非常有限——我知道「哪里挂了」,但不知道「用户做了什么才挂的」「系统当时处在什么状态」「这个问题影响了多大范围」。这三类信息恰恰是排障时最花时间的部分。
有用日志应该服务排障问题,而不是只证明代码报错了。我判断一组日志好不好的标准很简单:假设我现在不知道 bug 是什么,只看日志能不能还原出事情经过。如果能,这日志就及格了。
这篇文章讨论的是「日志上下文」——每条日志除了消息本身,还应该带哪些结构化信息,让排障从「猜」变成「查」。
为什么堆栈不够:从「出错」到「理解出错」的差距
堆栈告诉你崩溃发生在哪一行,但它不告诉你以下这些事情:
- 请求是谁发起的:是所有用户都受影响,还是某个特定租户的数据触发了边界条件?
- 请求经过了什么路径:用户先做了 A 再做 B,还是直接调了 C?不同路径可能走不同的代码分支。
- 外部依赖当时的状态:第三方接口超时了还是正常返回了错误码?这两种情况的处理方式完全不同。
- 业务实体的关键属性:订单金额是 100 还是 100000?用户角色是普通用户还是管理员?这些属性往往是触发 bug 的关键条件。
缺少上下文的日志就像交通事故报告只写了「车停了」,没写车速、路况、信号灯状态。事后复盘的人只能对着报告发呆。
我见过不少团队在出了生产事故之后,花大量时间「还原现场」——翻代码、看 git log、问当事人、查数据库快照。如果日志本身就能回答大部分还原问题,这些时间可以省下来直接修 bug。
关键上下文:每条日志应该回答什么
日志上下文不是越多越好,而是要覆盖排障时会问到的关键问题。我把这些上下文分成六个层次:
请求标识(Request / Trace ID)
这是串起一条请求全链路日志的线索。在单体应用里,一个请求 ID 就够了;在微服务架构下,还需要 trace ID 来关联跨服务的调用链。
生成时机很关键——必须在系统边界(网关、入口中间件)生成,然后向下透传。如果每个服务各自生成,就失去了关联的意义。
// ❌ 每个 handler 内部生成,无法跨服务关联
function handleOrderCreate(req: Request) {
const localId = crypto.randomUUID()
logger.info({ localId }, 'creating order')
}
// ✅ 在入口中间件生成,注入到请求上下文
app.use((req, res, next) => {
const requestId = req.headers['x-request-id'] ?? crypto.randomUUID()
req.context = { requestId }
next()
})模块与操作名称
光有请求 ID 还不够。一条请求可能经过多个模块、多次数据库查询、多次外部调用。每条日志需要说明自己属于哪个模块、在做哪个操作,才能在大量日志里快速定位到出错的那一步。
// ❌ 看不出在做什么
{"level":"error","msg":"query failed","requestId":"abc-123"}
// ✅ 模块和操作清晰
{"level":"error","msg":"query failed","requestId":"abc-123","module":"order-service","operation":"createOrder","step":"validateInventory"}用户 / 租户标识
知道「哪个用户遇到了问题」对于判断影响范围至关重要。但这里有个前提:标识要安全。记录用户 ID、租户 ID 这类内部标识没问题,但不能记录能直接定位到个人的敏感信息(手机号、身份证号等)。
关键参数摘要
触发 bug 的往往是某些特定参数值。日志里应该记录影响业务逻辑的关键参数,但要做摘要而不是完整复制。比如,记录「订单包含 3 个 SKU,总金额 299」比记录整个订单 JSON 有用得多,而且安全得多。
外部依赖状态
现代应用几乎都依赖外部服务——支付、短信、存储、AI 接口。当这些依赖出问题时,日志需要记录:调了哪个接口、返回了什么状态码、耗时多久。区分「对方返回了 500」和「对方超时 30 秒」对排障方向的影响完全不同。
业务状态变化
有些 bug 不是单次请求的问题,而是状态机出了问题。比如订单从「已支付」变成了「待发货」,但库存没有扣减。这类问题需要在状态变化时记录日志:变更前状态、变更后状态、变化的触发条件。
案例:三个真实场景的日志对比
案例一:支付回调处理失败
用户在 App 里完成支付,但订单状态一直卡在「支付中」。客服反馈到开发,开发需要查为什么支付回调没生效。
// ❌ 只有错误,没有上下文
logger.error('payment callback processing failed', error)
// 输出:
// {"level":"error","msg":"payment callback processing failed","error":"TypeError: Cannot read property 'amount' of undefined"}
// ✅ 带完整上下文
logger.error({
requestId: ctx.requestId,
module: 'payment',
operation: 'handlePaymentCallback',
provider: 'stripe',
orderId: order.id,
userId: order.userId,
callbackStatus: req.body.status,
orderStatusBefore: order.status,
error: error.message,
stack: error.stack,
}, 'payment callback processing failed')
// 输出:
// {"level":"error","msg":"payment callback processing failed","requestId":"req-7f3a","module":"payment","operation":"handlePaymentCallback","provider":"stripe","orderId":"ord-8821","userId":"usr-4412","callbackStatus":"succeeded","orderStatusBefore":"pending_payment","error":"Cannot read property 'amount' of undefined","stack":"..."}有了上下文,排障路径很清晰:requestId 可以拉出这个请求的全部日志;orderId 和 userId 可以直接查数据库看订单状态;callbackStatus: "succeeded" 说明 Stripe 那边确实支付成功了;orderStatusBefore: "pending_payment" 确认了订单确实还没更新。接下来只需要看为什么 amount 是 undefined——很可能是订单查询那边的数据加载逻辑有 bug。
案例二:定时任务批量失败
一个每日执行的同步任务突然大面积失败,运维在凌晨收到了告警。
// ❌ 只知道失败了
logger.error('sync job failed', error)
// ✅ 带业务上下文
logger.error({
module: 'sync-service',
operation: 'dailyProductSync',
jobRunId: 'run-20260625-001',
totalItems: 15000,
successCount: 23,
failedCount: 14977,
firstError: errors[0]?.message,
firstErrorSku: errors[0]?.sku,
externalApiStatus: lastApiResponse?.status,
externalApiLatencyMs: lastApiResponse?.latencyMs,
durationMs: Date.now() - startTime,
}, 'daily product sync job failed')运维拿到这条日志就能判断:successCount: 23 说明不是全部失败,开头几条成功了;externalApiStatus 会告诉他是外部 API 从第 24 条开始返回错误,还是超时;firstErrorSku 可以直接拿去做 API 复现。不用叫醒开发就能做初步定位。
案例三:权限校验偶发失败
某个用户反馈偶尔无法访问自己创建的资源,但其他用户没问题。
// ❌ 只有结果
logger.warn('permission denied', { userId, resourceId })
// ✅ 带权限上下文
logger.warn({
requestId: ctx.requestId,
module: 'auth',
operation: 'checkResourceAccess',
userId: user.id,
userRole: user.role,
userTenantId: user.tenantId,
resourceId: resource.id,
resourceOwnerId: resource.ownerId,
resourceTenantId: resource.tenantId,
permissionRule: 'owner-or-admin',
matchedRule: 'none',
crossTenantAccess: user.tenantId !== resource.tenantId,
}, 'permission denied for resource access')看到 crossTenantAccess: true,问题就清楚了——这个用户的租户和资源的租户不一样,权限规则没有考虑跨租户场景。没有这个上下文,光看 userId 和 resourceId 根本查不出原因。
日志上下文注入的完整流程
下面是一个典型的请求生命周期里,日志上下文如何在各层逐步丰富:
这个流程的关键点有三个:
- Request ID 在入口生成,不在业务层生成。如果每个服务自己生成,日志就没法关联。
- 上下文逐层丰富,不是在一处塞所有字段。认证中间件加用户信息,业务层加操作信息,依赖调用加响应状态。
- Canonical Log 在请求结束时记录,把整条请求的关键信息汇总成一条宽事件。这条日志是排障时最先看的那条。
日志上下文的质量对比
下表对比了「没有上下文」「基础上下文」「高质量上下文」三种日志在排障能力上的差异:
| 维度 | 无上下文日志 | 基础上下文日志 | 高质量上下文日志 |
|---|---|---|---|
| 单条日志信息量 | 只有错误消息和堆栈 | 加上请求 ID 和时间戳 | 包含请求 ID、模块、操作、用户、参数摘要、依赖状态 |
| 跨服务关联 | 不可能 | 通过 trace ID 关联 | trace ID + 每层模块/操作标注 |
| 影响范围判断 | 靠猜 | 通过用户 ID 聚合 | 直接按 userId/tenantId 查询 |
| 问题复现 | 需要翻数据库 | 参数摘要提供部分线索 | 关键参数直接可用于复现 |
| 状态回溯 | 不知道变更前状态 | 知道当前状态 | 记录变更前后的状态和触发条件 |
| 排障平均时间 | 小时级,可能无法定位 | 分钟级到小时级 | 分钟级,大部分问题可直接定位 |
| 告警价值 | 只知道出错了 | 知道哪个服务出错了 | 知道什么操作在什么条件下出错 |
日志级别:不是所有失败都是 error
日志级别滥用是另一个常见问题。info、warn、error 不是随便选的,每个级别应该有明确的语义定义:
| 级别 | 语义定义 | 典型场景 | 是否触发告警 |
|---|---|---|---|
debug | 开发排障信息,生产环境默认关闭 | 函数入参出参、中间计算值 | 否 |
info | 正常业务流程的关键节点 | 请求开始/结束、状态变更、任务完成 | 否(但可聚合为指标) |
warn | 预期内的异常或降级 | 参数校验失败、重试成功、功能降级、限流 | 条件告警(频率超阈值时) |
error | 影响用户体验或数据一致性的异常 | 数据库写入失败、支付回调处理异常、关键依赖不可用 | 是 |
fatal | 系统无法继续运行 | 数据库连接池耗尽、核心配置缺失 | 是,立即通知 |
常见的错误做法:
// ❌ 参数校验失败打 error,告警风暴
if (!input.email) {
logger.error('missing email', { input })
return res.status(400).json({ error: 'email required' })
}
// ✅ 参数校验是预期内的失败,用 warn
if (!input.email) {
logger.warn('validation failed: missing email', {
requestId: ctx.requestId,
module: 'user-service',
operation: 'createUser',
validationField: 'email',
})
return res.status(400).json({ error: 'email required' })
}
// ❌ 外部超时和内部 bug 混在一起
catch (error) {
logger.error('failed to fetch user profile', error)
}
// ✅ 区分外部依赖问题与内部异常
catch (error) {
if (error instanceof TimeoutError) {
logger.warn({
module: 'user-service',
operation: 'fetchProfile',
dependency: 'profile-api',
timeoutMs: 5000,
retryAttempt: attempt,
}, 'profile api timeout, will retry')
} else {
logger.error({
requestId: ctx.requestId,
module: 'user-service',
operation: 'fetchProfile',
error: error.message,
stack: error.stack,
}, 'unexpected error fetching profile')
}
}敏感信息控制:排障需要上下文,不需要密码
日志上下文不是原始数据的搬运工。以下字段必须脱敏或摘要:
| 数据类型 | 正确做法 | 错误做法 |
|---|---|---|
| 密码 / 密钥 | 永不记录 | 记录明文或 base64 |
| Token / API Key | 只记录前 6 位 + *** | 完整记录 |
| 手机号 | 138****1234 | 13812341234 |
| 邮箱 | a***[email protected] | 完整记录 |
| 身份证 | 只记录是否通过校验 | 完整记录 |
| 请求 body | 只记录影响业务逻辑的关键字段摘要 | JSON.stringify(req.body) |
| 响应 body | 只记录状态码和关键字段 | 完整记录 |
// ❌ 原始 body 全量记录
logger.info('creating order', { body: req.body })
// ✅ 摘要记录关键字段
logger.info({
requestId: ctx.requestId,
module: 'order-service',
operation: 'createOrder',
itemCount: req.body.items?.length ?? 0,
totalAmount: req.body.totalAmount,
currency: req.body.currency,
// 不记录:收货地址、手机号、支付 token
}, 'creating order')
// Token 脱敏工具函数
function maskToken(token: string): string {
if (!token || token.length < 8) return '***'
return token.slice(0, 6) + '***'
}结构化日志格式:让日志可查询
文本日志人眼能读,但机器难处理。生产日志应该输出结构化的 JSON 格式,这样日志平台(ELK、Loki、Datadog)才能高效索引和查询。
// ❌ 文本格式,难以查询
logger.info(`Order ${orderId} created by user ${userId}, total: ${total}, items: ${itemCount}`)
// 要查某个用户的订单,需要正则匹配,慢且易错
// ✅ JSON 结构化,字段可索引
logger.info({
requestId: ctx.requestId,
module: 'order-service',
operation: 'createOrder',
orderId,
userId,
total,
itemCount,
durationMs: Date.now() - startTime,
}, 'order created')
// 直接查询:userId="usr-4412" AND operation="createOrder"推荐使用成熟的日志库(如 pino、winston、zerolog)而不是自己拼 JSON。这些库自带上下文注入、序列化安全和性能优化。
检查清单:上线前审查你的日志
每次提交涉及日志改动的代码前,我会逐项过一遍这个清单:
- 请求 ID 透传:入口中间件是否生成了 Request ID?是否注入到了所有下游调用?
- 模块标注:每条日志是否包含
module和operation字段? - 用户标识:涉及用户操作的日志是否记录了
userId或tenantId? - 参数摘要:关键业务参数是否记录?是否做了摘要而非全量?
- 敏感信息脱敏:密码、Token、手机号、邮箱等是否已脱敏?
- 外部依赖状态:调用外部服务的日志是否记录了状态码和耗时?
- 状态变化记录:业务状态变更前后的值是否都记录了?
- 日志级别语义:
error是否只用于真正影响用户的异常?warn和info的边界是否清晰? - 结构化输出:日志是否输出为 JSON 格式?字段命名是否与团队规范一致?
- Canonical Log:请求结束时是否有一条汇总日志包含完整上下文?
- 日志量控制:高频路径是否避免了
debug级别的日志?循环内部是否避免了逐条打印? - 错误分类:外部超时和内部异常是否用了不同的日志级别和处理方式?
- 可查询性:在日志平台上,能否通过
requestId、userId、orderId等关键字段在 10 秒内定位到相关日志?
总结
日志是系统在生产环境里唯一留下的「证据」。证据质量直接决定了排障效率。
堆栈告诉你在哪一行挂的,上下文告诉你为什么挂、挂了影响谁、怎么复现。前者是调试的起点,后者才是排障的终点。
把日志当成产品来做:想清楚读者是谁(未来的自己和值班的同事),他们要回答什么问题(发生了什么、影响多大、怎么修),然后为这些问题提供足够的数据。
不要等出了事故才想起来加日志。上线前就把上下文准备好,排障时才不会对着空日志发呆。
参考资料
- An Engineer's Checklist of Logging Best Practices — Honeycomb
- Trace ID vs Correlation ID: Understanding the Key Differences — Last9
- Structured JSON Logging in Production (2026) — DevStudio IT
- Correlation IDs — Microsoft Engineering Fundamentals Playbook
- Structured Logging in Production: Best Practices — OpenObserve
- Logging in Production Systems: What Actually Matters — Medium
- How to Implement Request-Trace Correlation — OneUptime
- Expert Guide to Logging Best Practices — New Relic