Files
server-26/drb-c2-core/tests/test_ai_timeouts.py
T
Logan CusanoandClaude Opus 5.5 278edf48dc Explicit timeouts on every OpenAI and Gemini request (#153)
No AI client set a timeout: OpenAI's SDK waits 600s per attempt and retries
twice (timeouts included); google-genai waits forever. A hung provider call
had no upper bound, so recorrelation_sweep's 15-minute pipeline hold-back was
a guess against an unbounded tail.

- config: stt_timeout_seconds (120), openai_timeout_seconds (60),
  openai_max_retries (1), gemini_timeout_seconds (60).
- app/internal/ai_clients.py builds every OpenAI/AsyncOpenAI client with them
  (transcription, extraction, embeddings, summarizer, vocabulary learner,
  trip chat). gemini.py's shared client gets HttpOptions(timeout=ms).
- A timeout raises like any other provider error, so existing fallbacks are
  unchanged: rules-only correlation, rules decision on tiebreak, raw
  transcript on correction, ai_health "transient".
- MIN_MINUTES_SINCE_PIPELINE_START is now derived from those timeouts
  (pipeline_worst_case_seconds, 3-scene budget + 2 min non-AI slack), floor
  15: 21 min with the defaults. Loop warns if it reaches the scan window.
- tests/test_ai_timeouts.py: client limits, a real hung-socket request that
  gives up in <5s, timeout fallback per tier, the derived bound, and a guard
  against any new OpenAI( outside ai_clients.py.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-04 18:00:25 -04:00

247 lines
10 KiB
Python

"""
server-26#153 — no OpenAI or Gemini request ran with an explicit timeout.
OpenAI's SDK waits 600s per attempt and retries twice (timeouts included);
google-genai waits forever. A hung provider call therefore had no upper bound,
and recorrelation_sweep's MIN_MINUTES_SINCE_PIPELINE_START was a guess against
that tail. These tests pin:
- every client is built with the configured timeout / retry budget,
- a hung request really does give up (real SDK, local socket that never answers),
- a timeout takes the same fallback path as any other provider error,
- the sweep hold-back is derived from the timeouts, not hand-picked.
"""
import pathlib
import re
import socket
import threading
import time
from unittest.mock import AsyncMock, patch
import httpx
import openai
import pytest
from app.config import settings
from app.internal import ai_clients, ai_health, gemini, llm_correlator, recorrelation_sweep
from app.internal import intelligence, summarizer, transcript_correction
APP_DIR = pathlib.Path(__file__).resolve().parent.parent / "app"
def _timeout_error() -> openai.APITimeoutError:
return openai.APITimeoutError(request=httpx.Request("POST", "https://api.openai.com/v1/x"))
@pytest.fixture(autouse=True)
def _reset_ai_health():
ai_health._state = {t: ai_health._default_state() for t in ai_health.TIERS}
yield
ai_health._state = {t: ai_health._default_state() for t in ai_health.TIERS}
@pytest.fixture
def openai_key():
with patch.object(settings, "openai_api_key", "sk-test"):
yield
# ── Every client carries the configured limits ──────────────────────────────
def test_openai_client_uses_configured_timeout_and_retries(openai_key):
with patch.object(settings, "openai_timeout_seconds", 42.0), \
patch.object(settings, "openai_max_retries", 1):
client = ai_clients.openai_client()
assert client.timeout == 42.0
assert client.max_retries == 1
def test_openai_client_timeout_override_for_stt(openai_key):
client = ai_clients.openai_client(timeout=settings.stt_timeout_seconds)
assert client.timeout == settings.stt_timeout_seconds
def test_async_openai_client_uses_configured_limits(openai_key):
with patch.object(settings, "openai_timeout_seconds", 7.0), \
patch.object(settings, "openai_max_retries", 0):
client = ai_clients.async_openai_client()
assert client.timeout == 7.0
assert client.max_retries == 0
def test_defaults_are_not_the_sdk_defaults():
# SDK defaults: OpenAI 600s x 3 attempts, Gemini unbounded.
assert settings.stt_timeout_seconds < 600
assert settings.openai_timeout_seconds < 600
assert settings.openai_max_retries < openai.DEFAULT_MAX_RETRIES
assert settings.gemini_timeout_seconds > 0
def test_gemini_client_sets_timeout_in_milliseconds():
saved = gemini._client
gemini._client = None
try:
with patch.object(settings, "gemini_api_key", "test-key"), \
patch.object(settings, "gemini_timeout_seconds", 45.0):
client = gemini._get_client()
assert client._api_client._http_options.timeout == 45_000
finally:
gemini._client = saved
def test_no_openai_client_is_built_outside_ai_clients():
"""Regression guard: a new `OpenAI(...)` elsewhere would silently run on
the 600s SDK default again."""
offenders = []
for path in APP_DIR.rglob("*.py"):
if path.name == "ai_clients.py":
continue
for n, line in enumerate(path.read_text().splitlines(), 1):
if re.search(r"\b(Async)?OpenAI\(", line) or re.search(r"genai\.Client\(", line):
if path.name == "gemini.py" and "genai.Client(" in line:
continue
offenders.append(f"{path.relative_to(APP_DIR)}:{n}: {line.strip()}")
assert offenders == []
# ── A hung request actually gives up ────────────────────────────────────────
@pytest.fixture
def hung_server():
"""A TCP server that accepts connections and never sends a byte."""
srv = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
srv.bind(("127.0.0.1", 0))
srv.listen(8)
conns = []
stop = threading.Event()
def accept():
srv.settimeout(0.1)
while not stop.is_set():
try:
conns.append(srv.accept()[0])
except OSError:
continue
t = threading.Thread(target=accept, daemon=True)
t.start()
yield f"http://127.0.0.1:{srv.getsockname()[1]}/v1"
stop.set()
t.join(timeout=2)
for c in conns:
c.close()
srv.close()
def test_hung_openai_request_times_out_instead_of_waiting_600s(openai_key, hung_server, monkeypatch):
monkeypatch.setenv("OPENAI_BASE_URL", hung_server)
with patch.object(settings, "openai_timeout_seconds", 0.3), \
patch.object(settings, "openai_max_retries", 1):
client = ai_clients.openai_client()
t0 = time.monotonic()
with pytest.raises(openai.APITimeoutError):
client.chat.completions.create(model="gpt-4o-mini", messages=[{"role": "user", "content": "x"}])
elapsed = time.monotonic() - t0
# 2 attempts x 0.3s + SDK backoff (<~1s); far below the 600s default.
assert elapsed < 5
# ── Timeouts degrade exactly like other provider errors ────────────────────
def test_timeout_messages_classify_as_transient():
assert ai_health.classify(str(_timeout_error())) == "transient"
assert ai_health.classify(str(httpx.ReadTimeout("The read operation timed out"))) == "transient"
def _corr_ctx():
return {"call_id": "c1", "is_thin_call": False, "recent": [{"incident_id": "i1"}],
"all_active": [], "call_units": ["12"], "call_cleared": [], "tags": ["mva"]}
@pytest.mark.asyncio
async def test_gemini_timeout_in_decide_falls_back_to_rules():
def hang(model, prompt):
raise httpx.ReadTimeout("The read operation timed out")
with patch.object(settings, "gemini_api_key", "test-key"), \
patch.object(llm_correlator, "_build_decide_prompt", lambda ctx: "p"), \
patch.object(llm_correlator, "_sync_gemini", hang):
assert await llm_correlator.decide("c1", _corr_ctx()) is None # None == rules_only
state = ai_health.snapshot()["correlation_cheap"]
assert state["consecutive_failures"] == 1
assert state["permanent"] is False
@pytest.mark.asyncio
async def test_gemini_timeout_in_tiebreak_keeps_the_rules_decision():
def hang(model, prompt):
raise httpx.ReadTimeout("The read operation timed out")
rules = {"action": "new", "matched_incident": None, "corr_debug": {}}
with patch.object(llm_correlator, "_build_tiebreak_prompt", lambda r, l, c: "p"), \
patch.object(llm_correlator, "_sync_gemini", hang):
out = await llm_correlator.tiebreak(rules, {"action": "orphan"}, _corr_ctx())
assert out is rules
assert ai_health.snapshot()["correlation_smart"]["permanent"] is False
@pytest.mark.asyncio
async def test_gemini_timeout_in_transcript_correction_keeps_raw_text():
def hang(model, prompt):
raise httpx.ReadTimeout("The read operation timed out")
text = "engine 5 respond to a structure fire at 12 main street smoke showing"
with patch.object(settings, "gemini_api_key", "test-key"), \
patch.object(transcript_correction, "resolve_context", AsyncMock(return_value={})), \
patch.object(transcript_correction, "_sync_gemini", hang):
assert await transcript_correction.correct("c1", text) == (None, None, False)
class _TimingOutOpenAI:
"""Stands in for the client ai_clients builds; every endpoint times out."""
def __init__(self, *a, **k):
self.chat = self.embeddings = self
self.completions = self
def create(self, **kwargs):
raise _timeout_error()
def test_extraction_timeout_propagates_to_the_ai_health_path(openai_key):
# _sync_extract re-raises API failures so extract_scenes reports them to
# ai_health (tier "extraction"); a timeout must not be swallowed as "no scenes".
with patch.object(ai_clients, "openai_client", _TimingOutOpenAI):
with pytest.raises(openai.APITimeoutError):
intelligence._sync_extract("unit 12 on scene", "PD Dispatch", 1, "sys", None)
def test_embedding_timeout_returns_none(openai_key):
with patch.object(ai_clients, "openai_client", _TimingOutOpenAI):
assert intelligence._sync_embed("unit 12 on scene") is None
def test_summary_timeout_returns_none(openai_key):
with patch.object(ai_clients, "openai_client", _TimingOutOpenAI):
assert summarizer._sync_summarize({"type": "fire"}, ["engine 5 on scene"]) is None
# ── The sweep hold-back is derived from the timeouts ────────────────────────
def test_worst_case_bound_follows_the_settings():
with patch.object(settings, "stt_timeout_seconds", 100.0), \
patch.object(settings, "openai_timeout_seconds", 10.0), \
patch.object(settings, "openai_max_retries", 1), \
patch.object(settings, "gemini_timeout_seconds", 20.0), \
patch.object(settings, "stt_retry_on_degenerate", True):
bound = recorrelation_sweep.pipeline_worst_case_seconds(n_scenes=2)
# stt 2x2x100 + correction 20 + extraction 2x10 + embeds 2x2x10 + decide/tiebreak 2x20 + slack
assert bound == 400 + 20 + 20 + 40 + 40 + recorrelation_sweep._NON_AI_SLACK_SECONDS
def test_hold_back_covers_the_worst_case_and_never_drops_below_old_floor():
bound_min = recorrelation_sweep.pipeline_worst_case_seconds() / 60
assert recorrelation_sweep.MIN_MINUTES_SINCE_PIPELINE_START >= bound_min
assert recorrelation_sweep.MIN_MINUTES_SINCE_PIPELINE_START >= 15
# ...and stays inside the scan window, or the sweep could never recover a
# call whose pipeline died after writing intelligence_started_at.
assert recorrelation_sweep.MIN_MINUTES_SINCE_PIPELINE_START < settings.recorrelation_scan_minutes