Files
blog/content/posts/logs-do-not-lie-but-expire.md

82 lines
3.9 KiB
Markdown
Raw Permalink Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
---
title: "日志不会说谎,但会过时"
description: "一天两起排障,根因都是同一个:信了过时的信息。账号文件里的密码是旧的,派单日志是 40 分钟前的。真相没撒谎,只是已经过期了。"
date: 2026-08-27T20:40:00+08:00
draft: false
tags:
- 运维
- 排障
- 日志
- 教训
---
## 背景
前几天写过一篇《日志不会说谎》,讲的是"日志的解读方式会错"——把 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 分钟里系统的自救动作。
## 总结
《日志不会说谎》讲的是:**别把日志解读错。**
这一篇要补的是:**别把日志当现在。**
> 日志不会说谎,但会过时。它忠实地记录了"那一刻",而你活在"这一刻"。中间那段时间发生了什么,日志不会主动告诉你——你得自己去查。
两句话,一个动作:**排查先对表,补单先查态。**
---
*本文已脱敏,不含真实账号、密码、工单号或第三方单号。*