From c5553eb9a682db8d981a70588639f34b4dce5f47 Mon Sep 17 00:00:00 2001 From: Macky Date: Fri, 2 Oct 2026 19:01:33 +0700 Subject: [PATCH] fix(llm): raise persona-reply/judge token budgets over hidden reasoning MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The Qwen3.8 GGUF reasons internally before answering and the llama.cpp endpoint ignores enable_thinking — hidden reasoning consumed the whole 400-token persona_reply budget (HTTP 200, content='') -> LLMError -> live 500 'LLM service unavailable'. The 800-token judge JSON had the same starve and silently degraded to 'pending', so customers who decided to buy never closed the session. - persona_reply 400 -> 1200, evaluate_turn 800 -> 1600 - tests/test_llm_budgets.py pins the floors so a regression to the old values fails loudly - full suite: 540 passed; independent review PASS (truncation-safe: partial protocol JSON is rejected, never rendered) --- backend/app/services/simulator.py | 10 +++- backend/tests/test_llm_budgets.py | 59 +++++++++++++++++++ docs/HANDOFF.md | 9 +++ .../2026-10-02-llm-budget-root-cause.md | 42 +++++++++++++ 4 files changed, 118 insertions(+), 2 deletions(-) create mode 100644 backend/tests/test_llm_budgets.py create mode 100644 docs/engineering-log/2026-10-02-llm-budget-root-cause.md diff --git a/backend/app/services/simulator.py b/backend/app/services/simulator.py index 724bfd8..1d30a7a 100644 --- a/backend/app/services/simulator.py +++ b/backend/app/services/simulator.py @@ -248,7 +248,10 @@ class Simulator: "role": "system", "content": "Contract correction: output one JSON object with a non-empty string field named reply. Do not include analysis or extra prose.", }) - resp = self.llm.complete_conversation(msgs, temperature=0.7, max_tokens=400) + # NOTE: the Qwen GGUF reasons internally before answering (the llama.cpp + # endpoint ignores enable_thinking), so the hidden reasoning consumes part + # of the budget — 400 starved it (content=''). 1200 fits reasoning + reply. + resp = self.llm.complete_conversation(msgs, temperature=0.7, max_tokens=1200) parsed = self._parse_persona_reply(resp) if parsed is not None: return parsed @@ -298,8 +301,11 @@ class Simulator: ) user_prompt = f"PERSONA:\n{persona_summary}\n\nTRANSCRIPT:\n{transcript}{state_note}" try: + # 1600 (was 800): the Qwen GGUF's hidden reasoning can eat the whole 800 + # budget (content=''), which made the judge silently degrade to 'pending' + # — a customer who decided to buy never closed the session. result = self.judge_llm.complete_json( - sys, user_prompt, temperature=0.2, max_tokens=800 + sys, user_prompt, temperature=0.2, max_tokens=1600 ) except LLMError: # judge unavailable — fall back to pending (don't crash, don't misuse keywords) diff --git a/backend/tests/test_llm_budgets.py b/backend/tests/test_llm_budgets.py new file mode 100644 index 0000000..f625638 --- /dev/null +++ b/backend/tests/test_llm_budgets.py @@ -0,0 +1,59 @@ +"""Budget guard: the Qwen GGUF reasons internally (hidden thinking) before the +visible answer, and llama.cpp's endpoint ignores enable_thinking — so the hidden +reasoning consumes part of the token budget. If a budget is too small, the call +returns HTTP 200 with content='' → LLMError → "LLM service unavailable" (the 2026-10-02 +live incident: persona_reply at 400 tokens, judge JSON at 800). + +These tests pin the budgets so an "optimization" back to the small values fails loudly +instead of silently re-breaking chat. +""" +from __future__ import annotations + +from app.services.simulator import Simulator + + +class _CapturingLLM: + def __init__(self, payload: str) -> None: + self.payload = payload + self.conversation_kwargs: list[dict] = [] + self.json_kwargs: list[dict] = [] + + def complete_conversation(self, messages, **kwargs): + self.conversation_kwargs.append(kwargs) + return self.payload + + def complete_json(self, system, user, **kwargs): + self.json_kwargs.append(kwargs) + return {"decision": "none", "mood": 0, "reason": "x", "summary": "s"} + + +def test_persona_reply_budget_covers_hidden_reasoning(): + # 1200: enough for the model's internal reasoning + the visible reply. + stub = _CapturingLLM('{"reply": "ค่ะ"}') + Simulator(stub).persona_reply( + persona={ + "name": "n", "tier": "B", "initiation_mode": "customer", "channel": "line", + "profession": "p", "age_group": "u", "background": "b", "personality": "r", + "lifestyle": "l", "income": "i", "budget": "b", "decision_timeline": "d", + "pains": [], "negotiation_levers": [], "goal": "g", "tolerance": 2, + "recontact": True, "special": "", + }, + sales_kit={"productName": "x"}, + messages=[{"role": "seller", "text": "สวัสดีครับ"}], + internal={"turns": 1, "misses": 0, "score": 50}, + scenario="social", + ) + assert stub.conversation_kwargs[0]["max_tokens"] >= 1200 + + +def test_judge_budget_covers_hidden_reasoning(): + # 1600: the judge JSON (score/mood/decision/reason/summary) must fit after + # the hidden reasoning, or the judge silently degrades to 'pending' and a + # customer who decides to buy never closes the session. + stub = _CapturingLLM("") + Simulator(stub).evaluate_turn( + persona={"name": "n", "tier": "B", "budget": "b"}, + messages=[{"role": "customer", "text": "hi"}, {"role": "seller", "text": "hello"}], + internal={"turns": 1, "misses": 0, "score": 50}, + ) + assert stub.json_kwargs[0]["max_tokens"] >= 1600 diff --git a/docs/HANDOFF.md b/docs/HANDOFF.md index 2af36c1..9b794ab 100644 --- a/docs/HANDOFF.md +++ b/docs/HANDOFF.md @@ -242,6 +242,15 @@ cd backend && uv run python run.py # Flask :5001 - `docs/engineering-log/2026-08-15-s4-3-offline-dialect-remediation.md` — offline Alembic dialect finding, test-first fix, verification, and pending review. - `docs/engineering-log/2026-08-16-s4-4-importer-errorhandler-commit.md` — re-verification (330 tests on clean lock venv) and commit of the staged S4.4 importer + error-handler hardening increment. +## 2026-10-02 live "LLM service unavailable" — root cause + fix in review +- Symptom: live chat 500 `LLM service unavailable` while llama.cpp log shows the model generating (two 400-token tasks = the two `persona_reply` attempts, all hidden reasoning). +- Root cause (live probes): Qwen3.8-27B GGUF reasons internally; llama.cpp ignores `enable_thinking` → hidden reasoning eats `max_tokens` → HTTP 200 `content=''` → `LLMError`. `persona_reply` (400) crashed the 500; `evaluate_turn` judge (800) silently degraded to `pending` (buying customers never closed the session). +- Fix: `simulator.py` budgets 400→1200 (reply) / 800→1600 (judge) + `tests/test_llm_budgets.py` guard. **540 passed.** Diff-check clean, security scan 0. Independent review delegated (in progress). +- Review: independent reviewer **PASS** (verified: 14 focused passed, truncation-safe, no raw-JSON leak, deterministic tests, no stale callers). +- Deploy pending commit → push (CON-003: owner approval for push). +- Better server-side cure (owner): restart llama.cpp with `--reasoning-format none` (or no-think template via `--jinja`) — kills hidden reasoning for ALL clients. Until then chat sends carry +10–20s. +- Evidence: `docs/engineering-log/2026-10-02-llm-budget-root-cause.md`. + ## 2026-10-02 trial follow-up and analysis progress — local verification - Working tree is on `main` at HEAD `8c89b17`; all changes below are uncommitted. Do not push/deploy without owner approval (`project.md` CON-003). - Implemented: follow-up notice variants, gone/loss debrief with possibility-framed explanations, retained retry marker across judge outage, forced gone outcome to loss, persisted bounded analysis progress + UI polling, progress indicator, LLM timeout 180s, finite client polling 30m. diff --git a/docs/engineering-log/2026-10-02-llm-budget-root-cause.md b/docs/engineering-log/2026-10-02-llm-budget-root-cause.md new file mode 100644 index 0000000..9ccb79e --- /dev/null +++ b/docs/engineering-log/2026-10-02-llm-budget-root-cause.md @@ -0,0 +1,42 @@ +# 2026-10-02 — "LLM service unavailable" deep-dive: Qwen3.8 hidden reasoning starves the token budget + +## Symptom +Live: `POST /api/chat/{session}/send` → 500 `{"error":"LLM service unavailable"}` while the +llama.cpp log shows the model **generating fine** (two tasks at exactly 400 tokens, ~45 t/s, +`truncated=0`). + +## Diagnosis (evidence, all live probes against `pchome.moreminimore.com/v1`) +1. Endpoint health: simple prompt → HTTP 200, Thai answer, `finish=stop`. +2. `enable_thinking:false` probe, JSON prompt, max_tokens=300 → **HTTP 200, `content=''`, + `completion_tokens=300`** — the entire budget consumed by hidden reasoning. llama.cpp here + **ignores the `enable_thinking` field** (no `--jinja` chat template). +3. Same JSON prompt at max_tokens=800 → valid JSON. +4. `persona_reply` shape (thinking ON, max_tokens=400, short prompt) → sometimes works; + with real large prompts (full persona card + 30-msg transcript) the reasoning eats 400 → + `content=''` → `LLMError("LLM returned empty response")` → `chat_routes` catches → + 500. The two 400-token tasks in the llama.cpp log = the two `range(2)` `persona_reply` + attempts (internal loop) — both all-reasoning. +5. `evaluate_turn` (JSON judge, max_tokens=800) has the same starve at scale — it does NOT + crash (soft fallback to `pending`), so the **customer who decided to buy never closed the + session** — a silent quality bug, not just a 500. + +## Why the earlier "queue retry" fix wasn't the whole story +The retry fix (d17462e) is still correct and valuable (queue >180s timeouts under shared +load), but this 500 was NOT a timeout: HTTP 200 + empty body, in seconds. + +## Fix (committed with the tests) +- `simulator.py`: `persona_reply` max_tokens 400→1200; `evaluate_turn` 800→1600 — enough for + hidden reasoning + visible answer. +- `tests/test_llm_budgets.py`: pins the minimum budgets so a future "optimization" back to + 400/800 fails loudly instead of silently re-breaking chat. +- 540 tests pass (538 prior + 2 new). + +## Follow-up (server side, owner action — better fix) +The proper cure is on the llama.cpp side: restart with `--reasoning-format none` (or a +no-think chat template via `--jinja`) so no budget is burned on hidden reasoning. That +restores ~5s latencies for ALL clients of the shared server (incl. Hermes). Until then, +chat sends carry +10–20s of hidden reasoning (acceptable). + +## Status +- Code: uncommitted pending independent review (delegated). +- Deploy: pending review → commit → push → EasyPanel.