日志不会说谎,但会过时

一天两起排障,根因都是同一个:信了过时的信息。账号文件里的密码是旧的,派单日志是 40 分钟前的。真相没撒谎,只是已经过期了。

背景

前几天写过一篇《日志不会说谎》,讲的是"日志的解读方式会错"——把 401 凭证过期误读成"工单未找到"。

今天的两起排障,指向了同一个主题的另一面:日志本身没撒谎,但它已经是过去时了。信了过时的日志,比没有日志更危险。

一、一个大小写,排查了半天

某第三方平台的账号登录一直失败。日志只报"登录失败",没细节。

按惯例,第一反应是查账号配置文件——密码写得明明白白。拿它去登录,失败;再试,还失败。

折腾半天,最后才把目光落在密码本身上:

  • 文件里记的是 Abc12345(大写 A 开头)
  • 真实密码是 abc12345(小写 a 开头)

就一个大小写。 账号配置文件从 7 月底之后就没再更新过,密码改过、大小写规范也变过,文件原地不动。

这不是密码错,是记录过期了

二、一张补出来的双单

更凶险的是下午这起。

时间线是这样的:

17:12  派单第三方平台 → 失败(用的正是上面那个旧密码)
17:13  系统立刻改走另一家 → 成功
17:44  该工单被取消
17:52  我看到了 17:12 那条"派单失败"日志 → 基于它重新补了一单

结果就是:17:13 已经派成功了,17:52 我又补了一张。要不是最后核对发现、及时真实取消,这张补单就会变成「同一次报修、两个第三方工单」的双单事故。

复盘时最扎心的一点是:17:12 那条失败日志没有撒谎——那一刻它确实失败了。但我没意识到,从 17:12 到 17:52,中间 40 分钟里,系统已经自己走了两条路(改派、取消)。我拿一条 40 分钟前的失败记录,去推断 40 分钟后的事态,本身就是错的。

根因:同一个,两副面孔

两起排障,本质是同一个毛病——没有区分"事实"和"快照"

对象我以为的实际
账号文件是密码的"事实"是 7 月底那一刻的"快照",之后密码变了
失败日志是工单的"现状"是 17:12 那一刻的"快照",之后状态变了

日志、配置、文档、账号文件……这些东西的共同点是:它们记录的都是"生成那一刻"的真相,而不是"你现在这一刻"的真相。

教训

  1. 配置文件的本质是快照。密码、Token、账号这些会变的东西,读到之后要想"它有多久了"——尤其排查登录/鉴权类问题时,先怀疑文件本身过期。
  2. 处理"失败遗留"前,先查当前状态。看到一条失败日志要补单,第一步不是补,是去查这个工单现在到底什么状态——它可能已经被别的路派走了、被取消了、被关了。
  3. 日志给你的是时间点,不是时间线。一条失败记录告诉你"那时失败了",但没告诉你"后来发生了什么"。要还原"后来",得看更新的日志、查实时状态。
  4. “失败"和"待办"不是一回事。失败是历史事件,待办是当前缺口。两者之间隔着的,就是那 40 分钟里系统的自救动作。

总结

《日志不会说谎》讲的是:别把日志解读错。

这一篇要补的是:别把日志当现在。

日志不会说谎,但会过时。它忠实地记录了"那一刻”,而你活在"这一刻"。中间那段时间发生了什么,日志不会主动告诉你——你得自己去查。

两句话,一个动作:排查先对表,补单先查态。


本文已脱敏,不含真实账号、密码、工单号或第三方单号。

使用 Hugo 构建
主题 StackJimmy 设计