关于日志,我踩过的坑和总结的原则

作者:摸鱼的鲸鱼 发布时间: 2026-04-15 阅读量:84 评论数:0

我们组有个不成文的说法:一个人写日志的水平,大概等于他排查过多少次线上问题。因为只有半夜三点对着一屏毫无用处的日志抓瞎过,你才会知道该打什么。

先说几个我亲手制造或者亲眼见过的反面例子。

反例一:一天 80GB

有个接口把完整的请求体和响应体都打进了 info 日志,理由是「方便排查」。这个接口日均调用 2000 万次,每条日志平均 4KB。上线第二天,日志盘告警,一天写了 80GB,日志采集组件的 CPU 打满,把业务进程也拖慢了。

更讽刺的是:真出问题那天,我们想查某个用户的记录,grep 一个 80GB 的文件花了十几分钟,最后还是从数据库里查出来的。日志太多和日志太少,实用价值是一样的——都是零。

反例二:进入方法,退出方法

logger.info('进入 calculatePrice')
// ...
logger.info('退出 calculatePrice')

这种日志我至今没搞懂它想告诉我什么。函数被调用了,然后返回了,这不是理所当然的吗?如果你关心的是耗时,那应该打耗时;如果你关心的是入参,那应该打入参。「进入」和「退出」这两个词本身携带的信息量是零。

反例三:吞掉了 traceback

except Exception as e:
    logger.error('处理失败: ' + str(e))

然后你在日志里看到一行:处理失败: list index out of range。哪个 list?哪一行?调用栈是什么?全都没有。这一行日志唯一的作用是让你知道「有东西坏了」,而这件事你从监控告警里已经知道了。

Python 里应该用 logger.exception() 或者 logger.error(msg, exc_info=True)。我们后来在代码检查里加了规则,禁止在 except 块里裸用 str(e)。

反例四:日志里躺着手机号

这个是安全同事扫出来的。一个下单流程的日志里完整打印了收货信息,包括姓名、手机号、详细地址。日志会被采集到集中平台,平台的查询权限范围比业务系统宽得多。等于绕过了所有的权限控制。

后来我们做了统一的脱敏格式化器,在序列化阶段就替换掉敏感字段。但更重要的是意识:日志的读者范围永远比你以为的大。

我现在遵循的原则

  1. 每条日志都要能回答一个具体的排查问题。 写之前先想:什么时候有人会来看这一行?如果想不出场景,就别打。
  2. 必须有 trace_id,而且要能穿透异步边界。 这是分布式系统里日志有没有用的分水岭。同步调用用 ThreadLocal 或 contextvars 很容易,但丢进线程池、消息队列之后经常就断了,需要显式传递。我们为此专门包了一层任务提交的工具函数。
  3. 结构化,不要拼字符串。 logger.info('order created', extra={'order_no': no, 'amount': amt}) 比拼接的字符串好一万倍,因为它能被索引、被聚合、被告警。
  4. 级别要有纪律。 我的划分是:ERROR 表示需要人介入,看到就要有人处理;WARN 表示不正常但系统自己扛住了,需要定期看;INFO 是业务关键节点,量要可控;DEBUG 默认关闭,可以随便打。最忌讳的是 ERROR 满天飞——当一个系统每天报 5000 条 ERROR,实际上等于没有 ERROR,因为没人看了。
  5. 打决策依据,不打决策结果。 「优惠券不可用」这条日志没什么用,「优惠券不可用: 门槛 100,订单实付 87」才有用。我判断一条日志好不好,标准是:看完这行,我还需不需要去读代码才能理解发生了什么?
  6. 耗时用埋点,不用两行日志相减。 早期我们靠「开始」和「结束」两条日志算耗时,一旦并发上来,日志交错在一起根本对不上。
  7. 循环里绝不打日志。 要打就在循环外打汇总:处理了多少条,成功多少,失败多少,失败的前 5 个 id 是什么。

一点补充的体会

好的日志有一种气质:它是写给「未来那个不了解上下文的人」看的,而那个人多半就是三个月后的你自己。所以别用只有你懂的缩写,别指望读者知道 status=7 是什么意思,也别在日志里用反问句和感叹号(我见过 logger.error('这不可能发生!!!'),然后它发生了,而我们完全不知道该怎么办)。

最后一个小习惯:我每次排查完线上问题,都会顺手补一条日志——就是这次「要是当时有这条日志就好了」的那条。几年下来,这大概是我写过的最有价值的一类代码。

评论