Skip to content

fix(stream): ask the backend before killing a slow local request (progress-aware watchdog for W2) - #278

Merged
OmarB97 merged 1 commit into
mainfrom
feat/w2-progress-aware-stream-watchdog
Jul 14, 2026
Merged

OmarB97 merged 1 commit into
mainfrom
feat/w2-progress-aware-stream-watchdog

Conversation

@OmarB97

@OmarB97 OmarB97 commented Jul 14, 2026

Copy link
Copy Markdown
Owner

The bug

Hermes killed a healthy 90.7k-token turn on deepseek-v4-flash-w2 at 240s, while vLLM was still prefilling it:

API call failed after 1 retries: Local dflash stream produced no first chunk after 240s (threshold: 240s)
Fallback policy any: deepseek-v4-flash-w2 via ai-router failed (reason: timeout); no usable configured fallback remained.

Two defects, one root cause: the watchdog was a blind stopwatch.

Defect 1 — the budget was an uncalibrated step ladder

est_tokens > 100_000 -> 300.0
est_tokens >  50_000 -> 240.0     # <- 90.7k landed here
else                 -> 180.0
  • Discontinuous. 99,999 tokens got 240s; 100,001 got 300s.
  • Capped at 300s with no headroom above 100k.
  • Calibrated against nothing. Those numbers correspond to no measurement of any backend.
  • Its 180s floor did not even clear a cold model load. Measured on taro: a llama-swap W2 load takes 138.5s for a 4-token prompt, before any prefill. llama-swap evicts W2 whenever another model is requested on the same GPU, so the very next W2 turn pays that load and re-prefills the whole context (the eviction wipes the KV cache). The old floor left ~40s for everything else.

Now continuous, and never narrower than the ladder it replaces:

budget = cold_start_allowance + base + per_1k * (tokens / 1000)   [clamped to a ceiling]
tokens old new
10,000 180s 400s
50,000 180s 560s
90,700 240s 723s
131,072 300s 884s

Defect 2 — the real one: it never asked

A stopwatch cannot distinguish "the server is wedged" from "the server is healthily prefilling 90k tokens." So it guesses, and at some context size it always guesses wrong.

It no longer has to guess. ai-gate proxies every generation request to llama-swap, which makes it the one component that knows the truth, and it already exposes it:

GET /_gate/status
{ "active_generation_count": 1,
  "active_generations": [{"id","model","path","client_host","started_at","age_s"}] }

When the no-first-chunk budget expires, the watchdog now asks the backend whether it is still working. If it is, the request is extended and the wait is surfaced to the user (⏳ Still prefilling ~90,700 tokens (312s elapsed). The server reports it is working — waiting.) instead of dying silently. Only a genuinely idle backend — or the absolute ceiling — ends the request.

This is what makes it hold up as contexts grow: it is no longer a prediction.

Note a deliberate subtlety: if the gate reports a generation for a different model, we still treat the backend as busy. On a single-GPU llama-swap host that means our model was evicted and is being swapped back in — precisely when patience is required.

Why there is no fitted TTFT curve in this diff

I measured, and the honest answer is that a single constant would be fiction:

  • Prefix-cached (the normal agentic case — each turn appends to an already-cached conversation): 18.8s @ 4k, 87.5s @ 32k, then flat ~100s at 64k/96k/128k. TTFT stops growing because vLLM serves the shared prefix from KV cache. This is why W2 feels fast turn-to-turn.
  • Uncached (after an eviction wipes the cache): the same 4k prompt with unique content took 62.6s — 3.3× the cached figure.

The cost of a healthy request spans more than an order of magnitude depending on cache state, and nothing client-side can know which regime a given turn is in. That is the argument for liveness over prediction, and the budget is now just a safety net for backends that expose no signal.

Evidence

$ python3 -m pytest tests/agent/test_local_stream_timeout.py -q
95 passed in 3.27s

$ python3 -m pytest tests/agent/ -q -k "stream or timeout or interrupt or chat_completion or watchdog"
509 passed, 5079 deselected

Mutation checks — neither new guard is vacuous:

