Skip to content

Event-loop-watchdog self-exit + split-brain under 30–45 MB sessions: proxy disappears mid-request (422 oversize refusal) and two instances commit the same session #5507

New issue
New issue
Open
Open
Event-loop-watchdog self-exit + split-brain under 30–45 MB sessions: proxy disappears mid-request (422 oversize refusal) and two instances commit the same session#5507
Labels
bugSomething isn't workingdshneeds-decisionp2scope/wiring

Description

@zhongyaoli
zhongyaoli
opened on Nov 2, 2026

中文摘要

DSH 会话长到 30–45MB（请求体 5–12MiB）时，bili 主线程压缩卡顿触发看门狗：30 秒告警、300 秒自杀重启；重启空窗期网关对超大请求返回 422（拒绝直发原文），并且两个实例会同时提交同一会话（今日 1069 次）。希望：看门狗可配置/只告警、重活移到 worker、会话库加单写者锁、空窗期短暂等待替代 422。

Summary

billion-context 0.1.211 on macOS, heavy local DSH profile. Sessions grow to 30–45 MB of
history (request bodies 5–12 MiB, largest inbound 43.8 MiB). Under that load three
things happen together:

  1. The main event loop blocks long enough to trip the built-in watchdog
    (soft warn 30 s, hard self-exit 300 s). Those thresholds are hardcoded constants
    (WATCHDOG_SOFT_WARN_MS = 3e4, WATCHDOG_HARD_TIMEOUT_MS = 5 * 6e4) — no env var and no
    config key can raise or disable them.
  2. While the proxy is down for a few seconds, the gate refuses to forward the
    uncompressed body:
    bili_gate_oversize_refusal_fallback — "the bili proxy died and no replacement came
    up, so this body would go to the provider uncompressed — but its core text alone
    (~1,275,883 tok floor estimate from 5,103,529 B / 4) exceeds the model context window
    (1,000,000) ... ([pi] Direct connection fallback after proxy disconnect: no oversized rejection, no self-healing, no visible alerting (al | [pi] 代理失联后的直连兜底无 oversized 拒绝、无自愈、无可见告警（opencode/dsh 都有）—— 1.06M token 原始历史被直接送进上游 #4516)". HTTP 422, turn fails, retry usually succeeds.
  3. Two instances are alive at the same time and both commit the same session.

Evidence (one machine, ~7 h window, bili.log)

  • 44 × listening on http://127.0.0.1:18802 (repeated restarts)
  • 84 × [event-loop-watchdog] main event loop silent for 30–34s (soft threshold 30s) — self-exit after 300s of continuous block (#4762)
  • 36 × shutdown grace window elapsed; forcing exit (liveConns=0) /
    ... but liveConns=4 — extending drain 6/10 (#3890)
  • 1069 × [split-brain] session <id> committed by BOTH this instance (pid ..., http://127.0.0.1:18802, lane dsh, v0.1.211) and another ...
  • [session] evicted session-<id> from resident pool (weight 98141572 bytes, ...)
  • observed inbound bodies: 43.8 MiB, 12.0 MiB, 10.3 MiB, 5.7 MiB
  • Host DSH process restarts (JS heap OOM at ~2.86 GB of a 4.19 GB cap) cause abrupt
    client disconnects; the stale-heartbeat path (dsh lane: parent watchdog false-positives kill healthy proxy; spawner then gives up permanently #4994) then spins up a new instance while
    the old ones linger.

Questions

  1. Would you accept making the event-loop watchdog configurable (e.g.
    BILI_WATCHDOG_SOFT_WARN_MS / BILI_WATCHDOG_HARD_TIMEOUT_MS), or a documented
    "warn only, never self-exit" mode? Here the loop is not hung — it is doing a legitimate
    fold on a very large history, and self-exit turns a slow request into a dead proxy.
  2. Can the heavy fold work move off the main thread (worker thread, or chunked async with
    yielding)? Is better-sqlite3 synchronous I/O the main blocker, and if so is a
    worker-owned DB handle feasible?
  3. Split-brain looks like a data-integrity risk: two instances both committing the same
    session. Is there a single-writer lock on the session store? If not, could the losing
    instance refuse writes instead of both committing?
  4. The oversize refusal ([pi] Direct connection fallback after proxy disconnect: no oversized rejection, no self-healing, no visible alerting (al | [pi] 代理失联后的直连兜底无 oversized 拒绝、无自愈、无可见告警（opencode/dsh 都有）—— 1.06M token 原始历史被直接送进上游 #4516) is right in principle, but it fires during a 1–3 s window
    while a replacement instance boots. Could the gate wait/retry for a replacement for N
    seconds before returning 422?

Reproduction

Heavy multi-session use where several sessions each hold 200k–2M tokens (30 MB+ logs),
plus host restarts. Folding 8–12 MiB bodies then blocks the loop for 30 s+, triggering the
watchdog and the restart loop above.

Activity

  1. ranxianglei commented on Nov 2, 2026

    @ranxianglei
    ranxianglei
    on Nov 2, 2026
    Owner

    🤖 Powered by ework · qwen3.8-27b

    (ai: vllm-qwen/qwen3.8-27b)

    查重: 不重复。 没有 open/closed issue/PR 整体处理这组症状。最接近的线程(机制不同、各有归属):

    标签: bug + dsh + scope/wiring + p2(缺陷类;dsh 车道;主症状在代理生命周期/客户端接线面;大负载下 turn 会失败但重试通常可恢复、有绕行,故 p2 非 p1——若你认为体验已毁到 p1,说一声我改标)。

    已核实(v0.1.211 / 当前 master 代码逐条对过):

    1. watchdog 阈值确实写死:src/event-loop-watchdog.ts:44-45(WATCHDOG_SOFT_WARN_MS = 30_000、WATCHDOG_HARD_TIMEOUT_MS = 5 * 60_000),无 env/config 入口;模块注释明确「thresholds are deliberately hardcoded — a new config/env surface for an internal safety timer is not worth the owner-gated cost」。即放开配置属于 config-surface 决策,按仓库惯例需要 owner 签核(我不会擅自加)。
    2. 422 oversize 拒绝路径确认:src/agent/native-intercept.ts 的 fallbackOversizeRefusal(code bili_gate_oversize_refusal_fallback,retryable:true),文案与你引用的一致。注意:gate 已有等待机制——替换实例正在启动时请求最多等 readyTimeoutMs(默认 15 s)或车道的 spawnWaitMs;BUSY(事件循环饱和但还活着)的 origin 最多等 10 s([Bug?] Under high load, health check timeouts appear to be misinterpreted as "proxy unavailable": large session requests | [Bug?] 高负载下 health 探活超时疑似被当成「代理不可用」：大会话请求被本地拒发（0.1.199 / plugin native） #3654)。你的 422 发生在「proxy 死了且没有替换在途」的状态。
    3. split-brain 检测存在(src/served-markers.ts:184,文案与你日志逐字一致)。它是告警而非静默损坏:last-writer-wins,store 本体在 SQLite WAL 多进程下是安全的(owner 决定 A second process was detected writing to the same index.db — another process (pid 435075) is writing to the database in | 检测到第二个进程在写同一个 index.db 另一个进程（pid 435075）正在写入本会话目录的数据库——两个进程写同一个库会损坏数据（#3923/#3959）。请关闭多余实例：一个会话目录只能由一个实例服务。 #5082)。真正该修的是「为什么两个实例同时活着」——host OOM 重启后的 spawn 纪律,而不是给库加单写者锁(那会破坏支持拓扑)。

    一个证据问题:你贴的日志摘录里有 84 次 soft warn(30–34 s),但没看到 [event-loop-watchdog] FATAL … hard threshold 行——每次硬触发自杀前都会写这条 FATAL 行。如果整份 bili.log 里没有 FATAL 行,那 44 次重启更可能是 host OOM 重启循环驱动的(旧实例 lingering → 新实例接管),而非 watchdog 硬触发;请确认一下日志里有没有 FATAL 行。这影响 Q1/Q4 的归因。

    下一步(按新规约不开新 issue,决策都在本线程走):

    • 把四个机制在 v0.1.211 上核完(dsh 车道 respawn 路径、reconcile 热点路径、drain/shutdown 路径);
    • 然后在本线程发一条 🔶 需要决策 评论,Q1–Q4 各给选项+代价+推荐;
    • 有无决策依赖、可直接修的部分(若有)直接以 PR 交付。
  2. ranxianglei
    added
    bugSomething isn't working
    dsh
    p2
    scope/wiring
    on Nov 2, 2026

  3. ranxianglei commented on Nov 2, 2026

    @ranxianglei
    ranxianglei
    on Nov 2, 2026
    Owner

    🤖 Powered by ework · qwen3.8-27b

    (ai: vllm-qwen/qwen3.8-27b)

    无需决策的部分已交付:PR #5510(Q4 的真实缺口);其余需要你拍板,见下一条 🔶 需要决策 评论。

    标签: bug, dsh, scope/wiring, p2(大会话下可用但存在失败窗口,重试可恢复)

    是什么问题: 30–45MB 大会话时,代理重启空窗期(几秒)内模型请求被 422 拒收(bili_gate_oversize_refusal_fallback)或直发原文。根层:dsh/omp/opencode 三条车道在"替代实例还在冷启动"期间只肯等 15 秒,而它们自己批准的冷启动预算是 60 秒——等不及就提前降级。看门狗自杀与双实例同写是另外两层机制(见下)。

    什么原因导致的(分层):

    影响范围与严重程度: p2。能用、重试通常成功(你观察到 retry 成功),但"大会话 + 慢冷启动"组合下每次交接都有失败窗口;影响 dsh/omp/opencode 自启动代理的车道。

    怎么修复的: PR #5510 —— 四条车道每个"launcher 真正起进程"的转换点(plan-time spawn、attach→spawn 回退尾、dsh 自愈重 spawn)统一装上与 pi 相同的等待预算 SPAWN_BUDGET_MS + 10s;健康 attach / off 开关 / inline 模式一律不装(负向测试钉住,#3617 双向纪律)。新增 tests/issue5507-lane-respawn-hold.test.ts(8 用例全绿)+ 触碰车道既有套件 131 全绿 + typecheck 干净。

    是否有回归问题: 审过的既有行为:① 退化路径等待预算 15s→70s(最坏总等待 30s→85s,含 15s 就绪上限)——有意的车道对齐,非漂移;② 健康 attach、off 开关、inline 模式行为不变(负向测试钉住);③ 无 wire/协议/配置面/kernel 变更。全量回归以 CI 为准。

    是否破坏缓存: 不涉及(不动缓存/增量游标/去重键)。

    是否改了设计方向: 不涉及——把 dsh/omp/opencode 对齐到 pi 既有的 #4516 设计,消除车道间分歧。

    是否引入了新的配置: 没有(复用既有 BILI_SPAWN_WAIT_MS / BILI_SLOW_START_GRACE_MS 预算)。

    对你四个问题的处置:

    判定: PR #5510 待 CI 绿即可合(Q4 止血闭环);Q1/Q2/Q3 与 Q4 剩余语义等你拍板。

  4. ranxianglei commented on Nov 2, 2026

    @ranxianglei
    ranxianglei
    on Nov 2, 2026
    Owner

    🤖 Powered by ework · qwen3.8-27b

    🔶 需要决策
    (ai: vllm-qwen/qwen3.8-27b)

    背景一句话: 本 issue 四个问题中,Q4 的无决策部分已由 PR #5510 闭环;看门狗行为、大会话折叠的主线程开销、会话库写入拓扑这三件事需要你拍板。

    D1 — 事件循环看门狗:阈值可否配置 / 能否只告警不自杀(对应 Q1)

    D2 — 大会话折叠的重活是否移出主线程(对应 Q2)

    • A: 先定向 profiling(合成 30–45MB fixture 或在你机器上打点)定位阻塞主因,再沿该路径做分块异步让出(yield-loop.ts 已有先例)。代价: 一轮 profiling 时间;改动小、风险低、可增量合入。
    • B: 直接整体迁 worker 线程(worker 持有 DB handle)。代价: 架构级改动、周期长;且 kernel 在 plugin 模式跑在宿主进程里,proxy 侧迁移不解决宿主侧 OOM([PR] fix(native): refuse oversized direct model requests (#5405) #5406)那一半。
      推荐: A。不决定的默认行为: 不做,维持现状。

    D3 — 会话库要不要加单写者锁(对应 Q3)

    D4 — gate 剩余语义(对应 Q4 超出本 PR 的部分)

    已把 needs-decision 标签打到本 issue。D1 的前置是 #5450 合入;四项都不阻塞 PR #5510 的合并。

  5. ranxianglei
    added
    needs-decision
    on Nov 2, 2026
  6. ranxianglei
    added a commit that references this issue on Nov 2, 2026

    fix(agent): honor armed spawn-wait hold in opencode V2 resolver (#5507)

    045a298

  7. WardLu commented on Nov 10, 2026

    @WardLu
    WardLu
    on Nov 10, 2026

    Adding a matching reproduction on 0.1.213 (newer than the versions above), same signature: event-loop-watchdog self-exit → proxy disappears mid-request → 422 oversize refusal.

    Environment

    • billion-context 0.1.213, macOS, Node 22.23.4, dsh lane, proxy on 127.0.0.1:<port> (localhost only).

    Symptom — two consecutive failed turns, each HTTP 422:

    422 {"type":"server_error","code":"bili_gate_oversize_refusal_fallback",
"message":"billion-context refused this request locally: the bili proxy died and no
replacement came up, so this body would go to the provider uncompressed — but its core
text alone (~2,260,371 tok floor estimate from 9,041,481 B / 4) exceeds the model context
window (1,000,000); ... (#4516).","retryable":true}

    Second retry had grown to ~2,320,959 tok (9,283,836 B / 4) — identical refusal. Retries re-send the same ~9 MB history and can never succeed while the proxy stays down.

    Preceding evidence (redacted log lines):

    slow-session: 6008 msgs / inbound=20.5MiB took local=172990ms — synchronous per-turn
  work is starving the event loop (#4528/#5744); consider closing/restarting the session
  or enabling compression

[event-loop-watchdog] main event loop silent for 34s (soft threshold 30s) — self-exit
  after 300s of continuous block (#4762)

[watchdog] heartbeat stale for pid <pid> (177034ms since last beat, pid still reads
  alive) — requiring 5 consecutive stale ticks before believing it (#4994)

[native-attach] keep http://127.0.0.1:<port> (pid <pid>): health probe failed but TCP
  connect succeeded — instance is BUSY (event loop saturated), not dead (#3654/#4811)

    Store stats: offending single-session transcript ~16 MB; sessions/index.db ~241 MB.

    Workaround that recovered it: do not resume the oversized session (start a fresh one); enable compression; trim/rotate index.db.

    Related: #4516 (oversize local refusal, closed), #4528 / #5744 (slow-session event-loop starvation, closed), #4762 (watchdog/port zombie, closed), #4994 / #3654 / #4811 (busy-vs-dead health-probe). Same watchdog-self-exit path as this issue, just at ~20.5 MiB inbound rather than 30–45 MB.

  8. ranxianglei
    added 2 commits that reference this issue on Nov 10, 2026

    fix(agent): hold in-flight launcher respawns under the spawn budget i…

    b8f8c8a

    fix(agent): honor armed spawn-wait hold in opencode V2 resolver (#5507)

    ddc0025

  9. ranxianglei commented on Nov 10, 2026

    @ranxianglei
    ranxianglei
    on Nov 10, 2026
    Owner

    🤖 Powered by ework · qwen3.8-27b

    (ai: vllm-qwen/qwen3.8-27b)

    Thanks @WardLu — this is valuable confirmation data. What it establishes, and one question back:

    1. Version confirmation. Your repro runs on 0.1.213, which is the current release line (the v0.1.213 tag is an ancestor of today's master). So the 422 facet persists in every released version so far — consistent with our triage conclusion that nothing shipped yet addresses it.

    2. Your log quantifies the main-thread mechanism (our Q2/D2). The line
    slow-session: 6008 msgs / inbound=20.5MiB took local=172990ms (emitted at src/server.ts:4784) is 173 seconds of synchronous per-turn work on the proxy's main event loop. One such turn alone already crosses the 30 s soft-warn threshold; two consecutive turns (~346 s) would cross the 300 s hard threshold. That is exactly the "legitimate O(full-history) fold blocking the loop" path we flagged — not a hang, not DB I/O, but CPU-bound pipeline passes over multi-MiB histories. This is the strongest quantitative evidence for decision item D2 (move heavy fold work off the main thread) posted earlier in this thread.

    3. One mechanism nuance, stated honestly. Your refusal wording — "the bili proxy died and no replacement came up" — is produced when the per-request resolver classifies the held origin as dead (or the send itself failed). The BUSY line you quoted ([native-attach] keep … instance is BUSY, src/launcher.ts:4257) comes from a different, host-side launcher probe that correctly kept the saturated instance instead of respawning into a twin (#3044). Both can be true at once: under a 173 s saturation the per-request liveness probe (1.5 s health budget) can classify the origin as dead even though the process is merely loop-saturated. Which micro-path actually produced your two 422s determines how much of your window the open fix covers (next point).

    4. Fix status. PR #5510 fixes the dsh-lane hold-budget gap: a request racing an in-flight launcher respawn now holds out under the launcher's own bring-up budget (60 s + margin) instead of degrading at the generic 15 s readiness cap (pi had this since #4516; dsh/omp/opencode did not). It has been open since Nov 2 and sat conflicted while master advanced ~45 commits; I just rebased it onto the current master tip (4dea18eab) — single positional conflict, resolved by union, typecheck clean, all touched-lane suites green locally (146/146) — and pushed (5faa385dd9). It awaits CI plus a human merge. Coverage of your case: full if your 422s fired during a respawn window; if they fired purely from busy-origin exhaustion with no respawn in flight, that residual belongs to decision item D4 (gate semantics beyond parity) and is not covered by the parity fix.

    5. One detail that would pin the micro-path (if you still have the log): the bili-native: liveness: lines around each 422 timestamp — specifically whether they say dead (…), BUSY (…), or still busy after N re-probe(s) — plus any proxy not ready — waiting up to Xs line. That tells us which of the two paths above fired.

    Your workaround matches our read exactly (fresh session + enable compression + trim index.db), and your observation that retries cannot succeed while the proxy stays down is correct — retryable: true only helps once a live compressed path exists again. No new issue opened for this — same thread, same failure family. Decision items D1–D4 remain pending the owner's ruling.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't workingdshneeds-decisionp2scope/wiring

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions