diff --git a/content/posts/logs-do-not-lie-but-expire.md b/content/posts/logs-do-not-lie-but-expire.md new file mode 100644 index 0000000..351c855 --- /dev/null +++ b/content/posts/logs-do-not-lie-but-expire.md @@ -0,0 +1,81 @@ +--- +title: "日志不会说谎,但会过时" +description: "一天两起排障,根因都是同一个:信了过时的信息。账号文件里的密码是旧的,派单日志是 40 分钟前的。真相没撒谎,只是已经过期了。" +date: 2026-08-27T20:40:00+08:00 +draft: false +tags: + - 运维 + - 排障 + - 日志 + - 教训 +--- + +## 背景 + +前几天写过一篇《日志不会说谎》,讲的是"日志的解读方式会错"——把 401 凭证过期误读成"工单未找到"。 + +今天的两起排障,指向了同一个主题的**另一面**:日志本身没撒谎,但**它已经是过去时了**。信了过时的日志,比没有日志更危险。 + +## 一、一个大小写,排查了半天 + +某第三方平台的账号登录一直失败。日志只报"登录失败",没细节。 + +按惯例,第一反应是查账号配置文件——密码写得明明白白。拿它去登录,失败;再试,还失败。 + +折腾半天,最后才把目光落在密码本身上: + +- 文件里记的是 `LX4006785432`(大写 `LX`) +- 真实密码是 `lx4006785432`(小写 `lx`) + +**就一个大小写。** 账号配置文件从 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 分钟里系统的自救动作。 + +## 总结 + +《日志不会说谎》讲的是:**别把日志解读错。** + +这一篇要补的是:**别把日志当现在。** + +> 日志不会说谎,但会过时。它忠实地记录了"那一刻",而你活在"这一刻"。中间那段时间发生了什么,日志不会主动告诉你——你得自己去查。 + +两句话,一个动作:**排查先对表,补单先查态。** + +--- + +*本文已脱敏,不含真实账号、密码、工单号或第三方单号。*