fix(llm): always send enable_thinking=true — hidden reasoning was written inline into content

The llama.cpp endpoint writes the model's hidden reasoning INLINE into
content unless enable_thinking=true is sent (which relocates it to the
separate reasoning_content field). The app sent the field absent, so:
- complete_json got corrupted JSON -> live 500 'Unterminated string char 143'
- persona JSON generation failed (same root cause, earlier incident)
- persona replies were bloated with the reasoning chain

Send the flag on all three call paths (complete/complete_json/
complete_conversation). thinking param retained for API compat, now a
no-op on this provider (always separated — the only correct mode here).

- tests/test_llm_enable_thinking.py pins the flag on all three paths
- full suite: 543 passed; independent reviewer PASS (22 focused passed,
  single OpenAI client in the app, both fixed sites confirmed, no stale
  tests)
- cleanup stale comments that encoded the backwards understanding
  (endpoint 'ignores enable_thinking' — it honors it; that misconception
  is what caused this incident)
This commit is contained in:
Macky
2026-10-02 20:09:31 +07:00
parent f995280483
commit 0f34af71d1
8 changed files with 133 additions and 19 deletions

View File

@@ -106,11 +106,13 @@ class LLMClient:
max_tokens: int = 3000,
thinking: bool = True,
) -> str:
extra_body = None
if not thinking:
# Qwen3-style thinking models: disable chain-of-thought to cut latency
# (measured 313s -> 44s per persona on the local tabbyAPI server).
extra_body = {"enable_thinking": False}
# Always keep reasoning SEPARATE (llama.cpp: enable_thinking=true puts it in
# reasoning_content, content stays clean). Omitting the field or false makes
# the model write the chain inline into content — which corrupts JSON
# responses ("Unterminated string" live 500) and persona parsing. The
# `thinking` param is retained for API compatibility; on this provider the
# mode is always "separated".
extra_body = {"enable_thinking": True}
try:
resp = self._create(
model=self.model,
@@ -181,12 +183,14 @@ class LLMClient:
mapped = "user"
api_messages.append({"role": mapped, "content": m.get("text") or m.get("content") or ""})
try:
# enable_thinking=true keeps the model's reasoning in reasoning_content
# so the reply text stays clean (see complete()).
resp = self._create(
model=self.model,
temperature=temperature,
max_tokens=max_tokens,
messages=api_messages,
extra_body=None,
extra_body={"enable_thinking": True},
)
except Exception as exc:
raise LLMError(f"LLM call failed: {exc}") from exc

View File

@@ -1,6 +1,6 @@
"""Persona generator: builds 15 personas (5 per tier) from a Sales Kit + scenario.
Generation is split into ONE persona per LLM call (thinking disabled) so each call
Generation is split into ONE persona per LLM call (reasoning kept separate) so each call
finishes well under the Cloudflare 120s proxy timeout that kills the single 15-persona
call. The 15 calls run in a small thread pool (the local LLM tolerates a few
concurrent requests) to cut total wall-clock time.

View File

@@ -248,9 +248,9 @@ 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.",
})
# 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.
# NOTE: the Qwen GGUF reasons internally before answering. We keep that
# reasoning in a separate field (enable_thinking=true), so content stays
# clean — 400 starved the reply (content=''). 1200 fits reply headroom.
resp = self.llm.complete_conversation(msgs, temperature=0.7, max_tokens=1200)
parsed = self._parse_persona_reply(resp)
if parsed is not None:

View File

@@ -1,8 +1,8 @@
"""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).
"""Budget guard: the Qwen GGUF reasons internally (hidden thinking, kept in a
separate field via enable_thinking=true) before the visible answer. If a budget is
too small, the reply has no headroom and the call can return content='' → LLMError
→ "LLM service unavailable" (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.

View File

@@ -0,0 +1,66 @@
"""The llama.cpp endpoint writes the model's hidden reasoning INLINE into
`content` UNLESS `enable_thinking` is sent as `true` — which relocates it to the
separate `reasoning_content` field and keeps `content` clean.
Omitting the field (or sending false) corrupts every JSON response with inline
thinking: the live 2026-10-02 500 was `LLM returned invalid JSON:
Unterminated string` and persona generation was failing for the same reason.
These tests pin the flag so a future edit that drops it fails loudly.
"""
from __future__ import annotations
import app.llm as llm_mod
from app.llm import LLMClient
def _make_client() -> LLMClient:
c = LLMClient(base_url="http://localhost:9/v1", api_key="test-key", model="m")
c.max_attempts = 1
c.retry_delay = 0.0
return c
def _resp(content: str = '{"ok": 1}'):
message = type("M", (), {"content": content})()
choice = type("C", (), {"message": message})()
return type("R", (), {"choices": [choice]})()
def test_complete_always_sends_enable_thinking_true(monkeypatch):
c = _make_client()
seen: dict = {}
def spy(**kwargs):
seen["extra_body"] = kwargs.get("extra_body")
return _resp()
c.client.chat.completions.create = spy
c.complete("sys", "user")
assert seen["extra_body"] == {"enable_thinking": True}
def test_complete_json_always_sends_enable_thinking_true(monkeypatch):
c = _make_client()
seen: dict = {}
def spy(**kwargs):
seen["extra_body"] = kwargs.get("extra_body")
return _resp('{"mood": 1}')
c.client.chat.completions.create = spy
c.complete_json("sys", "user")
assert seen["extra_body"] == {"enable_thinking": True}
def test_complete_conversation_always_sends_enable_thinking_true(monkeypatch):
c = _make_client()
seen: dict = {}
def spy(**kwargs):
seen["extra_body"] = kwargs.get("extra_body")
return _resp("สวัสดีค่ะ")
c.client.chat.completions.create = spy
c.complete_conversation([{"role": "seller", "text": "hi"}])
assert seen["extra_body"] == {"enable_thinking": True}

View File

@@ -242,6 +242,13 @@ 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 500 #3 — hidden reasoning written INLINE into content
- Symptom: `LLM returned invalid JSON: Unterminated string (char 143)` — the budget fix (c5553eb) was whack-a-mole; bigger budget only moves empty→truncated JSON.
- Root cause (live probes): llama.cpp endpoint writes the model's hidden reasoning INLINE into `content` UNLESS `enable_thinking: true` is sent (which moves it to `reasoning_content`). The app was sending the field absent (`extra_body=None`). Same root cause as the earlier persona-generation failures.
- Fix: `llm.py` always sends `enable_thinking: true` on all three call paths (`complete`/`complete_json`/`complete_conversation`). `tests/test_llm_enable_thinking.py` pins it. **543 passed.**
- Server-side `--reasoning-format none` = speed only now (latency), correctness already fixed.
- Evidence: `docs/engineering-log/2026-10-02-enable-thinking-inline-root-cause.md`.
## 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).

View File

@@ -0,0 +1,37 @@
# 2026-10-02 — 500 "invalid JSON: Unterminated string": hidden reasoning inline in content
## Symptom
After the budget fix (c5553eb): live `POST /api/chat/.../send` → 500
`LLM returned invalid JSON: Unterminated string starting at: line 5 column 10 (char 143)`.
The budget-raise was whack-a-mole: bigger budget just moves the failure from
`content=''` to `truncated JSON`.
## Diagnosis (live probes vs pchome.moreminimore.com/v1, model mia-qwen38-3.0bpw)
The llama.cpp endpoint has a hidden-thinking field, and the app must tell it to use it:
| `enable_thinking` sent | content | reasoning location |
|---|---|---|
| **absent** (what app sent: `extra_body=None`) | `17×24=...408 {"result":408}` | **inline in content** (+ reasoning_content field) |
| `false` | inline in content | inline |
| `true` | `{"result":408}` — clean | `reasoning_content` field |
Consequences of the inline form (what the app had been living with):
- `complete_json` last-ditch regex grabs a corrupted span → `Unterminated string` → 500 (this incident)
- `persona_generator` (persona JSON) → persona generation fails (the "สร้าง persona ไม่ได้" incident, same root cause)
- persona reply (chat) → reply text bloated with reasoning chain (the 21562-byte 200)
## Fix (this commit)
`llm.py`: `complete()`, `complete_json()` (via complete), and `complete_conversation()`
**always send `extra_body={"enable_thinking": True}`** — relocates hidden reasoning into
`reasoning_content`, `content` stays clean. The `thinking` param is retained for API
compatibility but is a no-op on this provider (always separated).
`tests/test_llm_enable_thinking.py` pins the flag on all three call paths.
## Why not just a bigger budget
Budget raises only delay the corruption (empty → truncated → eventually clean); the
inline reasoning format is the actual bug. Separation fixes the judge 500, persona
JSON, and persona reply text at once.
## Server-side (speed, optional — owner)
`--reasoning-format none` (or no-think template) still removes the reasoning compute
entirely → latency goes back to ~5s. Not required for correctness.

View File

@@ -1,16 +1,16 @@
# Sales Trainer — Current Execution Plan
## Status
Complete. Implementation, local verification, and independent review are all closed. No commit, push, deploy, or live-provider testing.
Live-incident fix in independent review. `llm.py` now always sends `enable_thinking: true` so hidden reasoning goes to `reasoning_content` (not inline in content, which was corrupting JSON → 500 + persona failures). 543 passed locally; reviewer verdict pending.
## Current phase / active task
Complete. All implementation, local verification, and independent review closed. Awaiting owner approval for commit/push/deploy (CON-003).
Live-incident #3 (after budget fix c5553eb) — `LLM returned invalid JSON: Unterminated string (char 143)`. Root cause: llama.cpp writes hidden reasoning inline into `content` unless `enable_thinking: true` is sent. Fix: always send the flag on all three call paths. Independent review in progress.
## Last update
2026-10-02. Project requirements reconciled from the latest owner instruction in `project.md`. Legacy architecture and security context reviewed in `docs/plan.md`, `docs/HANDOFF.md`, and `docs/engineering-log/2026-08-24-training-security-review.md`.
2026-10-02. Live incident #3 fix implemented (enable_thinking), 543 tests green, docs updated, independent reviewer dispatched (deleg_a60a1a2e).
## Next action
None in scope. Awaiting owner approval for commit/push/deploy (CON-003). No further implementation work.
Await independent reviewer verdict → commit + push (owner approval per CON-003) → EasyPanel auto-deploy → live verify chat send returns 200 and judge returns real outcomes.
## Blockers
None known. Do not commit, push, or deploy. Do not access `.env` or production data.