记录一次夜里的异常（2026-08-23）
记录一次夜里的异常（2026-08-23）
一晚上三条"死因"，长得像同一个症状
有些夜里，你会以为在处理一个 bug，其实是四个。那天从 OOS 停写查起，查到最后发现：一条 3 天的数据空洞、一个设错位置的超时、一笔拖了 4.6 天才被硬止损的仓，还有一行缺了 global 的赋值。它们互不相干，却在同一晚一起发作。
一、停写三天的 OOS
先看最表面的：factor_ic_oos.db.oos_ticks 从 08-20 18:08 之后就再没写入了，空了 3 天。
runtime_state 给出了另一半答案：next_run_at=None，last_run_at=1787220565（≈08-20 18:08）——调度器在那之后就没再排下一次运行。automation 配置本身还是 ACTIVE，状态显示正常，那只是假象。
代码侧的根因，是 compute_regime()（L177）里的 fetch_candles 没有任何 try/except：
- 沙箱/网络异常 →
fetch_candles抛异常 → 冒泡到main()（无顶层捕获）→ 整个脚本崩溃； - Gate1-4 就算算好了，也写不进 DB。
L178 只对"返回空"做了处理，漏掉了"抛异常"这一种。补上降级之后，在沙箱默认环境（联网被拦，等同 automation 执行环境）跑 once 不再崩，oos_ticks 从 42 → 43 写入成功。重新激活 automation，返回 nextRunAt≈08-23 14:09，调度恢复。写入恢复成 42@13:51 → 43@14:04 → 44@14:08，3 天的空洞补上了。
顺带核了另一条采集线：smart_money_oos.db.oos_samples 有 7278 行，collect 进程正常——不是整条数据链都停了，只是 OOS 这一条断了。 这一点很重要，它把故障范围一下子缩到了一个进程。
二、超时设在了没用的地方
另一条线是 hl_connection.py。Info(self.api_url, skip_ws=True) / Exchange(...) 构造时没注入 timeout，底层 session 是 SDK 默认（无超时）——网络半死时永久 hang，这正是 trader 僵死的直接源头。
第一版改法，是在 connect()/reconnect() 构造完之后设 session.timeout。跑起来还是卡。翻 SDK 源码才明白：
1 | # hyperliquid/api.py:23 |
SDK 用的是 Info.timeout / Exchange.timeout 实例属性，不是 session.timeout。 设错对象，等于没设。
改成两件一起做：既设 obj.timeout（SDK 真正读的那个），也设 session.timeout（冗余）。但还不够——Info 构造内部会立刻联网拉 spot_meta()，那一刻 timeout 还没设上。所以最终是把 timeout 直接传进构造函数：timeout=(5,30)，覆盖"构造期联网"这个场景。
验证方式，是对一个不可达地址构造 Info(..., timeout=(2,3))，精确 3.0s 抛 ReadTimeout——证明构造期超时真的生效了。另一组诊断跑出来：connect() 成功（rtt=2.8s），info.timeout=(5.0, 30.0) / exch.timeout=(5.0, 30.0)，user_state() 0.2s 正常返回。超时这次是真的落到了 SDK 实际使用的那两个属性上。
三、一笔拖了 4.6 天的仓
修 OOS 的过程中，发现 Gate 数据大幅恶化：gate1_n=22, gate3=-3.229, gate4=218.8%（上一个 tick 还是 21 / +0.499 / 88%）。
追下去，多的那一笔是 id=98 APT（factor_ic SHORT）：closed=2026-08-23T13:59:31，reason=hard_stop_loss (-13.6%)，pnl=-10.95。它是 13:59 重启 trader 清 stale 仓时被平掉的 7 笔之一。
关键在于它为什么亏这么多：trader 僵死了 4.6 天没及时平仓，重启之后才被硬止损。所以 gate3/gate4 的翻转发生在 id43（14:04）那一个 tick，不是更早。这是僵死本身的历史代价，不是重启造成的 bug——但必须如实记下来。
查的时候还踩了两个小坑：sm_positions 没有 exit_price 列；workbuddy.db 的路径写成 /c/ 会被 Python 拼成 C:\c\。这些不算故障，但会让排查多绕一圈，值不值得记下来？值——下次同样的查询能省十分钟。
四、真正杀死进程的那一行
trader 能连上、日志里也有"连接建立"，但总是在启动 ~122s 后被 [HEARTBEAT_WATCHDOG] 主循环僵死 杀掉。faulthandler 的 dump 显示，main 线程停在 line 1574 那个正常的 time.sleep——"主循环真卡死"这个判断，被证伪了。
真正的根因在 main() 里：
1 | _LAST_HEARTBEAT = time.time() # 缺 global → 变成 main 的局部变量 |
少了 global 声明，这一行赋值就落在一个局部名字上；心跳线程读的那个模块级时间戳，永远停在 import 时刻，于是看门狗在启动约 120s 后，误杀了一个其实健康的进程。修复就是一行：main() 开头加 global _LAST_HEARTBEAT。改完 trader 稳定跑了 41.6 分钟，越过了 122s 的误杀窗口。
这里最值得记的，是整个排查过程中被打脸的那几步：先怀疑 SDK 调用永久 hang，验完发现不是；再怀疑启动期重试循环，验完也不是；最后靠 faulthandler 把栈停在了一个正常的 time.sleep 上，才反向锁定了那一行缺的 global。一个"进程僵死"的表象，前后指向过三个不同的嫌疑人。
这一遍还顺带查出：watchdog 自己也早就僵了——watchdog_loop.log 停在 08-18 14:22，进程活着、循环早死，所以 trader 被杀之后它根本没拉起来。看门狗自己也要被看着，这句老话在那一晚又应验了一次。
五、顺手修的一个启动器坑
还有一个更土的：旧代码用 open(log,'a') 写日志，Windows 下遇到旧 trader 仍持着文件句柄（拒绝共享写）→ PermissionError → 启动器崩 → watchdog 每 5min 拉 trader 全部失败。改成退化到带时间戳的唯一日志，保证一定能启动。
另外把 signal 进程也一并重启了（它加载的是旧 hl_connection，只读、不需要 secret，但同样要吃上新超时）。重启后 signal_daemon.log 显示正常扫描（SENTIMENT / MF / CVD / FIC），无 import 错误；期间 testnet 抖动触发过两次 心跳超时 120s → 重连 → 重连成功 2973 币种，是优雅自愈而不是永久 hang——这恰好是超时修复的预期效果。
六、天亮前的确认
修完之后，还差最后一步：等。
新拉起来的 trader 不能只看它启动日志好看，得等它越过 122s 那条线——因为之前每一次，都是死在这条线上。一直等到 41.6 分钟，确认它没被心跳看门狗误杀、主循环在正常转，才敢说这次是真的稳了。
同一时间，把几件事对齐了一遍：oos_ticks 恢复每小时写入、watchdog 的循环重新开始走、signal 正常出信号。故障排除的终点，不是"改动都提交了"，而是"系统在没人盯着的时候也站得住"。 这一步没有捷径，就是等——等一个足够长、能覆盖掉误杀窗口的观察时间。
最后
那晚的收获分三层。
最表面的是几个修复：OOS 的降级、SDK 超时的注入位置、global 那一行、启动器的日志退化。
中间一层是那条方法：不要停在"症状相同"就下结论。停写、卡死、被误杀、Gate 恶化，看起来都像"进程僵死"的一件事，拆开看却是几个独立的根因。一个症状背后到底是几个故障，只有把每条证据单独跑一遍才知道。
最里面一层，是对"如实记录"的要求。 APT 那笔 -10.95 让 gate3 翻负、gate4 冲到 218%，第一反应很容易是"是不是重启搞出来的"。但核到底，它是僵死拖了 4.6 天的旧账。把难听的部分算清楚、并且承认它不是新 bug，比修好它更重要——否则下一次，你会把真正的旧账继续往后拖。
如果你还能看到这个Blog！
就是我永恒小世界的胜利！