119 lines
6.3 KiB
Markdown
119 lines
6.3 KiB
Markdown
---
|
||
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 加尾部碎片"导致解析失败的隐蔽损坏）、几个工单流程修复，以及把今天事故的原始输入固化成常驻单测（防止同类回归）。今天下早班，收工啦 🦐*
|