From f7c51b79dab5b520fb3e2d9cf04826647674c445 Mon Sep 17 00:00:00 2001 From: Phillip Tarrant Date: Fri, 10 Jul 2026 08:45:39 -0500 Subject: [PATCH] =?UTF-8?q?fix(api):=20best-effort=20call=20logging=20+=20?= =?UTF-8?q?non-JSON=20200=20=E2=86=92=20ModelError=20(final-review)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - call_log._default_write: swallow any exception from the default file/ stdout sink and report to stderr, so a log-write failure (disk full, bad permissions, misconfigured CALL_LOG_PATH) never turns a successful narration into a 500 (charter §13). Injected write= sinks (used by tests) are left to surface their own errors. - ollama_client.chat: catch ValueError alongside httpx.HTTPError in the retry loop so a 200 response with a non-JSON body (JSONDecodeError is a ValueError subclass) counts as a failed attempt and falls through to ModelError after the one retry, instead of escaping chat() uncaught (charter §12 — one retry, then ModelError, nothing else escapes). - main.py: update stale docstrings — /dm/narrate is now fully wired (routing + model call + logging); the other four roles remain stubs. Regression tests added for both fixes (TDD: watched RED, then GREEN). Co-Authored-By: Claude Opus 4.8 (1M context) --- api/app/call_log.py | 21 +++++++++++++++------ api/app/main.py | 9 ++++++--- api/app/ollama_client.py | 6 +++++- api/tests/test_call_log.py | 22 ++++++++++++++++++++++ api/tests/test_ollama_client.py | 12 ++++++++++++ 5 files changed, 60 insertions(+), 10 deletions(-) diff --git a/api/app/call_log.py b/api/app/call_log.py index 8e69a13..2ac8d73 100644 --- a/api/app/call_log.py +++ b/api/app/call_log.py @@ -16,12 +16,21 @@ from . import config def _default_write(line: str) -> None: - path = config.call_log_path() - if path: - with open(path, "a", encoding="utf-8") as handle: - handle.write(line + "\n") - else: - sys.stdout.write(line + "\n") + """Best-effort (charter §13): a good model call must never become a 500 + because the log write failed (disk full, bad permissions, a misconfigured + CALL_LOG_PATH). Any failure here is swallowed and reported to stderr — + never stdout, since stdout may itself be the default sink and must stay + clean JSON-lines for downstream tooling. + """ + try: + path = config.call_log_path() + if path: + with open(path, "a", encoding="utf-8") as handle: + handle.write(line + "\n") + else: + sys.stdout.write(line + "\n") + except Exception as exc: # noqa: BLE001 - logging must never break a request + print(f"call_log: failed to write log line: {exc}", file=sys.stderr) def record( diff --git a/api/app/main.py b/api/app/main.py index 9d9fddb..5ac3ffa 100644 --- a/api/app/main.py +++ b/api/app/main.py @@ -3,7 +3,9 @@ Skeleton: a health check plus the five role endpoints. Each role endpoint now validates the posted canon log against the contract (charter §11) before doing anything else — an invalid log is rejected with 422 and never reaches a prompt. -Prompt routing, model selection, and logging land later. +`/dm/narrate` is fully wired: prompt routing, the Ollama model call, and +call-log logging. The other four roles remain stubs until they get the same +treatment. """ from fastapi import Depends, FastAPI, HTTPException @@ -48,8 +50,9 @@ def health() -> dict: # ── Role endpoints (charter §4) ────────────────────────────────────────────── # The client knows these paths and nothing about which model or prompt serves -# them. Bodies are validated against the canon log contract; the AI half is a -# stub until prompt routing lands. +# them. Bodies are validated against the canon log contract. /dm/narrate is +# fully wired (routing + model call + logging); the other four roles remain +# stubs until prompt routing, model selection, and logging land for them too. @app.post("/dm/narrate") diff --git a/api/app/ollama_client.py b/api/app/ollama_client.py index 6de1d48..920c7b7 100644 --- a/api/app/ollama_client.py +++ b/api/app/ollama_client.py @@ -38,7 +38,11 @@ def chat( if content.strip(): return content last = "empty response from model" - except httpx.HTTPError as exc: # TimeoutException, TransportError, HTTPStatusError + except (httpx.HTTPError, ValueError) as exc: + # httpx.HTTPError: TimeoutException, TransportError, HTTPStatusError. + # ValueError: resp.json() raises json.JSONDecodeError (a ValueError + # subclass) on a 200 with a non-JSON body (e.g. a proxy error page) — + # treat that as a failed attempt too, not an uncaught escape (§12/§13). last = f"{type(exc).__name__}: {exc}" raise ModelError(last) finally: diff --git a/api/tests/test_call_log.py b/api/tests/test_call_log.py index a22a43e..9ddaa3b 100644 --- a/api/tests/test_call_log.py +++ b/api/tests/test_call_log.py @@ -32,3 +32,25 @@ def test_failure_record_shape(): assert parsed["ok"] is False assert parsed["error"] == "ModelError: down" assert "response" not in parsed + + +def test_default_write_failure_does_not_propagate(monkeypatch, capsys): + """§13 — a good narration must never become a 500 because the log write + failed. Point CALL_LOG_PATH at a path whose parent directory does not + exist, so the default sink's `open()` raises. record() must swallow it, + report to stderr (never stdout — stdout may be the log sink itself), and + still return the record. + """ + monkeypatch.setenv( + "CALL_LOG_PATH", "/nonexistent-dir-for-test/does/not/exist.log" + ) + rec = record( + role="narrator", model="qwen3.5:latest", options={"seed": 7}, + messages=[{"role": "user", "content": "x"}], canon_log={"a": 1}, + ok=True, latency_ms=120, response="prose", + ) + assert rec["response"] == "prose" + assert rec["ok"] is True + out, err = capsys.readouterr() + assert out == "" + assert err != "" diff --git a/api/tests/test_ollama_client.py b/api/tests/test_ollama_client.py index 8bd14e7..59a2402 100644 --- a/api/tests/test_ollama_client.py +++ b/api/tests/test_ollama_client.py @@ -81,3 +81,15 @@ def test_empty_content_retried_then_modelerror(): with pytest.raises(ModelError): chat("m", [{"role": "user", "content": "x"}], {}, client=_client(handler)) + + +def test_non_json_200_retried_then_modelerror(): + """A 200 response with a non-JSON body (e.g. a proxy error page) must + degrade to ModelError after the one retry, not escape as a bare + JSONDecodeError/ValueError (charter §12/§13). + """ + def handler(request): + return httpx.Response(200, text="not json") + + with pytest.raises(ModelError): + chat("m", [{"role": "user", "content": "x"}], {}, client=_client(handler))