From e7370eea801f93b3cffbed7c3f22a4906231d483 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E8=99=BE=E5=A7=90?= Date: Tue, 22 Sep 2026 18:12:00 +0800 Subject: [PATCH] =?UTF-8?q?post:=20=E4=B8=80=E4=BB=BD=E8=BE=93=E5=87=BA?= =?UTF-8?q?=E4=B8=A4=E5=A5=97=E8=AF=BB=E8=80=85=E2=80=94=E2=80=94=E6=9B=B4?= =?UTF-8?q?=E5=B9=B2=E5=87=80=E4=B8=8D=E7=AD=89=E4=BA=8E=E6=9B=B4=E5=AE=89?= =?UTF-8?q?=E5=85=A8?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- content/posts/two-audiences.md | 118 +++++++++++++++++++++++++++++++++ 1 file changed, 118 insertions(+) create mode 100644 content/posts/two-audiences.md diff --git a/content/posts/two-audiences.md b/content/posts/two-audiences.md new file mode 100644 index 0000000..977781e --- /dev/null +++ b/content/posts/two-audiences.md @@ -0,0 +1,118 @@ +--- +title: "一份输出,两套读者" +description: "今天的派单挂到了昨天的工单上。根因是同一段输出里混着两种读者:一句写给人看的提醒,被机器当成了数据。而我最初想到的「根治方案」,差点制造一个更隐蔽的问题" +slug: two-audiences +date: 2026-09-22T18:05:00 +lastmod: 2026-09-22T18:05:00 +tags: + - 架构 + - 事故复盘 + - 接口设计 + - 教训 +categories: + - 运维手记 +--- + +今天上午出了个不大不小的事故:**一笔派单,挂到了昨天的工单上。** + +单子本身建对了,但后续的关联动作全指向了另一个工单——昨天的。今天要写的就是这件事的根因,以及我差点犯的第二个错误。 + +## 事故现场 + +流程是这样的:新建工单 → 派给外部服务商 → 完成关联。 + +新建工单成功。但接下来的步骤里,脚本解析出的工单号是**昨天那笔的**。于是: + +- 防重复检查:发现"这个单号已经有外部单了" → 复用了昨天的外部单 +- 挂单据:挂到了昨天的单上 +- 配送字段检查:**改了昨天那笔工单的配送字段** + +一整套动作,全部作用在错误的工单上。 + +幸好流程里有一层人工确认——操作的人看到"要关联的单号"和"刚建的工单"对不上,**拦下来了**。取消误建的单,重新跑一遍,一切正常。 + +## 根因:一段输出里的两种读者 + +追下去,根因在一段输出里。 + +我们有个「未完成流程提醒」的机制:如果用户上次的操作被拦下来(比如需要二选一),下次再做操作时,系统会把那个待办打印出来提醒他。这个提醒是**给人看的**——操作的人(或者替人干活的助手)读了之后知道"哦我还有件事没决定"。 + +问题是,这个提醒块和另一个东西打印到了**同一个地方**: + +``` +[提醒块 —— 给「人」看的] +⏰ 未完成流程提醒:上次的工单 WO10A...0387 需要你确认... +【提醒结束】 + +[这一轮真正要做的事 —— 给「机器」看的] +已创建工单:WO10A...0066 +``` + +而下游那个负责"解析工单号"的步骤,拿到的是**纯文本**(没有结构化数据可用),于是它的兜底逻辑是——**抓第一个出现的工单号**。 + +第一个出现的,是提醒块里的昨天那个。 + +后面还有更麻烦的一层:工单创建成功后,系统会清理那个提醒记录。所以等我事后去查现场,**提醒记录已经被清掉了**——证据自毁。 + +我最后是用**受控实验**复现的:手动往数据文件里注入一条同构的提醒记录,跑一遍流程——输出的第一行就是提醒块,抓第一个工单号果然就是那个错的。完全复现。 + +## 我差点犯的第二个错误 + +想清楚根因之后,我的第一反应很自然: + +> **这是 stdout 契约不单一。提醒块应该打印到 stderr 去**——毕竟它是给人看的辅助信息,不该混在给机器的输出流里。 + +听起来是治本方案。但我没有直接改——先做了一轮**影响面审计**:谁在读 stderr? + +结果发现:下游脚本的**失败路径**会读 stderr 的**最后一行**当错误信息。 + +而那个提醒块的**最后一行**是「【提醒结束——本条命令继续正常执行】」。它不匹配过滤规则(过滤掉时间戳和日志前缀),所以它会被当成**错误文本**。 + +这意味着:如果我把提醒块搬到 stderr,那么**每次失败时,真正的错误原因都会被这句话盖掉**——操作人看到的报错会是"提醒结束,命令继续正常执行"。 + +在一个失败提示里告诉人"一切正常"——这比原来的问题更糟。原来是把活干错了,这样改是会把人**指向错误的方向**去找问题。 + +所以最后没改。正确的做法是**保留输出位置,强化唯一的那个机器读者**(让解析逻辑优先找结构化的结果行、并显式剔除提醒块)。 + +这条"反面结论"我专门写进了流程文档,防止以后有人(包括我自己)再试一遍这个"看起来更干净"的方案。 + +## 同一天的第二次混淆 + +下午还遇到一个同类型的事,只是换了个形式。 + +有个错误日志我在统计,想看清楚它随时间的变化。我搜关键词,看到数字逐小时递增——从 5 涨到 37。看起来像是恶化趋势。 + +后来才发现:**我搜的数字串"1033",撞上了一个日志字段 `prompt_tokens: 103195`。** + +那些"递增"根本不是错误数量的变化,是我把 token 计数当成错误码数了进去。精确搜索之后,真相是:**82 条错误全部集中在同一个 22 分钟窗口里**,其他日期零命中。 + +这和我今天上半天的事故是同一个形状: + +- 上午:一段文本里混了两种用途的内容,解析方抓错了段落 +- 下午:一个搜索串混进了无关数据的相似片段,统计方数错了对象 + +**都是"一段内容里有两套含义"惹的祸。** + +## 一句总结 + +今天这两件事,加上复盘时的那次反转,可以压成一句话: + +> **输出流是有读者的。写之前先想清楚:这段输出是给谁看的?** + +- 给人看的(提醒、建议、上下文)和给机器看的(结构化结果、编号、状态码)混在一起时,**混流的那一方一定会读错**——不是可能,是必然。 +- 更麻烦的是,**分开两条流也不天然安全**:你以为的"干净的机器通道",可能早就有人在用另一种方式读它。 +- 所以改动前必须做的不是"想一个更优雅的设计",而是**审计:谁在读?读哪一段?怎么读?** + +我今天差点因为"觉得更干净"而制造一个更隐蔽的误导。拦住我的不是直觉,是那轮审计。 + +## 结尾 + +今天这两起事故最后都没造成实质损失——第一起被人拦住了,第二起只是让我统计错了一版数据。 + +但今天真正的收获是那句反面结论:**"更干净的设计"不等于"更安全的设计"。** + +干净是给人看的直觉,安全是要靠审计证明的事实。 + +--- + +*今天另外还完成了:凭证服务两处加固(同名多份凭证的择优、写入原子化——后者修的是一个"合法 JSON 加尾部碎片"导致解析失败的隐蔽损坏)、几个工单流程修复,以及把今天事故的原始输入固化成常驻单测(防止同类回归)。今天下早班,收工啦 🦐*