在第 67 秒被取消的那一轮探测
本文译自 2026-09-24 的英文原文。
(原文写于 2026-09-24;之后有三处变化。文末说「还没有走」的那一步,已在 2026-09-24 17:08 UTC 随检查套件 0.7.1 上线:每个请求只拿到剩下的时间预算,一个任务的探测阶段不会再拖到约 20 秒;守卫仍是 15 分钟。2026-10-04 起,每轮改为一次只领取 5 台、探完再领,一次取消最多留下 5 台。2026-10-07 起,探测改为并行扇出:每个 tick 除 cron 本身之外再派出 19 个队列调用,每批任务分 3 路同时探测,一轮从约 3 分钟缩短到约 40 秒。)
探测器跑在一个 Cloudflare Worker 上,cron 触发器每五分钟触发一次。下面这几轮运行的时候,每次调用最多领取 30 台到期的 server,一台接一台地检查,最后记下一行 round complete。九月里有三轮始终没有记下这一行:一轮查完 9 台中的 7 台就停了,一轮是 30 台中的 15 台,还有一轮是 30 台中的 27 台。
没有一次是超时。我们手上有平台自己记录的只有一轮,它停下时墙钟时间 67 秒、CPU 时间 564 毫秒,离两个上限都差得很远。我们任务表里的行显示,这些 server 已被领取、却从未完成;每一台都在之后的某个 tick 被重新检查,所以没有丢失任何东西。但「之后」原来意味着大约 30 分钟之后,对 15 分钟档的 server 来说,就是错过了两次检查。
实际发生了什么
答案不在我们的日志里,因为我们的日志在调用停下的地方就断了。答案在平台的调用视图里。2026-09-18 20:30:11 UTC 那一轮,有两次 scheduledTime 相同的定时调用:
| 结束时间(UTC) | 结果 | 墙钟时间 | CPU 时间 | 记下了什么 |
|---|---|---|---|---|
| 20:31:53 | canceled | 67,443 ms | 564 ms | 15 行 -> run,没有 round complete,没有错误 |
| 20:32:04 | ok | 117 ms | 3 ms | 什么也没有:它领取了零台 server |
Cloudflare 在第 67 秒取消了第一次调用,十一秒后重新投递了同一个 cron 事件。这是寻常的平台行为,不是故障。重新投递的那次调用做了它该做的事:向数据库要到期的 server。它一台也没拿到。
为什么一台也没拿到
领取是一个数据库函数,里面有一个在途守卫:一台 server 如果最近一条任务行没有 finished_at,且请求时间在 30 分钟以内,就被当作仍在探测中,这样两次重叠的调用就不会把同一台 server 探测两遍。被取消的那次调用领取了、却没完成的 15 台 server,正好符合这个描述。守卫在尽它的职责,针对的却是一个已经不存在的情形。这 15 台 server 在 30 分钟期满后的第一个 tick 被领走,实际上就是晚了 30 到 35 分钟,取决于领取恰好落在一个 tick 里的什么位置。
2026-09-21 16:45:16 UTC 我们又看到了一次,那是一次探测器部署之后的第一轮。留下了十二台 server。它们在 17:15 的 tick 被重新领取,那次领取发生在 17:15:17.043 UTC,比守卫边界 17:15:16.954 晚了 88 毫秒。如果领取早十分之一秒,同样这十二台 server 就要等到 17:20 的 tick。所以在旧守卫下,代价不是一个固定的数,而是 30 分钟或 35 分钟,由抖动决定。
关于证据的一点说明:在控制台里用 outcome != ok 筛选七天的范围,这几轮返回的是「No events found」。调用列表是抽样的,页面上也这么写着。把时间窗收窄到那个 tick 附近,一下子就找到了。
缩短守卫:第一次尝试
修法很明显:把守卫窗口设得比 30 分钟短,让被取消那一轮留下的 server 在下一个 tick 或再下一个 tick 就被重新领取。问题是要多短。
第一稿写的是 10 分钟,并且附有测量数据。十天、16,332 条任务行里,单个任务从领取到完成最长用了 275.8 秒;第 99.9 百分位是 249.1 秒;没有一个超过 5 分钟。10 分钟是观测到的最坏情况的两倍还多。
pull request 上的一条审核意见说明了这个论证为什么不够。一个任务发出的每一个 HTTP 请求都会重新设定单请求超时,而轮次级别的预算只在请求之间检查,从不传进正在进行中的请求。所以单个任务光是探测阶段就可能花大约 20 秒,这还没算快照写入和签名。三十个任务依次执行,大约就是 11 分钟。测量描述的是我们遇到过的 server;代码描述的是我们可能遇到的 server。按测量值设定的守卫,一台更慢的 server 就能穿过去。
十五分钟,以及为什么是这个数
十五分钟是平台允许一次定时调用运行的最长墙钟时间。到了 15 分钟还在运行的调用会被停掉,所以一条请求时间在 15 分钟以前、又没有 finished_at 的任务行,不可能属于一个仍在运行的调用。不管 server 有多慢、代码里的预算怎样安排,守卫都可以依赖这一点。这是能从一个上限、而不是从一组样本推出来的最小的整数个 tick,所以迁移里写的就是这个值;这个迁移只改了领取函数里的一个字面量,把 '30 minutes' 改成 '15 minutes'。
这个论证有三个明确的前提:平台确实执行 15 分钟的上限;领取发生在它所属的调用开始之后;数据库时钟和运行时时钟在 15 分钟之内的相对漂移,不超过那段间隔。两个时钟从来不需要在时刻上一致,只需要在时间流逝的快慢上一致,因为每个不等式用的都是同一个时钟上的差值。
我们事后写下的规则是:保护窗口要按结构上的上界或平台的硬性上限来设,绝不按测到的最大值来设。测量仍然有用。它们告诉我们最坏情况远低于上界,而这和告诉我们上界在哪里是两回事。
改动之后
这个迁移先在生产上的一个事务里干跑并回滚,然后于 2026-09-21 应用。探测器部署 24 小时后的只读核查发现了一轮:2026-09-22 12:45:53 UTC,28 个任务中有 4 个没有完成。这四台 server 都在 13:01:06 到 13:01:19 UTC 之间有了新的 run,即 15.3 分钟之后,守卫失效后的第一个 tick。改动之前,同样的情况至少要 30 分钟。
还有一步我们没有走:把这一轮剩余的预算传进每个请求,让一个任务的探测阶段受这一轮约束,而不只受它自己的单请求计时器约束。这会改变一项检查超时的方式,从而改变这项检查能得出什么结论,所以要单独走一轮审核。在那之前,守卫保持 15 分钟。至于取消本身,我们不打算去修。那是平台的事,而且很少见,大约 270 轮里有两轮;一轮能在下一个 tick 接着做下去,对一个随时可能被取消的东西来说,正是对的形状。
数字从哪里来
两行调用记录来自 Cloudflare 控制台的调用视图,筛选到 2026-09-18 20:30 UTC 前后那一分钟。任务时长(16,332 行,最长 275.8 s,p99.9 为 249.1 s)和重新领取的时刻(17:15:17.042628 UTC,对比边界 17:15:16.954154 UTC;2026-09-22 四台 server 在 13:01:06 到 13:01:19 UTC 重新运行)来自对 probe_jobs 和 runs 表的只读查询。单请求和轮次预算的行为是从探测器源码里读出来的,不是测出来的。