# restore the old step ladder:
FAILED ... test_budget_clears_a_cold_model_load_at_every_context

# remove the progress-aware extension (kill without asking):
FAILED ... test_busy_backend_extends_instead_of_killing

Backwards compatibility

  • Every existing override still wins: HERMES_DFLASH_FIRST_CHUNK_TIMEOUT, HERMES_DFLASH_TTFB_TIMEOUT, config.yaml provider/model timeouts. An operator who pinned a number still gets that number.
  • Providers without a gate are untouched. The probe returns None on any error, non-200, missing endpoint, or unexpected body shape — never False — so a remote API or bare llama.cpp server keeps the legacy stopwatch exactly as before. There is a test for this.
  • New knobs (all optional): HERMES_DFLASH_PREFILL_SECONDS_PER_1K, HERMES_DFLASH_COLD_START_ALLOWANCE, HERMES_DFLASH_FIRST_CHUNK_CEILING, HERMES_GATE_PROBE_TIMEOUT.
  • The watchdog still bounds the worst case: the ceiling (default 1800s) is measured on a non-resettable clock, so a backend that lies about being busy cannot park a request forever.

Risks / gaps

  • The probe adds one short HTTP GET per expired budget window (default 4s timeout), not per poll. Negligible, and only on local endpoints.
  • This does not make W2 faster. It stops Hermes from killing it. Making large-context turns genuinely quicker is a serving-side question (expert cache sizing, KV dtype), out of scope here.
  • The fallback policy is still willing to fall back to another local model, which on a single-GPU llama-swap host would evict W2 and make recovery strictly worse. Not addressed in this PR; worth a follow-up.

Hermes killed a healthy 90.7k-token W2 turn at 240s while vLLM was still
prefilling it. Two defects, one root cause: the watchdog was a blind stopwatch.

1. The budget was a hardcoded step ladder (>100k -> 300s, >50k -> 240s, else
   180s). Discontinuous (99,999 tokens got 240s, 100,001 got 300s), capped at
   300s with no headroom, and calibrated against nothing. Its 180s floor did not
   even clear a MEASURED 138.5s llama-swap cold load, so the first turn after any
   model eviction was killed while healthy. Replaced with a continuous budget:
   cold_start_allowance + base + per_1k * tokens, clamped to a ceiling, and never
   narrower than the ladder it replaces.

2. More fundamentally, a stopwatch cannot tell a wedged server from one that is
   healthily prefilling 90k tokens. It now ASKS: ai-gate proxies every generation
   to llama-swap, so /_gate/status knows what is actually in flight. If the
   backend reports an active generation, the watchdog extends and surfaces
   progress instead of killing; only a genuinely idle backend, or the absolute
   ceiling, ends the request.

Measurement is deliberately not encoded as a curve: TTFT spans an order of
magnitude with prefix-cache state (18.8s vs 62.6s for the same 4k prompt, cached
vs unique), which is exactly why liveness beats prediction here.

Providers without a gate are unaffected: the probe returns None on any error,
non-200, or unexpected shape, and the legacy stopwatch applies unchanged.

Co-Authored-By: Claude Code <noreply@anthropic.com>
@OmarB97
OmarB97 merged commit 0d45b04 into main Jul 14, 2026
1 check failed
OmarB97 pushed a commit that referenced this pull request Jul 14, 2026
…ntime path

Two gaps, both found by reading the live log of a real 79.8k-token turn, which
reported "budget 240s" when the cost model says ~679s.

1. resolve_dflash_local_first_chunk_timeout -- the RUNTIME resolver -- never
   called _dflash_context_timeout_default. It fell straight through to the stale
   ladder (>50k -> 240s, >100k -> 300s). Only the legacy
   _dflash_local_first_chunk_timeout helper reached the cost model, and nothing
   on the hot path calls that. So the budget added in #278 was dead code: the
   step function that corresponds to no measurement of anything kept winning.

   Only the progress-probe half of #278 was actually live, which is why W2 still
   worked -- the watchdog extended on the gate's liveness signal rather than on a
   correct budget.

