pmwallets 的付费功能之一是订阅钱包的成交推送：被订阅的钱包在链上成交，我们通过 WebSocket 或 webhook 推给订阅者。网站上有一个公开的延迟看板，头条数字是「收到区块头 → 推送」。从 09-19 看板第一次显示数字，到 10-01 做完 Postgres 重启演练，这条链路改了好几轮，这里按时间记下来。
看板上的 −574 秒
看板上线初期出现过 p50 −574 秒，1h、24h、7d、30d 四个窗口显示同一个数。
写 ingest_latency 时传入整数毫秒，JSONEachRow 写入 DateTime64(3) 时却按秒解释，线上出现饱和到 9999-12-31 的值。项目笔记记录，78,834 行中有 37,602 行异常。查询只写时间下界，未来的异常值便进入所有窗口。修完写入后，部署又漏了重启 pmwallets-live，旧代码继续写异常值。
live 的日志用原始值，没有经过 ClickHouse 存储转换，因而没有暴露写入问题。原来的 test/latency-write.test.ts 在测试里复制转换函数，没有覆盖生产写入路径，后来删掉了。
修法是写带 Z 的 ISO 字符串。不带 Z 的字符串会按会话时区解释，在 session_timezone=Asia/Shanghai 下实测偏 8 小时；我最早的探针跑在 UTC 机器上，区分不出这两种写法。查询侧补上上界。部署脚本后来改成一个服务一个脚本。
负延迟是真的
修完存储，区块时间戳到检测的差值仍为负。独立轮询器采了 27 个连续区块：
- 本机时钟对 NTP 偏差约 +2.3ms；
- 相邻区块的时间戳间隔是 1, 2, 1, 2…，墙钟间隔是 1.40, 1.60…，平均都是 1.5 秒；
- 27 个区块全部在自己声称的时间戳之前就到了我们手里，领先 0.44–1.25 秒，中位 0.74 秒。
这次采样中，整秒区块时间戳与墙钟存在偏差。仅凭采样不能把超前现象归因于整秒取整。能确认的是，用这些块的时间戳作起点，会得到负延迟，因此看板改用收到区块头的本机时间。
现在延迟一律以 tDetect（我们收到区块头）为起点，区块时间戳到检测的差值另存为 headLead，页面上不显示，只在怀疑本机时钟漂移时看。「检测 → 推送」也改成逐行求差再取分位，原来页面上是两个中位数相减，差值的中位数不等于中位数之差。修完后实测：收到区块头到拿到日志 p50 0.050 秒，到入库 p50 0.128 秒、p99 0.541 秒。
推送抽成独立进程
09-21 推送从 API 进程里拆出来。推送有延迟承诺，又跟 API 共用事件循环，每次无关的部署都会把所有在线 socket 掐掉。push 进程只听 loopback，Caddy 按路径分流，/v1/ws 到 push，其余到 API，客户端 URL 不变。配置拆成 loadCoreConfig 和 loadApiConfig，登录或支付配置坏了，不该让推送起不来。就绪状态改成「至少成功跑完一轮 poll」，原来是「拿到锁」就报 ready，而 start() 拿锁后之后的所有异常都被吞掉重试，持续失败的推送会一直显示健康。
部署脚本里有一个坑只有实际跑才发现：curl 协商到 HTTP/2 时会静默丢掉 Connection: Upgrade，WS 升级请求变成普通 GET，push 返回 Cannot GET /v1/ws，看起来像路由错了。回环上是明文 HTTP/1.1，所以本机检查没暴露。测 WebSocket 升级要加 --http1.1。
09-20 还修过投递顺序：32 个 worker 各自认领后 wsSend，实测帧序为 704,700,701,702,703,705。客户端若保存高位游标，keyset 补拉就拿不到遗漏的低位成交。先改为 WS 按账本顺序串行发送，随后按用户分组：组内有序、组间并行，webhook 也独立并行，避免全局串行的数据库往返拖慢整轮。
从轮询改成唤醒
09-26 量了一次：推送 p50 0.69 秒，p95 1.56 秒，指标是服务端从拿到日志到推出。拆开看有两块。
一块是 push 每轮之后睡 PUSH_POLL_MS=500，笔记估计平均空等约 0.3 秒。另一块是投递前给未缓存 token 查市场名，p50 433ms、p95 2.7 秒，查询挡在投递前面。短周期市场不断产生新 token，会重复触发这条路径。
09-26，live 写完块后发送 pg_notify，频道是 pmw_blocks，push 用专用连接 LISTEN 唤醒。通知不承载成交数据，数据仍按游标从 ClickHouse 读，丢通知时由 3 秒轮询兜底。发送端 BlockNotifier 合并通知，同时最多一条在途，只记最高块号。当天先限制等待市场名的时间；09-27 才改成只读缓存、未命中后台查询，并按排序键重写查询，提交记录中的单 token 耗时从 343ms 降到约 100ms。
一主一备
09-28 检查部署对推送的影响，单进程重启期间约 16 秒没有推送，还触发了「推送轮询连续失败」告警。onModuleDestroy 没等 poll 完成就关掉 ClickHouse 客户端，正在执行的查询因此失败。
现在 push 分成 a、b 两个进程。备用进程阻塞在 pg_advisory_lock 上等锁，拿到锁才监听端口；Caddy 配两个 upstream、lb_policy first，连不上就切下一个，不需要健康检查轮询。部署先重启备用，再停主；主进程关闭时等当前这一轮 poll 跑完再放锁，最后以 1012 关闭所有 WS 连接。实测滚动重启时客户端 1.2 秒重连，0 漏单。
复审补了关停和换主时的边界处理：超时仍有 poll 在跑时，带锁退出；PUSH_WORKER=0 拒绝启动独立推送服务；认领和游标移动在同一条语句校验 PushEpoch，并对 epoch 行加 FOR SHARE，协调换主与进行中的写入。WS 行不再按超时重领，避免旧成交在新成交之后发送；新主接手时作废前任残留的 WS claim。
一条钉住 xmin 的等锁语句
09-29 发现推送 p50 随进程寿命慢慢爬到 1 秒左右，重启就恢复。拆开看，「开始读到发出」花了 749ms，PG 慢日志里 UPDATE "Subscription" SET "syncedBlock" 平均 387ms。这张表只有 9 行，文件却涨到了约 150MB。
原因就是前一天加的备用进程。它那条阻塞的 pg_advisory_lock 是一条一直没结束的语句，跑了 35 小时，一直持有快照，成了全库唯一的 backend_xmin，vacuum 回收不了任何死行。Subscription 每轮都被 UPDATE，死元组越积越多。
修法是 waitPush 分段等锁：锁会话将 lock_timeout 设为 5 分钟，超时报 55P03，同一会话重新等下一段。段内主进程放锁或崩溃时，PG 仍直接唤醒等待者。集成测试检查等锁期间 xmin 能前进。项目笔记记录，VACUUM FULL 后表从约 150MB 回到 224kB，推送 p50 回到 0.287 秒。
之后再遇到延迟回升，我先按这个顺序拆：用 query_start_time_microseconds 找相邻两次读取的间隔（就是轮询周期）；看 push 日志里有没有 block listener lost（断线退回了轮询）；延迟随进程寿命上涨，就去查 pg_stat_activity 里谁占着 backend_xmin，以及表的死元组数和文件大小。
Postgres 重启演练
10-01 做了 Postgres 重启演练。WriterLocks 丢失会话后以退出码 75 退出；当天 stats 的 pm2 配置也增加了只对 75 自动拉起的处理，其他退出码仍停着等人检查。这不是所有服务统一使用的重启规则。
演练执行 systemctl restart postgresql@16-main，PG 约 3 秒恢复。笔记记录，api、live、names、push-a、daily、stats 退 75，push-b 退 1，均被各自 pm2 配置拉起，32 秒内全部 online。推送中断约 10 秒，核对的 41 个块、20 笔成交没有漏推。/v1/ready 在演练中一直返回 200，但这不等于推送没有中断。
演练之后关闭了自动更新，安全补丁改成人工选择时间安装。同一天 /v1/ready 加了延迟检查：最近 20 分钟区块时间戳到推送的中位数超过 5 秒，返回 503，探针连续两次失败告警。这个健康检查仍用区块时间戳，与看板的「收到区块头 → 推送」口径不同。
pmwallets 工程笔记（5/7）