这周采集侧出了两件事:上游改了结算规则,每日审计报红;价格流隔一阵就会静默一两分钟,调快看门狗后数据丢得更多,当天就回滚了。
审计红了 172 个市场
我每天会对前一天的数据跑一遍审计,其中 F 项用自己采到的 Chainlink 价格,按官方规则把每个 Up/Down 市场的结果重算一遍,和官方公布的结果逐个比。08-06 那天是 2320/2320 全对。08-08 早上审 08-07,F 红了,2226 个市场里有 172 个对不上。
我第一反应是自己断流了。但分歧分布不像断流:所有币种都有,5m 和 15m 都有,全天分布均匀,方向也对称(86 个我判涨官方判跌,86 个反过来),最大幅度达到 0.12%。断流会集中在某个时段,贴线误差也不会这么大,更像是口径变了。
为了确认问题在哪,我查了这 172 个市场临近结算时的成交价。如果官方结错了,或者我的数据坏了,交易者看到的前端价格应该和官方结果对不上。结果 171 个里有 166 个,临结算成交价都站在官方那边。交易者看到的和官方一致,说明结算算法变了。
然后去翻市场元数据,果然多了一段 raw.cryptoMarketConfig,形如 {id:"btc-5m-twap-30", twapEnabled:true, twapLookbackSeconds:30},resolutionSource 也指向了 TWAP 流,描述文字改成了 time-weighted average price。上游在 2026-08-07 00:00 UTC 整点,把全部加密货币 Up/Down 市场的结算源从 Chainlink 瞬时流切成了 TWAP 流:当时 5m 市场用 30 秒回看,15m 用 60 秒。
我先用手上 1Hz 的瞬时 tick 做简单平均来近似 TWAP 重算一遍,一致率从 92.3% 升到 98.8%(2545/2576),剩下的分歧相对差全部小于 5e-4,是近似误差的量级。机制算是确认了。
找到 TWAP 流的 topic
知道要采 TWAP 流,但不知道它在 WebSocket 上叫什么。我先猜了几个 topic 名,全部订阅失败。最后是把市场详情页的 _next chunk 下载下来 grep,找到了一段选择逻辑 {30:"crypto_prices_twap_thirty",60:"crypto_prices_twap_sixty"},照这个名字订阅就成功了。帧格式和瞬时流差不多,多一个 window_s 字段,大约 1Hz。
08-08 部署的适配改了这几处:
- 采集器多订阅两个 TWAP topic,写进同一张
price_ticks,用 source 区分;每个 topic 单独记最后一条 tick 的时间,单个 topic 静默超过 60 秒就限频重连。 - 导出多两个目录,文件名带
twap30s-/twap60s-前缀。Release 资产是平铺的,不加前缀会和瞬时流撞名。 - 审计 F 按
twapEnabled分流,判定逻辑抽成纯函数加单测;strike 回填对 TWAP 市场也改读 TWAP 流,读不出规则的一律留空并告警。
清理任务按天删 price_ticks,不分 source。如果只上线采集,没有同时改导出,三天后 TWAP 行会被当成「已归档」删掉,虽然它们从没导出过。所以采集和导出同一批上线,prune 也加了守卫:库里有可售的 source,却没出现在 manifest 里,就拒绝删除一整天的数据。
08-07 全天加上 08-08 部署之前的官方 TWAP 精确值是永久缺口,没法补。TWAP 是 Chainlink 用它内部的高频数据算的,不能从 1Hz 的瞬时 tick 精确还原。这段时间的审计只能走近似口径,相对差小于 1e-3 记为无法判定、如实披露,超过才判红。瞬时流我没砍,结算不用它了,但 K 线全靠它聚合,而且客户做策略两条线都要。
价格流的「僵尸」
第二件事是从一个假红开始的。08-09 的审计报了一条「价格流静默 121 秒」,当天其他各项全绿。按时间线捋下来:02:43:00 上游停止推送;02:43:59 心跳检测到静默 59392ms,差 608ms 没到 60 秒阈值,看门狗这一轮没动手;02:44:59 看门狗触发强制重连;02:45:00 重连成功;而审计的 cron 恰好在 02:45:0x 去抓 health,读到的是重连前的 121 秒。
审计阈值和看门狗的触发阈值都是 60 秒,正常重连期间也会报红。我把审计阈值调到 300 秒,和单 topic 的阈值对齐。同时补上损失指标,按币种检查秒级覆盖率:95% 以上记录,85% 到 95% 披露,低于 85% 判红。原来的完整性检查只在最大断档超过 600 秒时报警,这类僵尸每次大约 150 秒,达不到阈值。
顺着查下去才发现真问题。这种「socket 还是 OPEN、ping 有回应、但一条数据都不来」的静默,每天有七十多次:
| 日期 | 秒级覆盖率 | 缺口秒数 | 僵尸次数 | 每次缺口 |
|---|---|---|---|---|
| 08-08 | 88.8% | 9640 | 62 | 155s |
| 08-09 | 87.6% | 10690 | 73 | 146s |
| 08-10 | 86.9% | 11279 | 78 | 145s |
缺口约等于次数乘以 150 秒,三天都对得上。我之前一直以为覆盖率下降是上游 feed 本身变稀了,其实主要成分就是这些僵尸。
到底是谁停了
要回答「是上游停推还是我这边的问题」,先排除了几样:同一个 Node 进程里的盘口 WebSocket 在静默期间照样每分钟收三四万帧,说明不是事件循环卡住、不是机器网络、不是进程假死;同一条 relay socket 上两个完全独立的源(Chainlink 聚合和币安镜像)同时静默,说明也不是某个数据源自己没数据。
这些还只是间接证据。我在客户端加了一组归因计数 relayFrames:socket 层读到的字节数 bytesRead、onMessage 调用次数和被丢弃的帧数。字节不涨、帧不涨,是上游停推;字节涨、帧不涨,是我没有消费;帧涨、tick 不涨,是帧到了却被我丢了。最后一种以前完全看不见,因为 relay-ws.client.ts 原来有三处静默 return(topic 不匹配、payload 校验失败、JSON 解析失败)。上游只要改个字段名,我就会丢掉整条流,看起来和停推一模一样。
第一条线上日志是 since={ms:4999, bytes:2, frames:0},而那次静默有 63877ms。delta 只覆盖最后 5 秒,无法判断整段静默。原因是基线快照的刷新条件写成了 silenceMs < 60s,静默前 59 秒一直满足条件,基线就一直在往后刷。基线应该取在静默开始之前,所以改成只在 tick 确实在流(静默小于 10 秒)时刷新,并抽成纯函数 shouldRefreshBaseline 加了回归测试:静默 59 秒不能算健康。
修完之后拿到的是 since={ms:55004, bytes:22, frames:0}。55 秒里 socket 上一共 22 个字节、0 条消息。我的 ping 间隔是 5 秒,55 秒里 11 次 ping,服务端回的 pong 帧不掩码、没有 payload,每个 2 字节,11 × 2 = 22,刚好对应收到的字节数。relay 在这段时间只应答 ping,没有推送数据。确认是上游停推后,缺失数据不补,只记录和公示。
看门狗调快,结果更亏
既然停推检测得越早、断档越短,我在同一个提交里把僵尸看门狗从 60 秒的心跳里拆出来,放到独立的 5 秒定时器上,最坏检出时间从 120 秒降到 65 秒。这里有个要注意的地方:silenceBaselineMs 只被 tick 推进,不被重连推进,上游停推期间每一次采样都会判静默。60 秒采样时这是自限的,改成 5 秒不加限频就是每小时 720 次重连。所以加了至少 60 秒一次的限频,单测直接跑一小时的采样循环,断言重连不超过 60 次。
08-11 部署上线,断档中位数从 98.5 秒降到 64.0 秒。但同一天按部署时刻切开看,断档频率从每小时 3.2 次涨到 8.6 次,净损失从 8.2% 涨到 13.0%。gap 直接从 price_ticks 算,和看门狗的检测方式无关。当晚就回滚回 60 秒。
回滚时还发现一个耦合。「健康基线」那个 10 秒阈值当时写成了 WATCHDOG_INTERVAL_MS * 2,采样周期改回 60 秒,它会变成 120 秒,重新引入「静默 59 秒仍算健康」的 bug。几小时前刚加的回归断言失败了,所以把健康阈值改成绝对常量,和采样周期分开。
回滚之后我差点又推翻自己一次。08-11 全天覆盖率 86.5%,和 08-10 的 86.8% 几乎一样,看起来「改没改都一样」。其实错在两点:新代码只跑了全天 18% 的时间,被稀释了;而且覆盖率和断档不是一个指标,缺的那 13.5% 里只有大约 9 个点来自超过 10 秒的断档,剩下是 feed 本身的秒级稀疏。另外我前一天还拿一个没走完的小时当过证据,14 点那个小时当时显示 78.4%,走完是 86.0%。
今天(08-12)把时段切开重新对照了一次:
| 时段 | 代码 | 断档/小时 | 中位时长 | 损失 |
|---|---|---|---|---|
| 08-10 全天 | 旧 60s | 3.3 | 92.0s | 8.8% |
| 08-11 00:00-10:37 | 旧 60s | 3.6 | 96.0s | 9.1% |
| 08-11 10:37-15:03 | 新 5s | 8.3 | 64.0s | 12.7% |
| 08-11 15:03-24:00 | 回滚后 | 2.7 | 93.5s | 6.9% |
| 08-12 00:00-07:50 | 旧 60s | 3.1 | 88.5s | 7.9% |
四个旧代码时段跨了两天,结果接近,新代码时段明显偏离。5 秒让每次断档短了 30 秒左右,但频率增加到 2.5 倍,总损失更高。
回滚那天我写的解释是「上游停推大约 90 秒会自愈,我 64 秒就掐掉一个还活着的 session」。对照表推翻了这个解释:两种代码下断档时长都约等于检出时间(旧代码中位 92 秒对检出均值 90 秒,新代码 64 秒对 60 到 65 秒),说明断档是被我这边的重连结束的,不是上游自己好的。更可能的是重连本身在招来下一次停推,旧代码大约 18 分钟重连一次,新代码 7.2 分钟一次,和断档频率同步。所以要优化的话,方向应该是提高阈值、减少重连,而不是加快检测。这和我最初的直觉正好相反。
在拿到那 22 个字节的记录之前,我还写过两个独立的最简客户端,准备做对照实验。复审时发现,同一台机器、同一个 IP 开多条连接,如果 relay 按 IP 限流,几条连接会一起静默,仍然分不清原因,所以删掉了它们。后来用计数器记录真实静默,确认了上游停推。后续调整看门狗会分时段看 gap,日覆盖率在这次实验里看不出差别。
outcometick 工程笔记(6/21)