2. _is_managed_local_w2_route did not list "ai-router" -- the ko-nas fleet router
   the desktop actually routes through. It proxies to taro's ai-gate and on to the
   same llama-swap/vLLM, so it is the same physical lane with the same slow cold
   prefill, but it fell through to the generic DFlash ladder and never got even
   the 360s W2 floor.

Scope is deliberately the measured lane only. The context budget is calibrated on
ONE setup (W2 behind llama-swap on taro); applying its cold-start allowance to an
arbitrary local DFlash provider would inflate that provider's deadline on the
strength of a measurement that says nothing about it. Generic routes keep the
existing policy byte-for-byte -- and the allowlist stays an allowlist rather than
"any local endpoint serving W2", which the existing
test_managed_local_w2_timeout_floor_is_route_and_model_specific pins on purpose.

Budgets on the managed W2 lane, no config/env override:
    tokens      old     new
    50,000      180     560
    79,800      240     679
    90,700      240     723
   131,072      300     884
Generic LAN DFlash routes: unchanged (180/240/300).

Explicit config.yaml and env overrides still win -- both return earlier. The
budget is now rounded to whole seconds; a deadline carrying 360.036s was noise.

Co-Authored-By: Claude Code <noreply@anthropic.com>
OmarB97 added a commit that referenced this pull request Jul 20, 2026
Hermes killed a healthy 90.7k-token W2 turn at 240s while vLLM was still
prefilling it. Two defects, one root cause: the watchdog was a blind stopwatch.

1. The budget was a hardcoded step ladder (>100k -> 300s, >50k -> 240s, else
   180s). Discontinuous (99,999 tokens got 240s, 100,001 got 300s), capped at
   300s with no headroom, and calibrated against nothing. Its 180s floor did not
   even clear a MEASURED 138.5s llama-swap cold load, so the first turn after any
   model eviction was killed while healthy. Replaced with a continuous budget:
   cold_start_allowance + base + per_1k * tokens, clamped to a ceiling, and never
   narrower than the ladder it replaces.

2. More fundamentally, a stopwatch cannot tell a wedged server from one that is
   healthily prefilling 90k tokens. It now ASKS: ai-gate proxies every generation
   to llama-swap, so /_gate/status knows what is actually in flight. If the
   backend reports an active generation, the watchdog extends and surfaces
   progress instead of killing; only a genuinely idle backend, or the absolute
   ceiling, ends the request.

Measurement is deliberately not encoded as a curve: TTFT spans an order of
magnitude with prefix-cache state (18.8s vs 62.6s for the same 4k prompt, cached
vs unique), which is exactly why liveness beats prediction here.

Providers without a gate are unaffected: the probe returns None on any error,
non-200, or unexpected shape, and the legacy stopwatch applies unchanged.

