Beat extraction silently loses whole windows on the local Qwen router, and logs the failure with an empty message #572

New issue

Open

opened 2026-09-09 06:29:43 +00:00 by claude-bot · 2 comments

claude-bot commented

2026-09-09 06:29:43 +00:00

Contributor

Seen on the dev replay of the 2026-09-09 session (same audio and transcript as prod, qwen3.5 on the shared llama.cpp router, 5 extraction windows, 4 passes):

05:53:17 WARNING Beat extraction failed for window 4/5 (pass 1):
05:59:10 WARNING Beat extraction failed for window 2/5 (pass 2):
06:06:03 WARNING Beat extraction failed for window 4/5 (pass 2):
06:16:13 WARNING Beat extraction failed for window 4/5 (pass 3):
06:22:02 WARNING Beat extraction failed for window 2/5 (pass 4):
06:28:08 WARNING Beat extraction failed for window 4/5 (pass 4):
06:28:20 INFO    Beat validation: 27/99 beats validated across 5 window(s)

Window 4 (00:55 to 01:14, the journal, the circus crest, the cant, the whole payoff of the session) failed in every pass, so the composed summary is built with no events from that stretch, and nothing tells the GM. Window 2 failed in two of four. The failures arrive about ten minutes after each window is submitted, which points at the per-call LLM timeout rather than at the model's output; the message is empty because _extract_one_pass logs %s of the exception and an httpx timeout stringifies to nothing.

Three things to fix.

Log type(exc).__name__ and repr(exc), never bare %s, in audio_service._extract_one_pass and anywhere else a provider exception is summarised into a log line.
When a window fails in every pass, the run record should say so. summarisation_runs has capability_gaps and now hallucination_drops; a windows_failed count (or the list of failed window indices) belongs beside them, and the GM-facing summary should carry a note that a stretch of the session was not summarised, rather than reading as complete.
Decide what a slow local model should get: a longer timeout for extraction (its output length scales with the window), a smaller extraction window when the provider is local (_EXTRACTION_CONTEXT_CAP is already an env knob), or one retry of a failed window before the pass ends. Measure on the replay: window 4 is the reproducible case.

Related: #568 (summary length is set by verified beats) and the model comparison notes on #566, where the same audio verified 21 to 93 beats on hosted models with no window failures.

**Seen on the dev replay of the 2026-09-09 session** (same audio and transcript as prod, qwen3.5 on the shared llama.cpp router, 5 extraction windows, 4 passes): ``` 05:53:17 WARNING Beat extraction failed for window 4/5 (pass 1): 05:59:10 WARNING Beat extraction failed for window 2/5 (pass 2): 06:06:03 WARNING Beat extraction failed for window 4/5 (pass 2): 06:16:13 WARNING Beat extraction failed for window 4/5 (pass 3): 06:22:02 WARNING Beat extraction failed for window 2/5 (pass 4): 06:28:08 WARNING Beat extraction failed for window 4/5 (pass 4): 06:28:20 INFO Beat validation: 27/99 beats validated across 5 window(s) ``` Window 4 (00:55 to 01:14, the journal, the circus crest, the cant, the whole payoff of the session) failed in **every** pass, so the composed summary is built with no events from that stretch, and nothing tells the GM. Window 2 failed in two of four. The failures arrive about ten minutes after each window is submitted, which points at the per-call LLM timeout rather than at the model's output; the message is empty because `_extract_one_pass` logs `%s` of the exception and an httpx timeout stringifies to nothing. **Three things to fix.** 1. Log `type(exc).__name__` and `repr(exc)`, never bare `%s`, in `audio_service._extract_one_pass` and anywhere else a provider exception is summarised into a log line. 2. When a window fails in every pass, the run record should say so. `summarisation_runs` has `capability_gaps` and now `hallucination_drops`; a `windows_failed` count (or the list of failed window indices) belongs beside them, and the GM-facing summary should carry a note that a stretch of the session was not summarised, rather than reading as complete. 3. Decide what a slow local model should get: a longer timeout for extraction (its output length scales with the window), a smaller extraction window when the provider is local (`_EXTRACTION_CONTEXT_CAP` is already an env knob), or one retry of a failed window before the pass ends. Measure on the replay: window 4 is the reproducible case. Related: #568 (summary length is set by verified beats) and the model comparison notes on #566, where the same audio verified 21 to 93 beats on hosted models with no window failures.

claude-bot commented

2026-09-09 06:43:33 +00:00

Author

Contributor

Two refinements from the completed replay (run 1h13m: 26 min transcription, 47 min summarisation, 17 LLM calls, 178k prompt tokens):

The failing windows are not necessarily timeouts. The delegate that ran the replay read the router's behaviour as an empty response for those windows, consistent with the standing note that this llama.cpp endpoint returns empty content under some output-length conditions. Fix 1 (log the exception type and repr) settles it either way; until then the ten-minute cadence is the only evidence.
Because window 4 never contributed, the composed summary has nothing from the journal, the circus crest or the cant, and reads as if the session ended at the cave mouth. The GM-visible gap note in fix 2 is the important part.

Also observed during the same run, filed separately: one summarisation-stage prompt of ~31k tokens was sent against a 22.9k budget (#575), the provider-slot cap is silently disabled in the post-session fan-out because the event loop is already closed (#573), and clean_term strips the closing parenthesis from "Viquilonto (Viq)" before it reaches Whisper (#574).

Two refinements from the completed replay (run 1h13m: 26 min transcription, 47 min summarisation, 17 LLM calls, 178k prompt tokens): - The failing windows are not necessarily timeouts. The delegate that ran the replay read the router's behaviour as an **empty response** for those windows, consistent with the standing note that this llama.cpp endpoint returns empty content under some output-length conditions. Fix 1 (log the exception type and repr) settles it either way; until then the ten-minute cadence is the only evidence. - Because window 4 never contributed, the composed summary has nothing from the journal, the circus crest or the cant, and reads as if the session ended at the cave mouth. The GM-visible gap note in fix 2 is the important part. Also observed during the same run, filed separately: one summarisation-stage prompt of ~31k tokens was sent against a 22.9k budget (#575), the provider-slot cap is silently disabled in the post-session fan-out because the event loop is already closed (#573), and `clean_term` strips the closing parenthesis from "Viquilonto (Viq)" before it reaches Whisper (#574).

claude-bot referenced this issue

2026-09-09 07:27:57 +00:00

Drop Whisper hallucination segments before the transcript is merged #569

rbrooks referenced this issue from a commit

2026-09-09 17:35:02 +00:00

fix(backend): retry, record and report a window beat extraction cannot read (#572)

rbrooks referenced this issue from a commit

2026-09-09 17:35:37 +00:00

fix(backend): retry, record and report a window beat extraction cannot read (#572)

claude-bot referenced this issue

2026-09-09 17:35:50 +00:00

fix(backend): four summarisation-pipeline defects found by replaying a real session (#566, #567, #572, #575) #583

claude-bot referenced this issue from a commit

2026-09-09 17:52:35 +00:00

Merge PR #583: fix(backend): four summarisation-pipeline defects found by replaying a real session (#566, #567, #572, #575)

claude-bot commented

2026-09-09 18:38:32 +00:00

Author

Contributor

Measured after #583 on the dev replay (same audio, qwen3.5 9B): four passes, windows_failed = [], no window errored; window 5 (the post-game chatter) now logs "returned no beats … an answer, not a failure" on every pass instead of looking like a loss. Critic count 0 (#567), the highlights call ran windowed with no over-budget warning (#575), and the composed summary follows session order (#566). 19 of 30 beats verified; the remaining errors in the prose (the party placed in Ironroot Hold, a Foundry token glitch narrated as an event) are the model's, not the pipeline's.

Measured after #583 on the dev replay (same audio, qwen3.5 9B): four passes, `windows_failed = []`, no window errored; window 5 (the post-game chatter) now logs "returned no beats … an answer, not a failure" on every pass instead of looking like a loss. Critic count 0 (#567), the highlights call ran windowed with no over-budget warning (#575), and the composed summary follows session order (#566). 19 of 30 beats verified; the remaining errors in the prose (the party placed *in* Ironroot Hold, a Foundry token glitch narrated as an event) are the model's, not the pipeline's.