Quote board silently empty: strict JSON parse rejects ~2/3 of highlight responses, failure is indistinguishable from "no quotes found" #279

Closed
opened 2026-08-05 16:00:21 +00:00 by claude-bot · 1 comment
Contributor

The player-facing quote board (#116) has produced zero rows on prod. Root cause is a strict JSON parse rejecting malformed model output, with a silent-failure path that made it look like the model simply found nothing memorable.

Distinct from #278 (which is the publication gate on approve_audio). This is about rows never being written in the first place.

Mechanism

  1. llm_service.py:174-183 sends response_format: {"type":"json_object"}. The prod endpoint (llama.cpp router build b9029 fronting Qwen3.5-9B-UD-Q8_K_XL) does not enforce the JSON grammar — it returns finish_reason=stop with structurally invalid JSON.
  2. On the large (~33k token) highlights prompt the model emits compact single-line JSON that is corrupt at the tail. Observed shapes: missing }, missing ]}, and an extra trailing }.
  3. _parse_highlights_json (webapp/backend/app/services/audio_service.py:963-990) is strict. json.loads fails, and the only salvage path is gated behind if not text.startswith("{") (:980) — so for a response that starts with {, the repair never runs at all. Verified by reading: a truncated-but-{-leading response goes straight to json.loadsexcept{}.
  4. audio_service.py:1041-1043: empty dict → return [].
  5. reminder_tasks.py:2133-2137 logs INFO … extracted 0 highlightsidentical to the legitimate "model found nothing" outcome. No warning, no error.

Evidence

Reproduced against the live endpoint with the real 81,302-char transcript from session d633ad3c: 9 prod-shaped calls, 6 returned structurally invalid JSON (~67% failure rate). Correlation was perfect — every compact-style response was malformed, every pretty-printed one parsed.

Live worker log for that session:

02:59:31,220 Summary complete: 1910 chars
02:59:45,747 HTTP Request: POST http://10.3.0.28:8090/v1/chat/completions "HTTP/1.1 200 OK"
02:59:46,075 process_audio: extracted 0 highlights (session=d633ad3c-…)

HTTP 200, 14.5s, no exception logged. The block runs; the parse is what fails.

Forcing a parseable response showed 5/5 quotes passed the verbatim/hallucination substring check plus 3 moments — 8 rows would have been written. The filter is not the blocker.

Correcting an earlier assumption

The symptom was originally read as "zero highlights across 6 transcribed sessions." In fact only one session has ever attempted extraction: #116 landed in 86e6e66 on 2026-07-17 and the prod worker was rebuilt 2026-07-27, so the 2026-07-29 session is the only one whose process_audio ran the extraction block. The other transcripts (2026-03-25 → 2026-07-15) predate the feature entirely. So this is 1 failure out of 1 attempt against a measured ~67% failure rate — not 6 for 6.

Ruled out

  • Config/flag gate — no flag check exists in the write path; highlights_in_discord only governs Discord posting. max_quotes resolves correctly from the DB (both campaigns: 5).
  • Different LLM config — byte-identical object to the one summarisation uses (:2069-2071 vs :2109-2111).
  • Swallowed exception at :2138 — that path logs a WARNING; zero such lines in the full 39,884-line worker log.
  • max_tokens=2048 truncationfinish_reason=stop on every malformed run, completion tokens 229-382.

Why summarisation works and this doesn't

_summarise_llamacpp (audio_service.py:2098-2129) sends no response_format, no max_tokens, and parses nothing — it returns content.strip() as prose. There is no JSON contract to violate.

The shared helper has the same flaw

extract_json_object (webapp/backend/app/services/llm_service.py:283-303) also fails on a missing trailing }rfind("}") can't recover a truncated tail. Every json_mode=True caller is exposed to the same endpoint behaviour: lore proposals, generation_service, stat-block generation. Those raise rather than silently returning [], which is why only highlights failed quietly — but they are equally fragile. Worth fixing once, centrally, rather than per-caller.

Fix direction

  1. Tolerant parse, shared: drop the if not text.startswith("{") gate so salvage always runs; use json.JSONDecoder().raw_decode() (fixes the extra-trailing-} case outright); add bracket-balance repair (walk the string tracking depth outside string literals, truncate to the last complete element, append missing closers). All 6 captured malformed samples are recoverable this way.
  2. Make failure visible — log a WARNING with response length when a parse yields {}, and have the caller distinguish "parse failed" from "0 highlights". The indistinguishable INFO line is what hid this for a full release cycle.
  3. Infra lever — the endpoint isn't honouring json_object. Constrained decoding via response_format: {"type":"json_schema", …} or an explicit grammar would eliminate the class entirely. Worth testing against this router build.
  4. Backfill path — highlights only need the stored transcript, and the sole call site is inside process_audio (reminder_tasks.py:2105), whose audio is already deleted. A GM-facing "regenerate highlights from transcript" action would let existing sessions be backfilled.
  5. Test gapwebapp/backend/tests/test_highlights.py:100-104 only feeds well-formed JSON or total garbage. Add fixtures for the three real corruption shapes.