Co-authored-by: Omar Baradei <omar@kostudios.io>
Co-authored-by: Claude Code <noreply@anthropic.com>
OmarB97 added a commit that referenced this pull request Aug 2, 2026
…promises (#338)

`agent.local_stream_stale_timeout` (default 900) and its env twin
`HERMES_LOCAL_STREAM_STALE_TIMEOUT` were read by no code. A whole-tree grep
found exactly four references: the default in DEFAULT_CONFIG, the docs row, and
a test whose NAME mentions the knob but which asserted `float("inf")` — pinning
the absence of the ceiling.

The reader was dropped by #263 (d8aced7), which replaced the inline
`load_config()` + `env_float("HERMES_LOCAL_STREAM_STALE_TIMEOUT", ...)` block
with `resolve_stream_stale_timeout()` and never reinstated it. That commit
touched only agent/, run_agent.py and tests — the config default and the docs
row were left behind, still promising a bound that no longer existed. So every
generic (non-DFlash) local endpoint got `float("inf")`: exactly the infinite
disable the 900s default was introduced to replace.

A knob that is defaulted, documented, and inert is worse than no knob. This one
misdirected a root-cause investigation into deep-context turn timeouts on a
local lane, because the operator and the investigator both reasonably believed
a 900s ceiling was in force. The runtime cost is worse than a stale doc: with
the threshold at inf, `_stale_elapsed > _stream_stale_timeout` can never be
true, so the poll loop's stale branch is unreachable for a generic local
endpoint. A crashed or deadlocked local server that keeps the socket alive with
SSE pings parks the session forever — no reconnect, no fallback, no error.

`resolve_stream_stale_timeout` now resolves the ceiling instead of returning
inf: `HERMES_LOCAL_STREAM_STALE_TIMEOUT` (the documented escape hatch), then
`agent.local_stream_stale_timeout` (canonical), then 900s. Non-positive
disables the watchdog, so an unbounded wait stays reachable as a deliberate
choice for an exotically slow local model. A `providers.<id>.stale_timeout_seconds`
or an explicit `HERMES_STREAM_STALE_TIMEOUT` still wins outright, and the local
DeepSeek Flash family keeps its own tighter budget — this branch is reached
only when nothing more specific is set.

The ceiling is then widened — never narrowed — by the request's context-scaled
prefill cost, reusing `_dflash_prefill_scaled_timeout`. That helper is already
the portable half of the DFlash budget: the per-1k prefill term is arithmetic
(a bigger prompt takes proportionally longer on any backend), while the
cold-start allowance stays gated to the lane it was measured on. A FLAT
deadline is precisely how the old ladder killed healthy prefills mid-flight
(#278, #334: 240s at ~95k tokens, 240s at ~89k, 180s at ~33k, on a server that
was still working); trading "hangs forever" for "kills work that was fine"
would be the worse of the two. The same HERMES_DFLASH_FIRST_CHUNK_CEILING
(1800s) caps the result, so a wedged endpoint stays bounded at any prompt size.

Behavior change, stated plainly: a previously unbounded wedged local server now
trips at 900s + 4s/1k of prompt. The risk in the other direction is that this
path has no liveness probe (`_local_backend_generation_active` stays on the
DFlash first-chunk branch), so a healthy-but-very-slow generic local server
that exceeds the scaled ceiling is reconnected rather than waited out. The
mitigations are the generous base (5x the DFlash family's), the context
scaling, and a one-line escape hatch. Extending the probe to this branch is a
separate behavior change from wiring the knob.

test_generic_local_stream_stale_timeout_still_disables_by_default asserted inf.
That assertion pinned the regression, not the design — the config default and
the docs both describe a finite ceiling and #263 changed neither. Rewritten as
..._is_bounded_but_looser (900s, with the DFlash family's 180s asserted
alongside it on the same endpoint so the contrast is explicit).

TestGenericLocalStreamStaleCeiling resolves through the real config loader and
a real AIAgent: DEFAULT_CONFIG default, config.yaml value, env override,
unparseable env falling through to config rather than counting as an override,
0/negative disabling, context scaling (1260s at 90k, 904s at 1k), the 1800s
clamp at 400k, and explicit stale-timeout settings still winning.

TestGenericLocalStaleWatchdogActuallyFires drives the real poll loop in
`interruptible_streaming_api_call` against an endpoint that accepts the request
and never sends a chunk: the kill fires at 960s and counts toward the
cross-turn give-up breaker, and with the ceiling disabled 1200s of silence
produces no kill at all — the escape hatch, and a record of the pre-fix
behavior.

Two test-local mirrors of this resolution still said local means inf. The one
in test_stream_read_timeout_floor.py is exercised, so its local case now
asserts 900s — which makes it stronger, since it proves the local read-timeout
branch wins outright even when the stale value is finite. The one in
test_reasoning_stale_timeout_floor.py is never called with a local URL, so it
now raises instead of carrying a second, drifting copy of the rule.

Docs: HERMES_STREAM_RETRIES was documented as defaulting to 3; the code default
is 2, which yields 3 total attempts (corrected in the EN and zh-Hans env-var
tables and in the tips corpus). Three surfaces still said stale-stream
detection is "disabled entirely" for local providers — the
HERMES_STREAM_STALE_TIMEOUT row, the API-timeouts table and prose in
user-guide/configuration.md, and the table in guides/local-llm-on-mac.md — all
corrected to describe the ceiling, the scaling, and the 0 disable. Added the
knob to cli-config.yaml.example and expanded its DEFAULT_CONFIG comment, since
config.yaml is the canonical surface and the env var is the escape hatch.

Co-authored-by: Omar Baradei <omar@kostudios.io>
Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
OmarB97 added a commit that referenced this pull request Aug 2, 2026
…343)

The stale-stream watchdog in `interruptible_streaming_api_call` killed a
local connection on a stopwatch alone. The no-first-chunk branch a few
lines above it has asked the server since #278 —
`_local_backend_generation_active()` reads `/_gate/status`, and a backend
reporting an in-flight generation gets its deadline extended instead of
its socket closed — but the stale branch, the one that actually kills a
generic local stream, never asked.

That asymmetry was harmless while generic local endpoints resolved to
`inf`: the branch could not fire for them, so there was nothing to ask
about. #338 gave them a finite 900s ceiling, which is what makes the
question live. A healthy-but-slow local server that overruns it now has
its socket killed and reconnected, throwing away the prefill it already
paid for — the first step of a kill -> re-prefill -> kill spiral.

Probe in the shared stale branch for any local endpoint rather than only
the generic one, so a DFlash mid-stream stall is judged the same way its
pre-first-chunk wait already is. Extensions are bounded by the same
`HERMES_DFLASH_FIRST_CHUNK_CEILING` the first-chunk path uses, applied to
one silent stretch rather than to total request time, and are reset the
moment a chunk lands so they cannot accumulate across stalls. The probe
still returns None for any endpoint without a gate, so a bare Ollama or
llama.cpp is decided by the timer exactly as before and a remote API is
never asked at all.

Co-authored-by: Omar Baradei <omar@kostudios.io>
Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
OmarB97 added a commit that referenced this pull request Aug 2, 2026
…ll (#347)

`interruptible_api_call`'s stale detector was the last watchdog in this
file still deciding on a stopwatch alone. Both streaming ones already ask
`_local_backend_generation_active()` — the DFlash pre-first-chunk wait
since #278, the shared stale-stream branch since #343 — and a backend
reporting an in-flight generation gets its deadline extended instead of
its socket closed. The non-streaming kill never asked.

It matters more here than in either streaming branch. A stream killed
mid-generation has at least delivered the chunks it already produced; a
non-streaming call delivers nothing until it delivers everything, so the
kill throws away the whole prefill AND the whole generation and the retry
restarts from zero — the kill -> re-prefill -> kill spiral with nothing
salvaged.

The reachable population is narrower than the streaming case, and
deliberately so: a generic local endpoint left on the implicit default
resolves to `inf` in `_compute_non_stream_stale_timeout`, so the branch
cannot fire for it and there is nothing to ask about. Three
configurations do reach it:

  * a local DFlash model (~180s + context scaling);
  * a local model in the reasoning-floor allowlist — deepseek-r1, qwq,
    qwen3, nemotron-3, the o-series — at 300-600s. This one is the least
    obvious: the model is not DFlash, so it looks like the generic local
    case, but the floor returns uses_implicit_default=False, and that
    flag is exactly what the `inf` short-circuit tests;
  * any endpoint where the operator pinned `stale_timeout_seconds` or
    `HERMES_API_CALL_STALE_TIMEOUT`.

Probe in the stale branch for any local endpoint, mirroring the shape
#343 established. Extensions are bounded by the same
`HERMES_DFLASH_FIRST_CHUNK_CEILING`, measured over the current silent
stretch — which for a non-streaming call is the whole request, the same
span the pre-first-chunk streaming branch bounds, and the reason no reset
is needed here (there is no chunk that can end a stretch). An
operator-pinned threshold above the ceiling is honoured unchanged: the
guard is already false the first time the branch fires, so the probe
never runs and never shortens a deadline. The probe still returns None
for any endpoint without a gate, so a bare Ollama or llama.cpp is decided
by the timer exactly as before and a remote API is never asked at all.
The `_codex_silent_hang_hint` messaging on the kill path is untouched.

The docs claimed the non-stream detector is simply "auto-disabled for
local providers"; the two local families that keep a finite budget are
now named alongside the probe.

Co-authored-by: Omar Baradei <omar@kostudios.io>
Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant