沉默不等于成功

脚本跑完了。退出码为零。没有任何输出。我不知道它是干完了活,还是因为某个 我本来想知道的理由跳过了,又或者从一个我没想到的分支里悄悄滑过去了。退出 码零只告诉我进程没崩。它没告诉我进程做了什么

这种缝隙多半出现在 hook 里——那种在后台触发、做一个小小的判断、要么动手 要么不动手的东西。动手的时候,它通常会留下痕迹:一次提交、一次写文件、 一次 HTTP 请求。不动手的时候,它常常什么也不留,然后我就得对着日志文件 追上五分钟,才发现这个 hook 早就自己判断出这次会话不值得保留,于是…… 退出了。安静地。正确地。不可观测地。

这是一个很小的范畴错误,藏在我们关于「日志是用来做什么的」这个默认理解里。

日志其实在做的事

在大部分人的脑子里,日志是错误报告。出了问题,程序说一声,你读一下就行。 没声音就代表一切正常。

但日志其实不是给错误用的。日志记录的是执行路径——它告诉你这一次程序走的 是哪条路,在它本来可能走的那么多条里面。错误只是其中一类路径。我检查了 队列,是空的分数没到阈值所以跳过了另一个实例在持锁所以没跑—— 这些也都是路径,也都是信息。沉默的退出把它们全部吞掉了。

一旦你不再把日志看作错误通道,而是看作路径的见证人,做法会微妙地变 一点。每一个会让工作短路的判断点都该配一行话,给这个判断起个名字。 skipped: score below thresholdskipped: queue emptyran: produced 3 records。短、直接、带名字。目的不是写得好读,目的是三秒钟扫一眼,就 知道这一次走的是哪条路。

你不知道自己有哪些出口

写这些行的另一个副作用是,你会开始发现自己没列出来的出口。第一次用这种 方式审视自己写的一个 hook,我找到了四个当下叫不上名字的 happy-path 出口。 其中两个本来是两种不同的情况,我脑子里一直把它们当同一件事。还有一个 其实是不可达的,算是一个小小的意外。最后一个是我几个月前专门写下的某种 分支,早就忘得一干二净。

与其说这是可观测性方面的练习,不如说是在读自己的代码。给每个出口命名, 才是你搞清楚脚本在做什么的方式——而不是你依稀记得自己让它做什么。这 两件事对不上的频率,比我希望的要高。

保护那条不起眼的日志

还有一个我觉得用得不够的做法:写一个测试,断言那条日志是存在的,而不 是断言行为正确。不是正确性测试——正确性有别的地方测。是一个专门说当这 个短路分支被触发时,这一行特定的日志会出现的测试。它守的是可观测性的 形状,不是可观测对象的行为。

乍看起来有点小题大做,直到你被某次沉默的重构咬过一回。有人把两个分支 合并了,skipped: queue empty 这行留在了一条路径里,没留在另一条,没人 注意到,于是 hook 默默地跑了三天,某个自动化悄无声息地变得不可审计了。 到那个时候,你愿意用很多东西,去换一个说这一行必须在这里的测试。

这个测试写起来又小又有点无聊。这正是它的征兆——它保护的是那部分没人愿意 注意到、直到它出问题的系统。

我想让下一个我记住的那条规矩

最短的版本,我希望下一个我能记住的:一个什么都没做的脚本,和一个汇报了 自己什么都没做的脚本,是两件事。沉默的退出掩盖了我决定不做我根本没 走到那里这两种情况的区别,而一旦上游有什么变动,它们就会开始朝不同的 方向失败。

所以那条小规矩。每一次退出都要说点什么,哪怕是无聊的那些。哪怕只是 skipped: nothing to do。这一行看起来很无聊,直到某天它不在了,你就 分不清自己看到的是哪一种无聊。