fix: retry transient LLM failures to survive shared-server queue, log 500 detail

- llm.py: _create() wrapper retries APIConnectionError (incl. timeout) up to
  LLM_MAX_ATTEMPTS=3 with LLM_RETRY_DELAY_SECONDS=5s backoff; 4xx still fails
  fast. The local LLM server is shared with Hermes and serializes requests, so
  a request can be dropped by the client timeout while queued — chat/send was
  500ing on that.
- helpers.py: internal_error() now logs full exception detail server-side
  (was only the type name), so 500s are diagnosable; client message unchanged.
- config.py: LLM_MAX_ATTEMPTS / LLM_RETRY_DELAY_SECONDS env knobs.
- tests: test_llm_retry_queue (transient retried, 4xx not retried, no retry on
  success), test_internal_error_logging (detail in log, hidden from client,
  order-independent via explicit handler + logger re-enable).
This commit is contained in:
Macky
2026-10-02 17:04:55 +07:00
parent f63f1867f5
commit d17462edc4
5 changed files with 213 additions and 4 deletions

View File

@@ -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)

View File

@@ -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

View File

@@ -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

View File

@@ -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

View File

@@ -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