diff --git a/backend/app/api/helpers.py b/backend/app/api/helpers.py index 8de9c40..5cdb1d7 100644 --- a/backend/app/api/helpers.py +++ b/backend/app/api/helpers.py @@ -184,9 +184,14 @@ def api_error_handler(err: ApiError): def internal_error(message: str, exc: BaseException, status: int = 500) -> ApiError: - """Log only the exception type; never expose exception text to clients.""" + """Log the exception type and detail server-side; never expose text to clients. + + The detail is what makes 500s diagnosable — without it the log says only + "LLMError" and the real cause (404 unknown model / 401 bad key / ...) is + lost. Client-facing text stays the generic message. + """ current_app.logger.error( - "%s (error_type=%s)", message, type(exc).__name__ + "%s (error_type=%s) %s", message, type(exc).__name__, exc ) return ApiError(message, status) diff --git a/backend/app/config.py b/backend/app/config.py index dfd2f46..5a4da91 100644 --- a/backend/app/config.py +++ b/backend/app/config.py @@ -153,6 +153,14 @@ class Config: # LLM LLM_BASE_URL, LLM_MODEL, LLM_API_KEY, LLM_PROVIDER = resolve_llm() + # The local LLM server is shared (also serves Hermes): a concurrent long + # generation serializes requests, so a request can sit in the server queue + # well beyond a single attempt. Retry transient connection/timeout failures + # a few times so chat survives the queue instead of failing with 500. + LLM_MAX_ATTEMPTS = _get_int("LLM_MAX_ATTEMPTS", 3, minimum=1) + LLM_RETRY_DELAY_SECONDS = _get_float( + "LLM_RETRY_DELAY_SECONDS", 5.0, minimum=0.0 + ) # OAuth (Google + Facebook) — all optional; OAuth is disabled unless creds # are fully configured (fail closed). Client IDs / app IDs are public and diff --git a/backend/app/llm.py b/backend/app/llm.py index e8b45c8..348c45c 100644 --- a/backend/app/llm.py +++ b/backend/app/llm.py @@ -6,6 +6,7 @@ from __future__ import annotations import json import re +import time from typing import Any from openai import OpenAI @@ -55,8 +56,47 @@ class LLMClient: raise LLMError("LLM_API_KEY is not configured in .env") if not self.base_url: raise LLMError("LLM_BASE_URL is not configured (unknown provider)") + self.max_attempts = max(1, Config.LLM_MAX_ATTEMPTS) + self.retry_delay = Config.LLM_RETRY_DELAY_SECONDS self.client = OpenAI(base_url=self.base_url, api_key=self.api_key, timeout=180.0, max_retries=0) + def _create(self, *, model: str, temperature: float, max_tokens: int, messages, extra_body): + """Run chat.completions.create, retrying transient failures. + + The local LLM server is shared (it also serves Hermes): a concurrent long + generation serializes requests, so a request can be dropped by a client + timeout or a connection reset while it is queued. Retry those transient + cases (openai.APIConnectionError — incl. APITimeoutError) up to + Config.LLM_MAX_ATTEMPTS times so chat survives the queue; a 4xx from the + server (bad key/model) is NOT transient and raises immediately. + """ + import logging + from openai import APIConnectionError + + logger = logging.getLogger(__name__) + for attempt in range(1, self.max_attempts + 1): + try: + return self.client.chat.completions.create( + model=model, + temperature=temperature, + max_tokens=max_tokens, + messages=messages, + extra_body=extra_body, + ) + except APIConnectionError as exc: + if attempt == self.max_attempts: + raise + logger.warning( + "LLM attempt %d/%d failed (%s); retrying in %.1fs", + attempt, + self.max_attempts, + exc, + self.retry_delay, + ) + time.sleep(self.retry_delay) + # Unreachable: the loop either returns a response or raises. + raise LLMError("LLM call failed after retries") + def complete( self, system_prompt: str, @@ -72,7 +112,7 @@ class LLMClient: # (measured 313s -> 44s per persona on the local tabbyAPI server). extra_body = {"enable_thinking": False} try: - resp = self.client.chat.completions.create( + resp = self._create( model=self.model, temperature=temperature, max_tokens=max_tokens, @@ -141,11 +181,12 @@ class LLMClient: mapped = "user" api_messages.append({"role": mapped, "content": m.get("text") or m.get("content") or ""}) try: - resp = self.client.chat.completions.create( + resp = self._create( model=self.model, temperature=temperature, max_tokens=max_tokens, messages=api_messages, + extra_body=None, ) except Exception as exc: raise LLMError(f"LLM call failed: {exc}") from exc diff --git a/backend/tests/test_internal_error_logging.py b/backend/tests/test_internal_error_logging.py new file mode 100644 index 0000000..5bc26c7 --- /dev/null +++ b/backend/tests/test_internal_error_logging.py @@ -0,0 +1,60 @@ +"""internal_error: server log must carry the exception detail for 500 diagnosis, +while the client only ever sees the generic message. + +Uses a handler attached directly to the app logger so the assertion is +independent of suite-wide logging configuration (other tests may set levels +or propagation flags on shared loggers). +""" +from __future__ import annotations + +import logging + +import pytest + +from app.api.helpers import internal_error + + +class _Capture(logging.Handler): + def __init__(self): + super().__init__(level=logging.ERROR) + self.messages: list[str] = [] + + def emit(self, record: logging.LogRecord): + self.messages.append(record.getMessage()) + + +@pytest.fixture() +def captured_logs(app): + handler = _Capture() + app.logger.addHandler(handler) + # Other tests (alembic migrations in test_db_schema) run logging.config + # with disable_existing_loggers=True, which disables the app logger. + # Restore it so this assertion is independent of test order. + app.logger.disabled = False + yield handler + app.logger.removeHandler(handler) + + +def test_internal_error_logs_detail_and_hides_it_from_client(app, captured_logs): + sentinel = "404 model 'qwen3.8' not found on this endpoint" + with app.app_context(): + err = internal_error("LLM service unavailable", ValueError(sentinel)) + + # Client-facing payload stays generic — the sentinel must not leak. + assert err.message == "LLM service unavailable" + assert err.status == 500 + assert sentinel not in err.message + + # Server-side log DOES carry the detail, so a 500 is diagnosable. + logged = " ".join(captured_logs.messages) + assert "LLM service unavailable" in logged + assert "ValueError" in logged + assert sentinel in logged + + +def test_internal_error_default_status_and_type(app, captured_logs): + with app.app_context(): + err = internal_error("boom", RuntimeError("disk full")) + assert err.status == 500 + logged = " ".join(captured_logs.messages) + assert "RuntimeError" in logged and "disk full" in logged diff --git a/backend/tests/test_llm_retry_queue.py b/backend/tests/test_llm_retry_queue.py new file mode 100644 index 0000000..8cd8204 --- /dev/null +++ b/backend/tests/test_llm_retry_queue.py @@ -0,0 +1,95 @@ +"""LLM client: transient failures (timeout / connection reset — what a shared, +queueing LLM server produces under load) are retried so chat survives the queue; +a 4xx from the server (bad key / model) is NOT retried and fails fast. +""" +from __future__ import annotations + +import httpx +import pytest + +from app.llm import LLMClient, LLMError +from openai import APIStatusError, APITimeoutError + + +def _make_client(max_attempts: int = 3) -> LLMClient: + c = LLMClient(base_url="http://localhost:9/v1", api_key="test-key", model="m") + c.max_attempts = max_attempts + c.retry_delay = 0.0 + return c + + +def _resp(): + message = type("M", (), {"content": "ok"})() + choice = type("C", (), {"message": message})() + return type("R", (), {"choices": [choice]})() + + +def _patch_sleep(monkeypatch): + import app.llm as llm + + monkeypatch.setattr(llm.time, "sleep", lambda s: None) + + +def test_transient_failure_retries_then_succeeds(monkeypatch): + c = _make_client(max_attempts=3) + _patch_sleep(monkeypatch) + calls = {"n": 0} + + def flaky(**kwargs): + calls["n"] += 1 + if calls["n"] < 3: + raise APITimeoutError(request="req") + return _resp() + + c.client.chat.completions.create = flaky + assert c.complete("sys", "user") == "ok" + assert calls["n"] == 3 + + +def test_persistent_transient_failure_raises_after_max_attempts(monkeypatch): + c = _make_client(max_attempts=3) + _patch_sleep(monkeypatch) + calls = {"n": 0} + + def always_timeout(**kwargs): + calls["n"] += 1 + raise APITimeoutError(request="req") + + c.client.chat.completions.create = always_timeout + with pytest.raises(LLMError): + c.complete("sys", "user") + assert calls["n"] == 3 + + +def test_4xx_not_retried_fails_fast(monkeypatch): + c = _make_client(max_attempts=3) + _patch_sleep(monkeypatch) + calls = {"n": 0} + + def bad_model(**kwargs): + calls["n"] += 1 + raise APIStatusError( + message="model not found", + response=httpx.Response(404, request="req"), + body=None, + ) + + c.client.chat.completions.create = bad_model + with pytest.raises(LLMError): + c.complete("sys", "user") + # A 4xx is not transient: exactly one attempt, no retry. + assert calls["n"] == 1 + + +def test_success_no_retry(monkeypatch): + c = _make_client(max_attempts=3) + _patch_sleep(monkeypatch) + calls = {"n": 0} + + def ok(**kwargs): + calls["n"] += 1 + return _resp() + + c.client.chat.completions.create = ok + assert c.complete("sys", "user") == "ok" + assert calls["n"] == 1