Do not drop chat_template_kwargs: {"enable_thinking": False} in any fix — testing showed that removing it while keeping max_tokens=2048 yields finish_reason=length with empty content, as the whole budget goes to reasoning tokens.

Not verified

Why the router build lets ungrammatical JSON through (the GPU host's llama.cpp logs weren't reachable). Retry-only is insufficient — at a 67% failure rate, retry-once still fails ~45% of the time, so the repair is the necessary part.

Labels: bug, backend

The player-facing quote board (#116) has produced zero rows on prod. Root cause is a strict JSON parse rejecting malformed model output, with a silent-failure path that made it look like the model simply found nothing memorable. Distinct from #278 (which is the *publication* gate on `approve_audio`). This is about rows never being **written** in the first place. ## Mechanism 1. `llm_service.py:174-183` sends `response_format: {"type":"json_object"}`. The prod endpoint (llama.cpp router build b9029 fronting Qwen3.5-9B-UD-Q8_K_XL) **does not enforce the JSON grammar** — it returns `finish_reason=stop` with structurally invalid JSON. 2. On the large (~33k token) highlights prompt the model emits *compact* single-line JSON that is corrupt at the tail. Observed shapes: missing `}`, missing `]}`, and an extra trailing `}`. 3. `_parse_highlights_json` (`webapp/backend/app/services/audio_service.py:963-990`) is strict. `json.loads` fails, and the only salvage path is gated behind `if not text.startswith("{")` (`:980`) — **so for a response that starts with `{`, the repair never runs at all**. Verified by reading: a truncated-but-`{`-leading response goes straight to `json.loads` → `except` → `{}`. 4. `audio_service.py:1041-1043`: empty dict → `return []`. 5. `reminder_tasks.py:2133-2137` logs `INFO … extracted 0 highlights` — **identical to the legitimate "model found nothing" outcome**. No warning, no error. ## Evidence Reproduced against the live endpoint with the real 81,302-char transcript from session `d633ad3c`: **9 prod-shaped calls, 6 returned structurally invalid JSON** (~67% failure rate). Correlation was perfect — every compact-style response was malformed, every pretty-printed one parsed. Live worker log for that session: ``` 02:59:31,220 Summary complete: 1910 chars 02:59:45,747 HTTP Request: POST http://10.3.0.28:8090/v1/chat/completions "HTTP/1.1 200 OK" 02:59:46,075 process_audio: extracted 0 highlights (session=d633ad3c-…) ``` HTTP 200, 14.5s, no exception logged. The block runs; the parse is what fails. Forcing a parseable response showed **5/5 quotes passed** the verbatim/hallucination substring check plus 3 moments — 8 rows would have been written. The filter is not the blocker. ## Correcting an earlier assumption The symptom was originally read as "zero highlights across 6 transcribed sessions." In fact **only one session has ever attempted extraction**: #116 landed in `86e6e66` on 2026-07-17 and the prod worker was rebuilt 2026-07-27, so the 2026-07-29 session is the only one whose `process_audio` ran the extraction block. The other transcripts (2026-03-25 → 2026-07-15) predate the feature entirely. So this is 1 failure out of 1 attempt against a measured ~67% failure rate — not 6 for 6. ## Ruled out - **Config/flag gate** — no flag check exists in the write path; `highlights_in_discord` only governs Discord posting. `max_quotes` resolves correctly from the DB (both campaigns: 5). - **Different LLM config** — byte-identical object to the one summarisation uses (`:2069-2071` vs `:2109-2111`). - **Swallowed exception at `:2138`** — that path logs a WARNING; zero such lines in the full 39,884-line worker log. - **`max_tokens=2048` truncation** — `finish_reason=stop` on every malformed run, completion tokens 229-382. ## Why summarisation works and this doesn't `_summarise_llamacpp` (`audio_service.py:2098-2129`) sends no `response_format`, no `max_tokens`, and **parses nothing** — it returns `content.strip()` as prose. There is no JSON contract to violate. ## The shared helper has the same flaw `extract_json_object` (`webapp/backend/app/services/llm_service.py:283-303`) also fails on a missing trailing `}` — `rfind("}")` can't recover a truncated tail. Every `json_mode=True` caller is exposed to the same endpoint behaviour: lore proposals, `generation_service`, stat-block generation. Those **raise** rather than silently returning `[]`, which is why only highlights failed quietly — but they are equally fragile. Worth fixing once, centrally, rather than per-caller. ## Fix direction 1. **Tolerant parse**, shared: drop the `if not text.startswith("{")` gate so salvage always runs; use `json.JSONDecoder().raw_decode()` (fixes the extra-trailing-`}` case outright); add bracket-balance repair (walk the string tracking depth outside string literals, truncate to the last complete element, append missing closers). All 6 captured malformed samples are recoverable this way. 2. **Make failure visible** — log a WARNING with response length when a parse yields `{}`, and have the caller distinguish "parse failed" from "0 highlights". The indistinguishable INFO line is what hid this for a full release cycle. 3. **Infra lever** — the endpoint isn't honouring `json_object`. Constrained decoding via `response_format: {"type":"json_schema", …}` or an explicit `grammar` would eliminate the class entirely. Worth testing against this router build. 4. **Backfill path** — highlights only need the stored transcript, and the sole call site is inside `process_audio` (`reminder_tasks.py:2105`), whose audio is already deleted. A GM-facing "regenerate highlights from transcript" action would let existing sessions be backfilled. 5. **Test gap** — `webapp/backend/tests/test_highlights.py:100-104` only feeds well-formed JSON or total garbage. Add fixtures for the three real corruption shapes. **Do not drop `chat_template_kwargs: {"enable_thinking": False}`** in any fix — testing showed that removing it while keeping `max_tokens=2048` yields `finish_reason=length` with empty content, as the whole budget goes to reasoning tokens. ## Not verified Why the router build lets ungrammatical JSON through (the GPU host's llama.cpp logs weren't reachable). Retry-only is insufficient — at a 67% failure rate, retry-once still fails ~45% of the time, so the repair is the necessary part. Labels: bug, backend
rbrooks referenced this issue from a commit 2026-08-05 17:49:35 +00:00
Author
Contributor

Fixed and deployed in v3.11.1 (PR #280, merged as 01c9f86).

What shipped

repair_json_object() in llm_service is now the shared tolerant parser used by extract_json_object and _parse_highlights_json. It cascades: clean parse → raw_decode (which alone fixes the extra-brace shape) → close the open bracket stack → truncate to the last parseable point and close. Every candidate is validated with json.loads before being returned, so it can only ever return real JSON.

Two properties, both arrived at by getting them wrong first and being caught by tests:

  • It preserves the longest parseable prefix, not the nearest element boundary. Preferring commas/closed containers sounds safer but discarded a complete trailing quote on one of the real captured samples. The cost is that repair can leave an object missing the key it was about to receive — structurally indistinguishable from one legitimately omitting an optional key. So the documented contract is that callers validate required fields, not shape; extract_highlights does, and there is a test proving it drops a repaired half-object. strict=True exists for callers that can't tolerate this.
  • Well-formed JSON of the wrong shape is not repaired. An early version mined the first { out of a bare [...], silently dropping every later element and presenting the fragment as the whole response. test_workbench_rumor::test_parse_rumor_output_handles_malformed_reply caught it in the full-suite run. A valid non-object now reports failure so the caller's own shape-coercion fallback runs, as before.

Both repair and total failure now log at WARNING with response size only — never content, which is table talk. That was the actual reason this survived a release: INFO … extracted 0 highlights was indistinguishable from "the model found nothing memorable".

Also fixed the adjacent data-loss bug: the delete-then-reinsert cleared existing highlights before checking whether extraction returned anything, so every retry of a failing session destroyed a good set from an earlier successful run.

Tests

New tests/test_json_repair.py (15 tests) plus 5 in test_highlights.py, built on the three corruption shapes captured verbatim from the live endpoint. Full backend suite: 836 passed (up from 815).

Still open — worth a separate issue

This fixes the parsing, not the endpoint. The llama.cpp router still is not enforcing its JSON grammar and will keep returning malformed responses at roughly the measured ~2/3 rate on large prompts; the difference is that it now recovers and says so.

The follow-up worth doing is the constrained-decoding spike: whether response_format: {"type":"json_schema", …} or an explicit grammar is honoured by this build, and whether hitting the underlying llama.cpp server directly (bypassing the router) behaves differently — that would distinguish a router problem from a model problem. The new WARNING lines give a real failure rate to measure against, which the 9-sample estimate could not.

Closing this one; the spike should be filed on its own.

Fixed and deployed in **v3.11.1** (PR #280, merged as `01c9f86`). ## What shipped `repair_json_object()` in `llm_service` is now the shared tolerant parser used by `extract_json_object` and `_parse_highlights_json`. It cascades: clean parse → `raw_decode` (which alone fixes the extra-brace shape) → close the open bracket stack → truncate to the last parseable point and close. Every candidate is validated with `json.loads` before being returned, so it can only ever return real JSON. Two properties, both arrived at by getting them wrong first and being caught by tests: - **It preserves the longest parseable prefix**, not the nearest element boundary. Preferring commas/closed containers sounds safer but discarded a complete trailing quote on one of the real captured samples. The cost is that repair can leave an object missing the key it was about to receive — structurally indistinguishable from one legitimately omitting an optional key. So the documented contract is that **callers validate required fields, not shape**; `extract_highlights` does, and there is a test proving it drops a repaired half-object. `strict=True` exists for callers that can't tolerate this. - **Well-formed JSON of the wrong shape is not repaired.** An early version mined the first `{` out of a bare `[...]`, silently dropping every later element and presenting the fragment as the whole response. `test_workbench_rumor::test_parse_rumor_output_handles_malformed_reply` caught it in the full-suite run. A valid non-object now reports failure so the caller's own shape-coercion fallback runs, as before. Both repair and total failure now log at WARNING with response **size only** — never content, which is table talk. That was the actual reason this survived a release: `INFO … extracted 0 highlights` was indistinguishable from "the model found nothing memorable". Also fixed the adjacent data-loss bug: the delete-then-reinsert cleared existing highlights *before* checking whether extraction returned anything, so every retry of a failing session destroyed a good set from an earlier successful run. ## Tests New `tests/test_json_repair.py` (15 tests) plus 5 in `test_highlights.py`, built on the three corruption shapes captured verbatim from the live endpoint. Full backend suite: **836 passed** (up from 815). ## Still open — worth a separate issue **This fixes the parsing, not the endpoint.** The llama.cpp router still is not enforcing its JSON grammar and will keep returning malformed responses at roughly the measured ~2/3 rate on large prompts; the difference is that it now recovers and says so. The follow-up worth doing is the constrained-decoding spike: whether `response_format: {"type":"json_schema", …}` or an explicit `grammar` is honoured by this build, and whether hitting the underlying llama.cpp server directly (bypassing the router) behaves differently — that would distinguish a router problem from a model problem. The new WARNING lines give a real failure rate to measure against, which the 9-sample estimate could not. Closing this one; the spike should be filed on its own.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
rbrooks/Quest-Board#279
No description provided.