From 14f403eca70fd2c5d55ee740eb68ae6c28152924 Mon Sep 17 00:00:00 2001 From: withrvr Date: Mon, 14 Sep 2026 14:52:06 +0000 Subject: [PATCH 1/2] feat(observability): Prometheus /metrics and the missing ws.session wide event (Phase 13) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Active games/connections, agent turn latency/error/timeout counters per model, moves, and model-swap counts (DECISIONS.md §14) -- hooked into the existing single centralizing spot for each (AgentController._metrics, Referee._commit/_take_turn, RoomService.start/_finish_room), not new call sites. Also wires the ws.session wide event that docs/admin-and- observability.md has listed since Phase 1 but nothing ever built. The model-swap-aware turn *scheduler* DECISIONS §13 also describes remains explicitly out of scope: this only counts swaps, it doesn't yet try to minimise them. Also fixes a real onboarding bug found while adding this phase's one new dependency: docs/development/setup.md's documented `uv sync` silently drops the workspace-root dev tooling group (prek/zizmor/smokeshow) from the shared venv. Claude-Session: https://claude.ai/code/session_01UbiPa1rKCyqhqufgwJWkeW --- PROGRESS.md | 95 +++++++++++++- backend/app/agents/controller.py | 12 ++ backend/app/api/main.py | 2 + backend/app/api/routes/metrics.py | 19 +++ backend/app/api/routes/rooms.py | 26 +++- backend/app/llm/client.py | 2 + backend/app/llm/fake.py | 1 + backend/app/metrics.py | 72 ++++++++++ backend/app/referee/referee.py | 6 + backend/app/rooms/service.py | 7 + backend/pyproject.toml | 1 + backend/tests/observability/__init__.py | 0 backend/tests/observability/test_metrics.py | 137 ++++++++++++++++++++ backend/tests/rooms/test_room_service.py | 64 +++++++++ backend/tests/rooms/test_rooms_ws.py | 44 +++++++ docs/admin-and-observability.md | 38 ++++-- docs/api/api-reference.md | 9 ++ docs/development/setup.md | 16 ++- frontend/src/client/index.ts | 4 +- frontend/src/client/sdk.gen.ts | 15 ++- frontend/src/client/types.gen.ts | 14 ++ uv.lock | 11 ++ 22 files changed, 573 insertions(+), 22 deletions(-) create mode 100644 backend/app/api/routes/metrics.py create mode 100644 backend/app/metrics.py create mode 100644 backend/tests/observability/__init__.py create mode 100644 backend/tests/observability/test_metrics.py diff --git a/PROGRESS.md b/PROGRESS.md index 0e135db..8f9e252 100644 --- a/PROGRESS.md +++ b/PROGRESS.md @@ -41,8 +41,8 @@ branch; only the phase branch opens a PR into `master`. | 9.7 | Docker, CI/CD, and server-start optimization | done 2026-09-14 (PR #18) | | 10 | Frontend: play, spectate, admin, focus view | done 2026-09-14 (PR #20) | | 11 | Chat and personas | done 2026-09-14 (PR #21) | -| 12 | Leaderboard | done 2026-09-14 (branch phase-12-leaderboard, PR pending) | -| 13 | Observability | | +| 12 | Leaderboard | done 2026-09-14 (PR #22) | +| 13 | Observability | done 2026-09-14 (branch phase-13-observability, PR pending) | | 14 | CI/CD (local dry-run; no server yet) | | | 15 | Production deployment (deferred until local complete) | | | 16 | Scale and polish | | @@ -1101,6 +1101,97 @@ the two list routes (python-reviewer, MEDIUM) -- already documented as a found-but-deferred gap in `docs/leaderboard.md`'s "Left for later" section before either review even ran. +## Phase 13 — done 2026-09-14 (branch phase-13-observability) + +Self-planned (no formal spec; a direct continuation of context already in +hand). DECISIONS.md §14: "Prometheus `/metrics`... everything inspectable +locally." Scoped by first reading what already existed rather than +assuming: wide events (Phase 1), `/health`/`/health/llm` (Phase 1/6) were +already fully built. Only two real gaps: no `/metrics` at all, and +`docs/admin-and-observability.md`'s own `ws.session` wide event -- listed +in that doc's table since Phase 1 -- had never actually been wired into +the websocket route. + +- **`app/metrics.py`** (new): a dedicated `CollectorRegistry` (not + `prometheus_client`'s process-global default, so `/metrics` is explicit + about exactly what it exposes and test collection can't hit the + classic "duplicated metric name" footgun). `botpit_active_games`/ + `botpit_active_ws_connections` (gauges), `botpit_agent_turn_latency_seconds`/ + `_errors_total` (per model), `botpit_agent_turn_timeouts_total` (agent + seats only, not `scripted`), `botpit_moves_total`, `botpit_model_swaps_total` + (per `base_url`). "Moves per minute" (DECISIONS §14's own wording) is a + plain counter, not a stored per-minute number -- graphing `rate()` over + it is Prometheus's own idiom for exactly this. +- **`GET /metrics`** (new route, unauthenticated like `/health`): Prometheus + text exposition of that registry. +- **Instrumentation, hooked at the existing single centralizing spot in + each case rather than adding new ones**: `AgentController._metrics` + (already fed the wide event's `llm.calls`) now also records the + latency histogram and error counter; `Referee._commit` (already the one + place a move lands) increments `MOVES_TOTAL`; `Referee._take_turn`'s + existing `TimeoutError` branch increments the timeout counter for real + agent seats; `RoomService.start`/`_finish_room` (already the exactly- + once start/finish pair the archiving logic relies on) increment/decrement + `ACTIVE_GAMES` symmetrically. +- **`app.metrics.note_llm_call(base_url, model)`**: called right before + every real outbound LLM completion request + (`AgentController.decide`). Counts a swap when the immediately + preceding call to the same `base_url` used a different model -- + DECISIONS §13's "surface swap counts in metrics," not the model-swap- + *aware scheduler* that decision also describes (grouping concurrent AI + turns by model to minimise swaps). That scheduler does not exist and is + explicitly out of scope here: this phase is Observability, not + scheduling, and this counter is exactly what would tell a future phase + whether building it is worth it. Needed `base_url: str` added to the + `LLMClient` Protocol (both real adapters already had it; `FakeLLMClient` + needed a `base_url` attribute added too, or every existing agent test + using it would have started raising `AttributeError`). +- **`ws.session` wide event + `ACTIVE_WS_CONNECTIONS`** + (`app/api/routes/rooms.py`'s `room_ws`): wraps the accepted-connection + lifecycle (not the earlier auth/admission refusals -- a "session" is an + established connection). `events_sent` via `ev.incr` per message sent; + `close_reason="client_disconnect"` on a clean `WebSocketDisconnect`; any + other exception's type/message land in the wide event's own `error.*` + fields automatically, same as every other wide event. The gauge is + incremented right after `accept()` and decremented in a `finally`, so it + comes back down regardless of how the connection ends. +- **Found and fixed in passing, not this phase's actual subject**: + `docs/admin-and-observability.md`'s wide-event table named `agent.turn` + as the event kind; the real `event_kind` (and every seat kind, not just + agents) has always been `game.turn` -- corrected. +- **A real onboarding bug, found while adding this phase's one new + dependency (`prometheus-client`)**: ran a bare `uv sync` from `backend/` + to add it, which silently *removed* `prek`/`zizmor`/`smokeshow` from the + shared venv -- they're workspace-root `dev`/`github-actions` dependency + groups (root `pyproject.toml`), not part of `backend/pyproject.toml`'s + own `dependencies`, and this repo has exactly one `.venv` shared by the + whole uv workspace regardless of which member directory `uv sync` runs + from. `docs/development/setup.md` documented the exact bare `uv sync` + command that causes this -- meaning a fresh clone following that guide + verbatim would never get a working `prek run --all-files` gate at all. + Fixed the doc to use `uv sync --all-groups` and explained why, restored + the local venv the same way, and re-verified `uv run prek --version`/ + `uv run zizmor --version` both work again before continuing. + +New tests: `backend/tests/observability/test_metrics.py` (5: the route +returns valid Prometheus text, `note_llm_call`'s swap-counting logic in +isolation, agent-turn latency/error metrics via a real `decide()` call, a +real `Referee.run()` agent-seat timeout incrementing the counter, the +registry never exposes anything but `botpit_*` names). +`tests/rooms/test_room_service.py` (+2: `ACTIVE_GAMES` tracks a real +start/finish cycle, `MOVES_TOTAL` increments on a real submitted move -- +both poll rather than assume `_finish_room`'s async completion callback +already ran, matching this file's own established pattern for that race). +`tests/rooms/test_rooms_ws.py` (+1: `ACTIVE_WS_CONNECTIONS` and the +`ws.session` wide event's fields, over a real websocket connection) (787 +backend tests total; 59 Playwright tests, unchanged -- this phase touched +no frontend code). + +Full gate: backend suite (787 tests) green, `ty`/`mypy`/`ruff` clean, +verified the new `/metrics` route against the real built Docker image +(not just `TestClient`), full Playwright suite (59 tests, unchanged) +green against the real docker compose stack, `prek run --all-files` clean. + ## Phase 9.7 — done 2026-09-14 (branch phase-9.7-infra-optimization) Infrastructure-only pass: Docker image build, Compose, CI/CD workflows, diff --git a/backend/app/agents/controller.py b/backend/app/agents/controller.py index 164a7f4..e933780 100644 --- a/backend/app/agents/controller.py +++ b/backend/app/agents/controller.py @@ -21,6 +21,11 @@ ) from app.games.base import AnyGame, PlayerView, Seat from app.llm.client import CompletionRequest, LLMClient, LLMError, Message, with_retries +from app.metrics import ( + AGENT_TURN_ERRORS_TOTAL, + AGENT_TURN_LATENCY_SECONDS, + note_llm_call, +) from app.referee.seats import ControllerError, SeatKind, TurnContext from app.telemetry import current_event, get_logger @@ -92,6 +97,7 @@ async def decide(self, view: PlayerView, ctx: TurnContext) -> dict[str, Any]: think=self.think, ) try: + note_llm_call(self.client.base_url, self.model) result = await with_retries( functools.partial(self.client.complete, req) ) @@ -196,6 +202,12 @@ def _metrics(self, **fields: Any) -> None: ev = current_event() if ev is not None: ev.add("llm.calls", {"model": self.model, **fields}) + AGENT_TURN_LATENCY_SECONDS.labels(model=self.model).observe( + fields.get("latency_ms", 0) / 1000 + ) + error = fields.get("error") + if error is not None: + AGENT_TURN_ERRORS_TOTAL.labels(model=self.model, error=error).inc() async def _publish(self, payload: Any, visibility: Any) -> None: correlation = {"game_id": self.game_id} if self.game_id else {} diff --git a/backend/app/api/main.py b/backend/app/api/main.py index 380a7fd..c7dc14f 100644 --- a/backend/app/api/main.py +++ b/backend/app/api/main.py @@ -7,6 +7,7 @@ items, leaderboard, login, + metrics, private, roles, rooms, @@ -27,6 +28,7 @@ api_router.include_router(rooms.router) api_router.include_router(games.router) api_router.include_router(leaderboard.router) +api_router.include_router(metrics.router) if settings.FASTAPI_ENV == "development": diff --git a/backend/app/api/routes/metrics.py b/backend/app/api/routes/metrics.py new file mode 100644 index 0000000..d9bbf63 --- /dev/null +++ b/backend/app/api/routes/metrics.py @@ -0,0 +1,19 @@ +"""``GET /metrics`` (Phase 13, DECISIONS.md §14): Prometheus text +exposition of ``app.metrics.REGISTRY``. Unauthenticated, matching +``GET /health`` -- both are operational endpoints meant for a scraper/ +monitor, not user data, and Prometheus scrape configs rarely carry a +bearer token easily.""" + +from __future__ import annotations + +from fastapi import APIRouter, Response +from prometheus_client import CONTENT_TYPE_LATEST, generate_latest + +from app.metrics import REGISTRY + +router = APIRouter(tags=["metrics"]) + + +@router.get("/metrics") +def metrics() -> Response: + return Response(generate_latest(REGISTRY), media_type=CONTENT_TYPE_LATEST) diff --git a/backend/app/api/routes/rooms.py b/backend/app/api/routes/rooms.py index b5afa50..0c3b138 100644 --- a/backend/app/api/routes/rooms.py +++ b/backend/app/api/routes/rooms.py @@ -40,6 +40,7 @@ from app.events import Subscriber, filter_for_subscriber from app.games import get_game from app.games.move_schema import move_json_schema +from app.metrics import ACTIVE_WS_CONNECTIONS from app.models import ( Message, Room, @@ -63,6 +64,7 @@ RoomNotWaitingError, RoomService, ) +from app.telemetry import wide_event router = APIRouter(prefix="/rooms", tags=["rooms"]) @@ -568,10 +570,22 @@ async def room_ws( return await websocket.accept() + ACTIVE_WS_CONNECTIONS.inc() try: - async for event in service.bus.subscribe(str(room_id), since=since): - filtered = filter_for_subscriber(event, subscriber) - if filtered is not None: - await websocket.send_json(filtered.model_dump(mode="json")) - except WebSocketDisconnect: - pass + with wide_event( + "ws.session", + room_id=str(room_id), + user_id=str(user.id), + subscriber_kind=subscriber.kind, + seat=subscriber.seat, + ) as ev: + try: + async for event in service.bus.subscribe(str(room_id), since=since): + filtered = filter_for_subscriber(event, subscriber) + if filtered is not None: + await websocket.send_json(filtered.model_dump(mode="json")) + ev.incr("events_sent") + except WebSocketDisconnect: + ev.set(close_reason="client_disconnect") + finally: + ACTIVE_WS_CONNECTIONS.dec() diff --git a/backend/app/llm/client.py b/backend/app/llm/client.py index a06b568..c4a0e50 100644 --- a/backend/app/llm/client.py +++ b/backend/app/llm/client.py @@ -68,6 +68,8 @@ def __init__(self, message: str) -> None: class LLMClient(Protocol): + base_url: str + async def complete(self, req: CompletionRequest) -> CompletionResult: ... async def aclose(self) -> None: ... diff --git a/backend/app/llm/fake.py b/backend/app/llm/fake.py index b871cce..5ea3b10 100644 --- a/backend/app/llm/fake.py +++ b/backend/app/llm/fake.py @@ -29,6 +29,7 @@ def __init__( self._fn = responses self.latency_s = latency_s self.requests: list[CompletionRequest] = [] + self.base_url = "fake://test" async def complete(self, req: CompletionRequest) -> CompletionResult: self.requests.append(req) diff --git a/backend/app/metrics.py b/backend/app/metrics.py new file mode 100644 index 0000000..926c171 --- /dev/null +++ b/backend/app/metrics.py @@ -0,0 +1,72 @@ +"""Prometheus metrics (Phase 13, DECISIONS.md §14): active games, active +websocket connections, agent turn latency/errors per model, moves, +model swaps. Complements the wide-event log (``app/telemetry``) rather +than duplicating it -- wide events are for debugging one request/turn/ +game after the fact; these are for graphing trends over time. + +A dedicated ``CollectorRegistry`` rather than ``prometheus_client``'s +process-global default: keeps ``GET /metrics`` explicit about exactly +what it exposes, and avoids the classic "duplicated metric name" footgun +if this module is ever imported twice under different names (it happens +in test collection more often than you'd expect). +""" + +from __future__ import annotations + +from prometheus_client import CollectorRegistry, Counter, Gauge, Histogram + +REGISTRY = CollectorRegistry() + +ACTIVE_GAMES = Gauge( + "botpit_active_games", "Rooms currently in_progress", registry=REGISTRY +) +ACTIVE_WS_CONNECTIONS = Gauge( + "botpit_active_ws_connections", + "Open room websocket connections", + registry=REGISTRY, +) +AGENT_TURN_LATENCY_SECONDS = Histogram( + "botpit_agent_turn_latency_seconds", + "Latency of one LLM completion call within an agent's turn", + ["model"], + registry=REGISTRY, +) +AGENT_TURN_ERRORS_TOTAL = Counter( + "botpit_agent_turn_errors_total", + "LLM completion calls that failed or produced an unusable reply", + ["model", "error"], + registry=REGISTRY, +) +AGENT_TURN_TIMEOUTS_TOTAL = Counter( + "botpit_agent_turn_timeouts_total", + "Turns that hit their deadline and fell back to the referee's own move", + ["model"], + registry=REGISTRY, +) +MOVES_TOTAL = Counter( + "botpit_moves_total", "Moves applied across every game", registry=REGISTRY +) +MODEL_SWAPS_TOTAL = Counter( + "botpit_model_swaps_total", + "Consecutive LLM calls to the same backend that changed model -- a " + "likely VRAM swap (DECISIONS.md §13); the turn scheduler that would " + "actively minimise these remains a separate, not-yet-built feature, " + "this just counts them", + ["base_url"], + registry=REGISTRY, +) + +_last_model_by_base_url: dict[str, str] = {} + + +def note_llm_call(base_url: str, model: str) -> None: + """Call once right before every real outbound LLM completion request. + Increments ``MODEL_SWAPS_TOTAL`` when the immediately preceding call to + this same ``base_url`` used a different model. Synchronous with no + ``await`` between the read and the write, so concurrent asyncio tasks + cannot race this -- the same reasoning ``ModelRegistry.client_for`` + already relies on for its own check-then-insert.""" + last = _last_model_by_base_url.get(base_url) + if last is not None and last != model: + MODEL_SWAPS_TOTAL.labels(base_url=base_url).inc() + _last_model_by_base_url[base_url] = model diff --git a/backend/app/referee/referee.py b/backend/app/referee/referee.py index f6a8dc9..af10bef 100644 --- a/backend/app/referee/referee.py +++ b/backend/app/referee/referee.py @@ -30,6 +30,7 @@ ) from app.games import get_game from app.games.base import AnyGame, GameState, IllegalMoveError, Move, Seat +from app.metrics import AGENT_TURN_TIMEOUTS_TOTAL, MOVES_TOTAL from app.referee.seats import ( ControllerError, SeatController, @@ -221,6 +222,10 @@ async def _take_turn(self, seat: Seat) -> None: move = candidate except TimeoutError: ev.set(fallback=True, fallback_reason="timeout", timed_out=True) + if spec.kind == "agent": + AGENT_TURN_TIMEOUTS_TOTAL.labels( + model=spec.model or "unknown" + ).inc() move, next_state = self._fallback(seat) await self._publish( TurnTimedOut(seat=seat, fallback_move=move.model_dump(mode="json")), @@ -243,6 +248,7 @@ async def _commit(self, move: Move, next_state: GameState) -> None: self.state = next_state raw = move.model_dump(mode="json") self.moves.append(raw) + MOVES_TOTAL.inc() description = self.game.describe_move(move) await self._publish( MoveApplied( diff --git a/backend/app/rooms/service.py b/backend/app/rooms/service.py index 846db1c..224f5ad 100644 --- a/backend/app/rooms/service.py +++ b/backend/app/rooms/service.py @@ -41,6 +41,7 @@ make_event, ) from app.games import Seat, get_game +from app.metrics import ACTIVE_GAMES from app.models import ( GameEvent, GameRecord, @@ -551,6 +552,7 @@ async def start(self, room_id: uuid.UUID) -> Room: self.session.add(room) self.session.commit() self.session.refresh(room) + ACTIVE_GAMES.inc() return room async def _finish_room(self, room_id: str, outcome: str) -> None: @@ -576,6 +578,11 @@ async def _finish_room(self, room_id: str, outcome: str) -> None: room = session.get(Room, uuid.UUID(room_id)) if room is None: return + # Unconditional, not nested in the status-write guard below -- + # same reasoning as archiving: this callback fires exactly once + # per game no matter which side won the `stop()` race, so the + # gauge must always come back down exactly once too. + ACTIVE_GAMES.dec() if room.status == "in_progress": room.status = outcome room.finished_at = get_datetime_utc() diff --git a/backend/pyproject.toml b/backend/pyproject.toml index 01e58e2..ab284f6 100644 --- a/backend/pyproject.toml +++ b/backend/pyproject.toml @@ -21,6 +21,7 @@ dependencies = [ # botpit "redis[hiredis]>=8.1.0", "websockets>=13", + "prometheus-client>=0.26.0,<1.0.0", ] [dependency-groups] diff --git a/backend/tests/observability/__init__.py b/backend/tests/observability/__init__.py new file mode 100644 index 0000000..e69de29 diff --git a/backend/tests/observability/test_metrics.py b/backend/tests/observability/test_metrics.py new file mode 100644 index 0000000..1b170a9 --- /dev/null +++ b/backend/tests/observability/test_metrics.py @@ -0,0 +1,137 @@ +"""Prometheus metrics (Phase 13, DECISIONS.md §14). Pure/unit-level checks +that don't need a real Room/RoomService/Redis -- those live alongside the +fixtures they need (``ACTIVE_GAMES``/``MOVES_TOTAL`` in +``tests/rooms/test_room_service.py``, the ``ws.session`` wide event and +``ACTIVE_WS_CONNECTIONS`` in ``tests/rooms/test_rooms_ws.py``). +""" + +from __future__ import annotations + +import asyncio +import json + +from fastapi.testclient import TestClient + +from app.agents import AgentController, get_persona +from app.events import InMemoryEventBus +from app.games import get_game +from app.llm.fake import FakeLLMClient +from app.metrics import ( + AGENT_TURN_ERRORS_TOTAL, + AGENT_TURN_LATENCY_SECONDS, + AGENT_TURN_TIMEOUTS_TOTAL, + MODEL_SWAPS_TOTAL, + REGISTRY, + note_llm_call, +) +from app.referee import PolicyController, Referee, SeatSpec, TurnContext +from app.telemetry import wide_event + + +def test_metrics_route_returns_prometheus_text(client: TestClient) -> None: + r = client.get("/api/v1/metrics") + assert r.status_code == 200, r.text + assert r.headers["content-type"].startswith("text/plain") + body = r.text + # Unlabeled gauges/counters are always present once registered, even at + # zero; labeled ones (agent turn latency, swaps) only appear once + # observed at least once, so only assert the always-present ones here. + assert "botpit_active_games" in body + assert "botpit_active_ws_connections" in body + assert "botpit_moves_total" in body + + +def test_note_llm_call_counts_a_swap_only_when_model_changes() -> None: + base_url = "http://fake-swap-test:1" # unique per test, never reused elsewhere + before = MODEL_SWAPS_TOTAL.labels(base_url=base_url)._value.get() + + note_llm_call(base_url, "model-a") + note_llm_call(base_url, "model-a") # same model: not a swap + assert MODEL_SWAPS_TOTAL.labels(base_url=base_url)._value.get() == before + + note_llm_call(base_url, "model-b") # different model: a swap + assert MODEL_SWAPS_TOTAL.labels(base_url=base_url)._value.get() == before + 1 + + note_llm_call(base_url, "model-a") # swapped back: still a swap + assert MODEL_SWAPS_TOTAL.labels(base_url=base_url)._value.get() == before + 2 + + +async def test_agent_turn_latency_and_error_metrics_recorded_via_decide() -> None: + game = get_game("uno_classic") + state = game.new_game(1, 2) + seat = game.current_seat(state) + assert seat is not None + view = game.player_view(state, seat) + bus = InMemoryEventBus() + + model = "observability-test-model" + latency_before = AGENT_TURN_LATENCY_SECONDS.labels(model=model)._sum.get() + error_before = AGENT_TURN_ERRORS_TOTAL.labels( + model=model, error="bad_json" + )._value.get() + + # First reply fails `_parse_answer` (not JSON at all) -- records a + # `latency_ms` observation and an `error="bad_json"` count via + # `_metrics` -- then the repair retry gets a real legal move, so + # `decide()` completes normally instead of raising. + good_reply = json.dumps({"reasoning": "ok", "move": view.legal_moves[0]}) + client = FakeLLMClient(["not json", good_reply], latency_s=0.01) + agent = AgentController(game, client, model, get_persona("steady"), bus, "r", seat) + ctx = TurnContext( + room_id="r", seat=seat, turn_id="t", attempt=1, deadline=1e9, last_error=None + ) + with wide_event("game.turn"): + move = await agent.decide(view, ctx) + + assert move == view.legal_moves[0] + assert AGENT_TURN_LATENCY_SECONDS.labels(model=model)._sum.get() > latency_before + assert ( + AGENT_TURN_ERRORS_TOTAL.labels(model=model, error="bad_json")._value.get() + == error_before + 1 + ) + + +async def test_agent_turn_timeout_increments_the_counter() -> None: + """The referee's own turn deadline (not `AgentController` itself) is + what times out -- needs a real `Referee.run()`, mirroring + `test_human_retries_until_deadline_then_fallback` but for an agent seat.""" + game = get_game("uno_classic") + bus = InMemoryEventBus(maxlen=10_000) + model = "observability-timeout-model" + slow_client = FakeLLMClient(latency_s=5.0) # far past the seat's own timeout + agent = AgentController( + game, slow_client, model, get_persona("steady"), bus, "r", 1 + ) + ref = Referee( + game, + bus, + "r", + 1, + [ + SeatSpec(seat=0, kind="scripted", player="b"), + SeatSpec(seat=1, kind="agent", player="a", model=model, timeout_s=0.05), + ], + {0: PolicyController(), 1: agent}, + ) + before = AGENT_TURN_TIMEOUTS_TOTAL.labels(model=model)._value.get() + task = asyncio.create_task(ref.run()) + for _ in range(500): + if AGENT_TURN_TIMEOUTS_TOTAL.labels(model=model)._value.get() > before: + break + await asyncio.sleep(0.01) + else: + task.cancel() + raise AssertionError("agent turn never timed out within 5s") + task.cancel() + try: + await task + except asyncio.CancelledError: + pass + assert AGENT_TURN_TIMEOUTS_TOTAL.labels(model=model)._value.get() == before + 1 + + +def test_registry_only_exposes_botpit_metrics() -> None: + """The dedicated registry (not `prometheus_client`'s process-global + default) means `/metrics` never leaks unrelated process metrics.""" + names = {m.name for m in REGISTRY.collect()} + assert all(name.startswith("botpit_") for name in names) diff --git a/backend/tests/rooms/test_room_service.py b/backend/tests/rooms/test_room_service.py index f85bacb..dd4dff0 100644 --- a/backend/tests/rooms/test_room_service.py +++ b/backend/tests/rooms/test_room_service.py @@ -19,6 +19,7 @@ from app.authz.permissions import P from app.core.config import settings from app.events import InMemoryEventBus +from app.metrics import ACTIVE_GAMES, MOVES_TOTAL from app.models import RoomCreate, RoomSeatSpec from app.referee import GameRunner from app.rooms.codes import is_valid_code @@ -353,6 +354,69 @@ async def test_all_agent_room_starts_directly( assert runner.active() == [] +# -- observability (Phase 13) -------------------------------------------------- + + +async def test_active_games_gauge_tracks_start_and_finish( + db: Session, service: RoomService, runner: GameRunner +) -> None: + before = ACTIVE_GAMES._value.get() + creator = create_random_user(db) + room = await service.create(creator, _two_agent()) + await service.start(room.id) + assert ACTIVE_GAMES._value.get() == before + 1 + + await service.stop(room.id, "test cleanup") + # `_finish_room` (the decrement) races `stop()`'s own return, per its own + # docstring -- poll rather than assume it already ran. + for _ in range(200): + if ACTIVE_GAMES._value.get() == before: + break + await asyncio.sleep(0.01) + assert ACTIVE_GAMES._value.get() == before + + +async def test_moves_total_increments_when_a_move_is_submitted( + db: Session, service: RoomService, runner: GameRunner +) -> None: + creator = create_random_user(db) + other = create_random_user(db) + room = await service.create( + creator, + RoomCreate( + game="uno_classic", + seat_count=2, + visibility="private", + seats=[ + RoomSeatSpec(kind="human", user_id=creator.id), + RoomSeatSpec(kind="human"), + ], + ), + ) + await service.join_by_code(other, room.code) + await service.start(room.id) + + running = runner.get(str(room.id)) + current_seat = running.game.current_seat(running.state) + assert current_seat is not None + current_user = next( + creator if s.user_id == creator.id else other + for s in service.seats(room.id) + if s.seat == current_seat + ) + view = running.game.player_view(running.state, current_seat) + + before = MOVES_TOTAL._value.get() + service.submit_move(current_user, room.id, view.legal_moves[0]) + for _ in range(200): + if MOVES_TOTAL._value.get() > before: + break + await asyncio.sleep(0.01) + assert MOVES_TOTAL._value.get() == before + 1 + + await service.stop(room.id, "test cleanup") + + # -- chat (Phase 11) ---------------------------------------------------------- diff --git a/backend/tests/rooms/test_rooms_ws.py b/backend/tests/rooms/test_rooms_ws.py index 56e6cfd..1ff66e3 100644 --- a/backend/tests/rooms/test_rooms_ws.py +++ b/backend/tests/rooms/test_rooms_ws.py @@ -7,6 +7,7 @@ from __future__ import annotations import concurrent.futures +import logging import time from collections.abc import Iterator from typing import Any @@ -16,6 +17,7 @@ from starlette.websockets import WebSocketDisconnect from app.core.config import settings +from app.metrics import ACTIVE_WS_CONNECTIONS pytestmark = pytest.mark.redis @@ -382,6 +384,48 @@ def test_ws_ticket_works_as_a_ws_token(client: TestClient, live_game: LiveGame) assert events +# -- observability (Phase 13) -------------------------------------------------- + + +def test_ws_session_wide_event_and_connection_gauge( + client: TestClient, live_game: LiveGame, caplog: pytest.LogCaptureFixture +) -> None: + room_id, seats = live_game + headers = seats[0] + caplog.set_level(logging.INFO, logger="botpit.wide") + + ticket = client.get(f"{API}/rooms/{room_id}/ws-ticket", headers=headers).json()[ + "ticket" + ] + before = ACTIVE_WS_CONNECTIONS._value.get() + with client.websocket_connect( + f"{API}/rooms/{room_id}/ws?token={ticket}&since=0" + ) as ws: + assert ACTIVE_WS_CONNECTIONS._value.get() == before + 1 + _recv_until( + ws, lambda seen: any(e["type"] == "game.started" for e in seen), timeout=5.0 + ) + # `with` exiting closes the connection; the gauge decrement happens in + # the route's own `finally`, on the server side of the same in-process + # ASGI app -- poll rather than assume it already landed. + for _ in range(200): + if ACTIVE_WS_CONNECTIONS._value.get() == before: + break + time.sleep(0.01) + assert ACTIVE_WS_CONNECTIONS._value.get() == before + + sessions = [ + r.wide + for r in caplog.records + if r.name == "botpit.wide" and r.wide.get("event_kind") == "ws.session" + ] + assert sessions + ev = sessions[-1] + assert ev["room_id"] == str(room_id) + assert ev["subscriber_kind"] in ("privileged", "player") + assert ev["events_sent"] >= 1 + + def test_ws_since_accepts_bare_seq_not_just_hyphenated_cursor( client: TestClient, live_game: LiveGame ) -> None: diff --git a/docs/admin-and-observability.md b/docs/admin-and-observability.md index 432eddf..f24965f 100644 --- a/docs/admin-and-observability.md +++ b/docs/admin-and-observability.md @@ -1,7 +1,8 @@ # Admin and observability -Status: logging design decided in Phase 1; dashboard and metrics land in -Phases 10 and 13. +Status: logging design decided in Phase 1; dashboard lands in Phase 10; +metrics and the last missing wide-event kind (`ws.session`) land in +Phase 13. ## Logging: wide events @@ -12,9 +13,9 @@ for debugging. Units of work in botpit: | Kind | Emitted when | Key fields | |---|---|---| | `http.request` | response sent | method, path, status, duration_ms, user_id, request_id | -| `ws.session` | websocket closes | room_id, subscriber kind, seat, events_sent, duration_ms, close reason | -| `agent.turn` | agent turn finishes or fails | game_id, turn_id, seat, model, persona, prompt_tokens, completion_tokens, latency_ms per call, retries, parse_ok, move, error | -| `game` | game finishes or is stopped | game_id, game_type, seats (human/AI, model), turns, duration_ms, winner, swaps | +| `ws.session` | websocket closes | room_id, user_id, subscriber_kind, seat, events_sent, duration_ms, close_reason (set only on a clean client disconnect; any other exception's own type/message land in `error.*` instead, same as every other wide event) | +| `game.turn` | a seat's turn finishes or fails (docs originally called this `agent.turn`; the actual `event_kind` -- and every seat kind, not just agents -- has always been `game.turn`) | game_id, turn_id, seat, seat_kind, model, retries, fallback, move, attempts; an agent seat's own LLM calls (`AgentController._metrics`) additionally add one `llm.calls` entry per attempt: model, latency_ms, prompt_tokens, completion_tokens, ok, error | +| `game` | game finishes or is stopped | room_id, game_id, game_type, seats, turns, duration_ms, winner, ranking | Correlation ids (`request_id`, `game_id`, `room_id`, `turn_id`, `user_id`, `seat`) are set on the current wide event and inherited by nested events. @@ -32,11 +33,30 @@ handler; the admin dashboard's live tail reads the same stream. - `GET /health`: app liveness plus DB and bus checks. - `GET /health/llm`: provider, reachability, models present/missing. -## Metrics (Phase 13) +## Metrics (Phase 13) -- done -Prometheus `GET /metrics`: active games, active connections, agent turn -latency histogram per model, agent error/timeout counters per model, -moves per minute, model swaps. +Prometheus `GET /metrics` (unauthenticated, matching `GET /health`; a +dedicated `CollectorRegistry` in `app/metrics.py`, not +`prometheus_client`'s process-global default, so this endpoint never +leaks unrelated process metrics): + +| Metric | Kind | Labels | +|---|---|---| +| `botpit_active_games` | gauge | -- | +| `botpit_active_ws_connections` | gauge | -- | +| `botpit_agent_turn_latency_seconds` | histogram | `model` | +| `botpit_agent_turn_errors_total` | counter | `model`, `error` | +| `botpit_agent_turn_timeouts_total` | counter | `model` (only real `kind="agent"` seats, not `"scripted"`) | +| `botpit_moves_total` | counter | -- ("moves per minute": graph this counter's `rate()`, Prometheus's own idiom, rather than botpit computing and storing a per-minute number itself) | +| `botpit_model_swaps_total` | counter | `base_url` | + +`botpit_model_swaps_total` counts a real signal (DECISIONS.md §13: two +consecutive LLM calls to the same Ollama endpoint that used different +models -- a likely VRAM swap), via `app.metrics.note_llm_call`. It is +**not** the model-swap-*aware scheduler* §13 also describes (grouping +concurrent AI turns by model to minimise these swaps) -- that scheduler +does not exist yet; this phase only adds the counter that would prove +whether it's worth building. ## Admin dashboard (Phase 10/13) diff --git a/docs/api/api-reference.md b/docs/api/api-reference.md index 1f2a229..c3ed2b8 100644 --- a/docs/api/api-reference.md +++ b/docs/api/api-reference.md @@ -77,6 +77,15 @@ Every new account is granted the default `player` role on creation per worker process — one real probe per TTL window regardless of how many callers ask. +## Metrics (`metrics.py`, no route prefix) — Phase 13, docs/admin-and-observability.md + +| Method & path | Auth | Request | Response | Status codes | +|---|---|---|---|---| +| `GET /metrics` | none | — | Prometheus text exposition of `app.metrics.REGISTRY` | — | + +Unauthenticated, matching `/health` -- both are operational endpoints for a +scraper/monitor, not user data. + ## Roles (`roles.py`, prefix `/roles`) — every route requires `admin:manage_roles` | Method & path | Request | Response | Status codes | diff --git a/docs/development/setup.md b/docs/development/setup.md index 0f15355..d8c5d26 100644 --- a/docs/development/setup.md +++ b/docs/development/setup.md @@ -22,10 +22,22 @@ the WSL/Ollama split specifically, see `DECISIONS.md` §0.5. ## Install dependencies ```bash -cd backend && uv sync # Python deps, backend/.venv -cd ../frontend && bun install # frontend deps +uv sync --all-groups # one shared .venv at the repo root (uv workspace, backend/ is its only member) +cd frontend && bun install # frontend deps ``` +`--all-groups` matters: the repo-root `pyproject.toml`'s `dev`/`github-actions` +groups (`prek`, `zizmor`, `smokeshow` -- everything `prek run --all-files` +needs) live outside `backend/pyproject.toml`'s own `dependencies`, so a bare +`uv sync` only installs botpit's runtime deps and silently leaves those +tooling packages missing, whether run from the repo root or from `backend/` +(there's no separate `backend/.venv` -- uv workspaces share one venv at the +workspace root regardless of which member directory you run `uv sync` from). +Re-running a bare `uv sync` from either place later (e.g. after `uv add`ing a +new runtime dependency) *removes* those tooling packages from the shared venv +if they were already installed -- always use `--all-groups` for any `uv sync` +in this repo, not just the first one. + ## Environment variables Settings are defined in `backend/app/core/config.py` (`class Settings`, diff --git a/frontend/src/client/index.ts b/frontend/src/client/index.ts index c7a6222..83b9695 100644 --- a/frontend/src/client/index.ts +++ b/frontend/src/client/index.ts @@ -1,4 +1,4 @@ // This file is auto-generated by @hey-api/openapi-ts -export { AdminService, FlagsService, GamesService, HealthService, ItemsService, LeaderboardService, LoginService, type Options, PrivateService, RolesService, RoomsService, UsersService, UtilsService } from './sdk.gen'; -export type { adminCreateOverrideData, adminCreateOverrideError, adminCreateOverrideErrors, adminCreateOverrideResponse, adminCreateOverrideResponses, adminReadFlagsData, adminReadFlagsResponse, adminReadFlagsResponses, adminReadSettingsData, adminReadSettingsResponse, adminReadSettingsResponses, adminRemoveOverrideData, adminRemoveOverrideError, adminRemoveOverrideErrors, adminRemoveOverrideResponse, adminRemoveOverrideResponses, adminUpdateFlagData, adminUpdateFlagError, adminUpdateFlagErrors, adminUpdateFlagResponse, adminUpdateFlagResponses, adminUpdateSettingData, adminUpdateSettingError, adminUpdateSettingErrors, adminUpdateSettingResponse, adminUpdateSettingResponses, Body_login_login_access_token, ChatSend, ClientOptions, FeatureFlagOverrideCreate, FeatureFlagOverridePublic, FeatureFlagPublic, FeatureFlagUpdate, flagsReadMyFlagsData, flagsReadMyFlagsResponse, flagsReadMyFlagsResponses, GameRecordPublic, gamesGameEventsData, gamesGameEventsError, gamesGameEventsErrors, gamesGameEventsResponses, gamesGetGameRecordData, gamesGetGameRecordError, gamesGetGameRecordErrors, gamesGetGameRecordResponse, gamesGetGameRecordResponses, gamesReplayData, gamesReplayError, gamesReplayErrors, gamesReplayResponses, healthHealthData, healthHealthLlmData, healthHealthLlmResponse, healthHealthLlmResponses, healthHealthResponse, healthHealthResponses, HealthReport, HTTPValidationError, ItemCreate, ItemPublic, itemsCreateItemData, itemsCreateItemError, itemsCreateItemErrors, itemsCreateItemResponse, itemsCreateItemResponses, itemsDeleteItemData, itemsDeleteItemError, itemsDeleteItemErrors, itemsDeleteItemResponse, itemsDeleteItemResponses, ItemsPublic, itemsReadItemData, itemsReadItemError, itemsReadItemErrors, itemsReadItemResponse, itemsReadItemResponses, itemsReadItemsData, itemsReadItemsError, itemsReadItemsErrors, itemsReadItemsResponse, itemsReadItemsResponses, itemsUpdateItemData, itemsUpdateItemError, itemsUpdateItemErrors, itemsUpdateItemResponse, itemsUpdateItemResponses, ItemUpdate, leaderboardAccountsLeaderboardData, leaderboardAccountsLeaderboardError, leaderboardAccountsLeaderboardErrors, leaderboardAccountsLeaderboardResponse, leaderboardAccountsLeaderboardResponses, LeaderboardEntry, leaderboardModelsLeaderboardData, leaderboardModelsLeaderboardError, leaderboardModelsLeaderboardErrors, leaderboardModelsLeaderboardResponse, leaderboardModelsLeaderboardResponses, LLMHealth, loginLoginAccessTokenData, loginLoginAccessTokenError, loginLoginAccessTokenErrors, loginLoginAccessTokenResponse, loginLoginAccessTokenResponses, loginRecoverPasswordData, loginRecoverPasswordError, loginRecoverPasswordErrors, loginRecoverPasswordHtmlContentData, loginRecoverPasswordHtmlContentError, loginRecoverPasswordHtmlContentErrors, loginRecoverPasswordHtmlContentResponse, loginRecoverPasswordHtmlContentResponses, loginRecoverPasswordResponse, loginRecoverPasswordResponses, loginResetPasswordData, loginResetPasswordError, loginResetPasswordErrors, loginResetPasswordResponse, loginResetPasswordResponses, loginTestTokenData, loginTestTokenResponse, loginTestTokenResponses, Message, MoveSubmission, NewPassword, PermissionsPublic, privateCreateUserData, privateCreateUserError, privateCreateUserErrors, privateCreateUserResponse, privateCreateUserResponses, PrivateUserCreate, RoleAssignment, RolePublic, rolesGrantUserRoleData, rolesGrantUserRoleError, rolesGrantUserRoleErrors, rolesGrantUserRoleResponse, rolesGrantUserRoleResponses, rolesReadPermissionsData, rolesReadPermissionsResponse, rolesReadPermissionsResponses, rolesReadRolesData, rolesReadRolesResponse, rolesReadRolesResponses, rolesReadUserRolesData, rolesReadUserRolesError, rolesReadUserRolesErrors, rolesReadUserRolesResponse, rolesReadUserRolesResponses, rolesRevokeUserRoleData, rolesRevokeUserRoleError, rolesRevokeUserRoleErrors, rolesRevokeUserRoleResponse, rolesRevokeUserRoleResponses, RoomCreate, RoomJoinRequest, RoomPublic, roomsCreateRoomData, roomsCreateRoomError, roomsCreateRoomErrors, roomsCreateRoomResponse, roomsCreateRoomResponses, RoomSeatJoinPublic, RoomSeatPublic, RoomSeatSpec, roomsForceStartRoomData, roomsForceStartRoomError, roomsForceStartRoomErrors, roomsForceStartRoomResponse, roomsForceStartRoomResponses, roomsGetRoomData, roomsGetRoomError, roomsGetRoomErrors, roomsGetRoomResponse, roomsGetRoomResponses, roomsJoinRoomData, roomsJoinRoomError, roomsJoinRoomErrors, roomsJoinRoomResponse, roomsJoinRoomResponses, roomsLeaveRoomData, roomsLeaveRoomError, roomsLeaveRoomErrors, roomsLeaveRoomResponse, roomsLeaveRoomResponses, roomsListRoomsData, roomsListRoomsError, roomsListRoomsErrors, roomsListRoomsResponse, roomsListRoomsResponses, roomsMovesSchemaData, roomsMovesSchemaError, roomsMovesSchemaErrors, roomsMovesSchemaResponses, RoomsPublic, roomsRoomEventsData, roomsRoomEventsError, roomsRoomEventsErrors, roomsRoomEventsResponses, roomsRoomQueueData, roomsRoomQueueError, roomsRoomQueueErrors, roomsRoomQueueResponses, roomsRoomViewData, roomsRoomViewError, roomsRoomViewErrors, roomsRoomViewResponses, roomsSendChatData, roomsSendChatError, roomsSendChatErrors, roomsSendChatResponse, roomsSendChatResponses, roomsStartRoomData, roomsStartRoomError, roomsStartRoomErrors, roomsStartRoomResponse, roomsStartRoomResponses, roomsStopRoomData, roomsStopRoomError, roomsStopRoomErrors, roomsStopRoomResponse, roomsStopRoomResponses, roomsSubmitMoveData, roomsSubmitMoveError, roomsSubmitMoveErrors, roomsSubmitMoveResponse, roomsSubmitMoveResponses, roomsWsTicketData, roomsWsTicketError, roomsWsTicketErrors, roomsWsTicketResponse, roomsWsTicketResponses, RuntimeSettingPublic, RuntimeSettingsPublic, RuntimeSettingUpdate, Token, UpdatePassword, UserCreate, UserPublic, UserRegister, UserRolesPublic, usersCreateUserData, usersCreateUserError, usersCreateUserErrors, usersCreateUserResponse, usersCreateUserResponses, usersDeleteUserData, usersDeleteUserError, usersDeleteUserErrors, usersDeleteUserMeData, usersDeleteUserMeResponse, usersDeleteUserMeResponses, usersDeleteUserResponse, usersDeleteUserResponses, UsersPublic, usersReadUserByIdData, usersReadUserByIdError, usersReadUserByIdErrors, usersReadUserByIdResponse, usersReadUserByIdResponses, usersReadUserMeData, usersReadUserMePermissionsData, usersReadUserMePermissionsResponse, usersReadUserMePermissionsResponses, usersReadUserMeResponse, usersReadUserMeResponses, usersReadUsersData, usersReadUsersError, usersReadUsersErrors, usersReadUsersResponse, usersReadUsersResponses, usersRegisterUserData, usersRegisterUserError, usersRegisterUserErrors, usersRegisterUserResponse, usersRegisterUserResponses, usersUpdatePasswordMeData, usersUpdatePasswordMeError, usersUpdatePasswordMeErrors, usersUpdatePasswordMeResponse, usersUpdatePasswordMeResponses, usersUpdateUserData, usersUpdateUserError, usersUpdateUserErrors, usersUpdateUserMeData, usersUpdateUserMeError, usersUpdateUserMeErrors, usersUpdateUserMeResponse, usersUpdateUserMeResponses, usersUpdateUserResponse, usersUpdateUserResponses, UserUpdate, UserUpdateMe, utilsHealthCheckData, utilsHealthCheckResponse, utilsHealthCheckResponses, utilsTestEmailData, utilsTestEmailError, utilsTestEmailErrors, utilsTestEmailResponse, utilsTestEmailResponses, ValidationError } from './types.gen'; +export { AdminService, FlagsService, GamesService, HealthService, ItemsService, LeaderboardService, LoginService, MetricsService, type Options, PrivateService, RolesService, RoomsService, UsersService, UtilsService } from './sdk.gen'; +export type { adminCreateOverrideData, adminCreateOverrideError, adminCreateOverrideErrors, adminCreateOverrideResponse, adminCreateOverrideResponses, adminReadFlagsData, adminReadFlagsResponse, adminReadFlagsResponses, adminReadSettingsData, adminReadSettingsResponse, adminReadSettingsResponses, adminRemoveOverrideData, adminRemoveOverrideError, adminRemoveOverrideErrors, adminRemoveOverrideResponse, adminRemoveOverrideResponses, adminUpdateFlagData, adminUpdateFlagError, adminUpdateFlagErrors, adminUpdateFlagResponse, adminUpdateFlagResponses, adminUpdateSettingData, adminUpdateSettingError, adminUpdateSettingErrors, adminUpdateSettingResponse, adminUpdateSettingResponses, Body_login_login_access_token, ChatSend, ClientOptions, FeatureFlagOverrideCreate, FeatureFlagOverridePublic, FeatureFlagPublic, FeatureFlagUpdate, flagsReadMyFlagsData, flagsReadMyFlagsResponse, flagsReadMyFlagsResponses, GameRecordPublic, gamesGameEventsData, gamesGameEventsError, gamesGameEventsErrors, gamesGameEventsResponses, gamesGetGameRecordData, gamesGetGameRecordError, gamesGetGameRecordErrors, gamesGetGameRecordResponse, gamesGetGameRecordResponses, gamesReplayData, gamesReplayError, gamesReplayErrors, gamesReplayResponses, healthHealthData, healthHealthLlmData, healthHealthLlmResponse, healthHealthLlmResponses, healthHealthResponse, healthHealthResponses, HealthReport, HTTPValidationError, ItemCreate, ItemPublic, itemsCreateItemData, itemsCreateItemError, itemsCreateItemErrors, itemsCreateItemResponse, itemsCreateItemResponses, itemsDeleteItemData, itemsDeleteItemError, itemsDeleteItemErrors, itemsDeleteItemResponse, itemsDeleteItemResponses, ItemsPublic, itemsReadItemData, itemsReadItemError, itemsReadItemErrors, itemsReadItemResponse, itemsReadItemResponses, itemsReadItemsData, itemsReadItemsError, itemsReadItemsErrors, itemsReadItemsResponse, itemsReadItemsResponses, itemsUpdateItemData, itemsUpdateItemError, itemsUpdateItemErrors, itemsUpdateItemResponse, itemsUpdateItemResponses, ItemUpdate, leaderboardAccountsLeaderboardData, leaderboardAccountsLeaderboardError, leaderboardAccountsLeaderboardErrors, leaderboardAccountsLeaderboardResponse, leaderboardAccountsLeaderboardResponses, LeaderboardEntry, leaderboardModelsLeaderboardData, leaderboardModelsLeaderboardError, leaderboardModelsLeaderboardErrors, leaderboardModelsLeaderboardResponse, leaderboardModelsLeaderboardResponses, LLMHealth, loginLoginAccessTokenData, loginLoginAccessTokenError, loginLoginAccessTokenErrors, loginLoginAccessTokenResponse, loginLoginAccessTokenResponses, loginRecoverPasswordData, loginRecoverPasswordError, loginRecoverPasswordErrors, loginRecoverPasswordHtmlContentData, loginRecoverPasswordHtmlContentError, loginRecoverPasswordHtmlContentErrors, loginRecoverPasswordHtmlContentResponse, loginRecoverPasswordHtmlContentResponses, loginRecoverPasswordResponse, loginRecoverPasswordResponses, loginResetPasswordData, loginResetPasswordError, loginResetPasswordErrors, loginResetPasswordResponse, loginResetPasswordResponses, loginTestTokenData, loginTestTokenResponse, loginTestTokenResponses, Message, metricsMetricsData, metricsMetricsResponses, MoveSubmission, NewPassword, PermissionsPublic, privateCreateUserData, privateCreateUserError, privateCreateUserErrors, privateCreateUserResponse, privateCreateUserResponses, PrivateUserCreate, RoleAssignment, RolePublic, rolesGrantUserRoleData, rolesGrantUserRoleError, rolesGrantUserRoleErrors, rolesGrantUserRoleResponse, rolesGrantUserRoleResponses, rolesReadPermissionsData, rolesReadPermissionsResponse, rolesReadPermissionsResponses, rolesReadRolesData, rolesReadRolesResponse, rolesReadRolesResponses, rolesReadUserRolesData, rolesReadUserRolesError, rolesReadUserRolesErrors, rolesReadUserRolesResponse, rolesReadUserRolesResponses, rolesRevokeUserRoleData, rolesRevokeUserRoleError, rolesRevokeUserRoleErrors, rolesRevokeUserRoleResponse, rolesRevokeUserRoleResponses, RoomCreate, RoomJoinRequest, RoomPublic, roomsCreateRoomData, roomsCreateRoomError, roomsCreateRoomErrors, roomsCreateRoomResponse, roomsCreateRoomResponses, RoomSeatJoinPublic, RoomSeatPublic, RoomSeatSpec, roomsForceStartRoomData, roomsForceStartRoomError, roomsForceStartRoomErrors, roomsForceStartRoomResponse, roomsForceStartRoomResponses, roomsGetRoomData, roomsGetRoomError, roomsGetRoomErrors, roomsGetRoomResponse, roomsGetRoomResponses, roomsJoinRoomData, roomsJoinRoomError, roomsJoinRoomErrors, roomsJoinRoomResponse, roomsJoinRoomResponses, roomsLeaveRoomData, roomsLeaveRoomError, roomsLeaveRoomErrors, roomsLeaveRoomResponse, roomsLeaveRoomResponses, roomsListRoomsData, roomsListRoomsError, roomsListRoomsErrors, roomsListRoomsResponse, roomsListRoomsResponses, roomsMovesSchemaData, roomsMovesSchemaError, roomsMovesSchemaErrors, roomsMovesSchemaResponses, RoomsPublic, roomsRoomEventsData, roomsRoomEventsError, roomsRoomEventsErrors, roomsRoomEventsResponses, roomsRoomQueueData, roomsRoomQueueError, roomsRoomQueueErrors, roomsRoomQueueResponses, roomsRoomViewData, roomsRoomViewError, roomsRoomViewErrors, roomsRoomViewResponses, roomsSendChatData, roomsSendChatError, roomsSendChatErrors, roomsSendChatResponse, roomsSendChatResponses, roomsStartRoomData, roomsStartRoomError, roomsStartRoomErrors, roomsStartRoomResponse, roomsStartRoomResponses, roomsStopRoomData, roomsStopRoomError, roomsStopRoomErrors, roomsStopRoomResponse, roomsStopRoomResponses, roomsSubmitMoveData, roomsSubmitMoveError, roomsSubmitMoveErrors, roomsSubmitMoveResponse, roomsSubmitMoveResponses, roomsWsTicketData, roomsWsTicketError, roomsWsTicketErrors, roomsWsTicketResponse, roomsWsTicketResponses, RuntimeSettingPublic, RuntimeSettingsPublic, RuntimeSettingUpdate, Token, UpdatePassword, UserCreate, UserPublic, UserRegister, UserRolesPublic, usersCreateUserData, usersCreateUserError, usersCreateUserErrors, usersCreateUserResponse, usersCreateUserResponses, usersDeleteUserData, usersDeleteUserError, usersDeleteUserErrors, usersDeleteUserMeData, usersDeleteUserMeResponse, usersDeleteUserMeResponses, usersDeleteUserResponse, usersDeleteUserResponses, UsersPublic, usersReadUserByIdData, usersReadUserByIdError, usersReadUserByIdErrors, usersReadUserByIdResponse, usersReadUserByIdResponses, usersReadUserMeData, usersReadUserMePermissionsData, usersReadUserMePermissionsResponse, usersReadUserMePermissionsResponses, usersReadUserMeResponse, usersReadUserMeResponses, usersReadUsersData, usersReadUsersError, usersReadUsersErrors, usersReadUsersResponse, usersReadUsersResponses, usersRegisterUserData, usersRegisterUserError, usersRegisterUserErrors, usersRegisterUserResponse, usersRegisterUserResponses, usersUpdatePasswordMeData, usersUpdatePasswordMeError, usersUpdatePasswordMeErrors, usersUpdatePasswordMeResponse, usersUpdatePasswordMeResponses, usersUpdateUserData, usersUpdateUserError, usersUpdateUserErrors, usersUpdateUserMeData, usersUpdateUserMeError, usersUpdateUserMeErrors, usersUpdateUserMeResponse, usersUpdateUserMeResponses, usersUpdateUserResponse, usersUpdateUserResponses, UserUpdate, UserUpdateMe, utilsHealthCheckData, utilsHealthCheckResponse, utilsHealthCheckResponses, utilsTestEmailData, utilsTestEmailError, utilsTestEmailErrors, utilsTestEmailResponse, utilsTestEmailResponses, ValidationError } from './types.gen'; diff --git a/frontend/src/client/sdk.gen.ts b/frontend/src/client/sdk.gen.ts index 745a455..c27d04c 100644 --- a/frontend/src/client/sdk.gen.ts +++ b/frontend/src/client/sdk.gen.ts @@ -2,7 +2,7 @@ import { type Client, type ClientMeta, type Options as Options2, type RequestResult, type TDataShape, urlSearchParamsBodySerializer } from './client'; import { client } from './client.gen'; -import type { adminCreateOverrideData, adminCreateOverrideErrors, adminCreateOverrideResponses, adminReadFlagsData, adminReadFlagsResponses, adminReadSettingsData, adminReadSettingsResponses, adminRemoveOverrideData, adminRemoveOverrideErrors, adminRemoveOverrideResponses, adminUpdateFlagData, adminUpdateFlagErrors, adminUpdateFlagResponses, adminUpdateSettingData, adminUpdateSettingErrors, adminUpdateSettingResponses, flagsReadMyFlagsData, flagsReadMyFlagsResponses, gamesGameEventsData, gamesGameEventsErrors, gamesGameEventsResponses, gamesGetGameRecordData, gamesGetGameRecordErrors, gamesGetGameRecordResponses, gamesReplayData, gamesReplayErrors, gamesReplayResponses, healthHealthData, healthHealthLlmData, healthHealthLlmResponses, healthHealthResponses, itemsCreateItemData, itemsCreateItemErrors, itemsCreateItemResponses, itemsDeleteItemData, itemsDeleteItemErrors, itemsDeleteItemResponses, itemsReadItemData, itemsReadItemErrors, itemsReadItemResponses, itemsReadItemsData, itemsReadItemsErrors, itemsReadItemsResponses, itemsUpdateItemData, itemsUpdateItemErrors, itemsUpdateItemResponses, leaderboardAccountsLeaderboardData, leaderboardAccountsLeaderboardErrors, leaderboardAccountsLeaderboardResponses, leaderboardModelsLeaderboardData, leaderboardModelsLeaderboardErrors, leaderboardModelsLeaderboardResponses, loginLoginAccessTokenData, loginLoginAccessTokenErrors, loginLoginAccessTokenResponses, loginRecoverPasswordData, loginRecoverPasswordErrors, loginRecoverPasswordHtmlContentData, loginRecoverPasswordHtmlContentErrors, loginRecoverPasswordHtmlContentResponses, loginRecoverPasswordResponses, loginResetPasswordData, loginResetPasswordErrors, loginResetPasswordResponses, loginTestTokenData, loginTestTokenResponses, privateCreateUserData, privateCreateUserErrors, privateCreateUserResponses, rolesGrantUserRoleData, rolesGrantUserRoleErrors, rolesGrantUserRoleResponses, rolesReadPermissionsData, rolesReadPermissionsResponses, rolesReadRolesData, rolesReadRolesResponses, rolesReadUserRolesData, rolesReadUserRolesErrors, rolesReadUserRolesResponses, rolesRevokeUserRoleData, rolesRevokeUserRoleErrors, rolesRevokeUserRoleResponses, roomsCreateRoomData, roomsCreateRoomErrors, roomsCreateRoomResponses, roomsForceStartRoomData, roomsForceStartRoomErrors, roomsForceStartRoomResponses, roomsGetRoomData, roomsGetRoomErrors, roomsGetRoomResponses, roomsJoinRoomData, roomsJoinRoomErrors, roomsJoinRoomResponses, roomsLeaveRoomData, roomsLeaveRoomErrors, roomsLeaveRoomResponses, roomsListRoomsData, roomsListRoomsErrors, roomsListRoomsResponses, roomsMovesSchemaData, roomsMovesSchemaErrors, roomsMovesSchemaResponses, roomsRoomEventsData, roomsRoomEventsErrors, roomsRoomEventsResponses, roomsRoomQueueData, roomsRoomQueueErrors, roomsRoomQueueResponses, roomsRoomViewData, roomsRoomViewErrors, roomsRoomViewResponses, roomsSendChatData, roomsSendChatErrors, roomsSendChatResponses, roomsStartRoomData, roomsStartRoomErrors, roomsStartRoomResponses, roomsStopRoomData, roomsStopRoomErrors, roomsStopRoomResponses, roomsSubmitMoveData, roomsSubmitMoveErrors, roomsSubmitMoveResponses, roomsWsTicketData, roomsWsTicketErrors, roomsWsTicketResponses, usersCreateUserData, usersCreateUserErrors, usersCreateUserResponses, usersDeleteUserData, usersDeleteUserErrors, usersDeleteUserMeData, usersDeleteUserMeResponses, usersDeleteUserResponses, usersReadUserByIdData, usersReadUserByIdErrors, usersReadUserByIdResponses, usersReadUserMeData, usersReadUserMePermissionsData, usersReadUserMePermissionsResponses, usersReadUserMeResponses, usersReadUsersData, usersReadUsersErrors, usersReadUsersResponses, usersRegisterUserData, usersRegisterUserErrors, usersRegisterUserResponses, usersUpdatePasswordMeData, usersUpdatePasswordMeErrors, usersUpdatePasswordMeResponses, usersUpdateUserData, usersUpdateUserErrors, usersUpdateUserMeData, usersUpdateUserMeErrors, usersUpdateUserMeResponses, usersUpdateUserResponses, utilsHealthCheckData, utilsHealthCheckResponses, utilsTestEmailData, utilsTestEmailErrors, utilsTestEmailResponses } from './types.gen'; +import type { adminCreateOverrideData, adminCreateOverrideErrors, adminCreateOverrideResponses, adminReadFlagsData, adminReadFlagsResponses, adminReadSettingsData, adminReadSettingsResponses, adminRemoveOverrideData, adminRemoveOverrideErrors, adminRemoveOverrideResponses, adminUpdateFlagData, adminUpdateFlagErrors, adminUpdateFlagResponses, adminUpdateSettingData, adminUpdateSettingErrors, adminUpdateSettingResponses, flagsReadMyFlagsData, flagsReadMyFlagsResponses, gamesGameEventsData, gamesGameEventsErrors, gamesGameEventsResponses, gamesGetGameRecordData, gamesGetGameRecordErrors, gamesGetGameRecordResponses, gamesReplayData, gamesReplayErrors, gamesReplayResponses, healthHealthData, healthHealthLlmData, healthHealthLlmResponses, healthHealthResponses, itemsCreateItemData, itemsCreateItemErrors, itemsCreateItemResponses, itemsDeleteItemData, itemsDeleteItemErrors, itemsDeleteItemResponses, itemsReadItemData, itemsReadItemErrors, itemsReadItemResponses, itemsReadItemsData, itemsReadItemsErrors, itemsReadItemsResponses, itemsUpdateItemData, itemsUpdateItemErrors, itemsUpdateItemResponses, leaderboardAccountsLeaderboardData, leaderboardAccountsLeaderboardErrors, leaderboardAccountsLeaderboardResponses, leaderboardModelsLeaderboardData, leaderboardModelsLeaderboardErrors, leaderboardModelsLeaderboardResponses, loginLoginAccessTokenData, loginLoginAccessTokenErrors, loginLoginAccessTokenResponses, loginRecoverPasswordData, loginRecoverPasswordErrors, loginRecoverPasswordHtmlContentData, loginRecoverPasswordHtmlContentErrors, loginRecoverPasswordHtmlContentResponses, loginRecoverPasswordResponses, loginResetPasswordData, loginResetPasswordErrors, loginResetPasswordResponses, loginTestTokenData, loginTestTokenResponses, metricsMetricsData, metricsMetricsResponses, privateCreateUserData, privateCreateUserErrors, privateCreateUserResponses, rolesGrantUserRoleData, rolesGrantUserRoleErrors, rolesGrantUserRoleResponses, rolesReadPermissionsData, rolesReadPermissionsResponses, rolesReadRolesData, rolesReadRolesResponses, rolesReadUserRolesData, rolesReadUserRolesErrors, rolesReadUserRolesResponses, rolesRevokeUserRoleData, rolesRevokeUserRoleErrors, rolesRevokeUserRoleResponses, roomsCreateRoomData, roomsCreateRoomErrors, roomsCreateRoomResponses, roomsForceStartRoomData, roomsForceStartRoomErrors, roomsForceStartRoomResponses, roomsGetRoomData, roomsGetRoomErrors, roomsGetRoomResponses, roomsJoinRoomData, roomsJoinRoomErrors, roomsJoinRoomResponses, roomsLeaveRoomData, roomsLeaveRoomErrors, roomsLeaveRoomResponses, roomsListRoomsData, roomsListRoomsErrors, roomsListRoomsResponses, roomsMovesSchemaData, roomsMovesSchemaErrors, roomsMovesSchemaResponses, roomsRoomEventsData, roomsRoomEventsErrors, roomsRoomEventsResponses, roomsRoomQueueData, roomsRoomQueueErrors, roomsRoomQueueResponses, roomsRoomViewData, roomsRoomViewErrors, roomsRoomViewResponses, roomsSendChatData, roomsSendChatErrors, roomsSendChatResponses, roomsStartRoomData, roomsStartRoomErrors, roomsStartRoomResponses, roomsStopRoomData, roomsStopRoomErrors, roomsStopRoomResponses, roomsSubmitMoveData, roomsSubmitMoveErrors, roomsSubmitMoveResponses, roomsWsTicketData, roomsWsTicketErrors, roomsWsTicketResponses, usersCreateUserData, usersCreateUserErrors, usersCreateUserResponses, usersDeleteUserData, usersDeleteUserErrors, usersDeleteUserMeData, usersDeleteUserMeResponses, usersDeleteUserResponses, usersReadUserByIdData, usersReadUserByIdErrors, usersReadUserByIdResponses, usersReadUserMeData, usersReadUserMePermissionsData, usersReadUserMePermissionsResponses, usersReadUserMeResponses, usersReadUsersData, usersReadUsersErrors, usersReadUsersResponses, usersRegisterUserData, usersRegisterUserErrors, usersRegisterUserResponses, usersUpdatePasswordMeData, usersUpdatePasswordMeErrors, usersUpdatePasswordMeResponses, usersUpdateUserData, usersUpdateUserErrors, usersUpdateUserMeData, usersUpdateUserMeErrors, usersUpdateUserMeResponses, usersUpdateUserResponses, utilsHealthCheckData, utilsHealthCheckResponses, utilsTestEmailData, utilsTestEmailErrors, utilsTestEmailResponses } from './types.gen'; export type Options = Options2 & { /** @@ -883,6 +883,19 @@ export class LeaderboardService { } } +export class MetricsService { + /** + * Metrics + */ + public static metrics(options?: Options): RequestResult { + return (options?.client ?? client).get({ + responseType: 'json', + url: '/api/v1/metrics', + ...options + }); + } +} + export class PrivateService { /** * Create User diff --git a/frontend/src/client/types.gen.ts b/frontend/src/client/types.gen.ts index db45ed4..566a4eb 100644 --- a/frontend/src/client/types.gen.ts +++ b/frontend/src/client/types.gen.ts @@ -2473,6 +2473,20 @@ export type leaderboardModelsLeaderboardResponses = { export type leaderboardModelsLeaderboardResponse = leaderboardModelsLeaderboardResponses[keyof leaderboardModelsLeaderboardResponses]; +export type metricsMetricsData = { + body?: never; + path?: never; + query?: never; + url: '/api/v1/metrics'; +}; + +export type metricsMetricsResponses = { + /** + * Successful Response + */ + 200: unknown; +}; + export type privateCreateUserData = { body: PrivateUserCreate; path?: never; diff --git a/uv.lock b/uv.lock index ef7c759..05a3947 100644 --- a/uv.lock +++ b/uv.lock @@ -274,6 +274,7 @@ dependencies = [ { name = "fastapi", extra = ["standard"] }, { name = "httpx" }, { name = "jinja2" }, + { name = "prometheus-client" }, { name = "psycopg", extra = ["binary"] }, { name = "pwdlib", extra = ["argon2", "bcrypt"] }, { name = "pydantic" }, @@ -307,6 +308,7 @@ requires-dist = [ { name = "fastapi", extras = ["standard"], specifier = ">=0.141.1,<1.0.0" }, { name = "httpx", specifier = ">=0.25.1,<1.0.0" }, { name = "jinja2", specifier = ">=3.1.4,<4.0.0" }, + { name = "prometheus-client", specifier = ">=0.26.0,<1.0.0" }, { name = "psycopg", extras = ["binary"], specifier = ">=3.3.5,<4.0.0" }, { name = "pwdlib", extras = ["argon2", "bcrypt"], specifier = ">=0.3.1" }, { name = "pydantic", specifier = ">2.0" }, @@ -1114,6 +1116,15 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/24/cd/ce637f4b6cc6c583516dc16b539408dab593672f7c6fe7723a37caf378ff/prek-0.5.3-py3-none-win_arm64.whl", hash = "sha256:20d92aef53a5e237f4659ecc6669c0fbc98a1b83f0e2476530400a72d42ca390", size = 5512958, upload-time = "2026-09-13T08:38:36.123Z" }, ] +[[package]] +name = "prometheus-client" +version = "0.26.0" +source = { registry = "https://pypi.org/simple" } +sdist = { url = "https://files.pythonhosted.org/packages/52/73/f1334c29c2af4cd9dba6c7817e61b611bd0215e2eb5565c6064a4de18802/prometheus_client-0.26.0.tar.gz", hash = "sha256:04a91bcf94e2cf74a44a1a874d651a2e853ed354b6e822f3b7487751465d5c2b", size = 92910, upload-time = "2026-07-24T19:36:41.893Z" } +wheels = [ + { url = "https://files.pythonhosted.org/packages/eb/a3/b69efbf4143b5b9859b977770bbbabcc2796b702fa69dc40271e45cd5a56/prometheus_client-0.26.0-py3-none-any.whl", hash = "sha256:fa93d06737aa02bacd05794768508bb97d2fbee28cb3bca04eaae92f0ca953d6", size = 64494, upload-time = "2026-07-24T19:36:40.854Z" }, +] + [[package]] name = "psycopg" version = "3.3.5" From 70aab58bbd874cb11e4e61e5b669946a7d215736 Mon Sep 17 00:00:00 2001 From: withrvr Date: Mon, 14 Sep 2026 15:01:39 +0000 Subject: [PATCH 2/2] fix: address python-reviewer findings on PR #23 - metrics.py: set explicit histogram buckets covering realistic LLM latency (default buckets topped out at 10s, LLM_TIMEOUT_SECONDS defaults to 120s) - controller.py: record real elapsed time on a hard LLM failure instead of hardcoding latency_ms=0 - fake.py: note why FakeLLMClient.base_url is a shared constant, so a future test doesn't assert an absolute swap-count value against it Claude-Session: https://claude.ai/code/session_01UbiPa1rKCyqhqufgwJWkeW --- PROGRESS.md | 34 +++++++++++++++++++++ backend/app/agents/controller.py | 10 +++++- backend/app/llm/fake.py | 8 +++++ backend/app/metrics.py | 5 +++ backend/tests/observability/test_metrics.py | 5 ++- 5 files changed, 58 insertions(+), 4 deletions(-) diff --git a/PROGRESS.md b/PROGRESS.md index 8f9e252..bdd4ec3 100644 --- a/PROGRESS.md +++ b/PROGRESS.md @@ -1192,6 +1192,40 @@ verified the new `/metrics` route against the real built Docker image (not just `TestClient`), full Playwright suite (59 tests, unchanged) green against the real docker compose stack, `prek run --all-files` clean. +### Review fixes (PR #23) + +`python-reviewer` reviewed the PR (no frontend changes this phase, so no +`react-reviewer` pass). Verdict: approve, no CRITICAL/HIGH findings. Real, +fixed anyway: + +- **Default histogram buckets didn't cover realistic LLM latency** + (MEDIUM): `prometheus_client`'s default buckets top out at 10s, but + `LLM_TIMEOUT_SECONDS` defaults to 120s -- exactly the range this metric + exists to characterize (a slow or VRAM-swapped call) would collapse + into one `+Inf` bucket, undercutting the whole point of the histogram. + Set explicit buckets (`0.5` through `120`, plus `+Inf`). +- **A hard LLM failure recorded `latency_ms=0`** (LOW): `with_retries` may + have already spent real wall-clock time retrying before giving up, and + a persistent failure is exactly the call this histogram would most want + timed accurately. Now measures real elapsed time around the call + instead of hardcoding 0. + +**Verified, not fixed (already correct or already mitigated)**: +`note_llm_call`'s synchronous check-then-write has no real race (no +`await` between the read and write, same reasoning `ModelRegistry.client_for` +already relies on -- confirmed by re-reading both); `_finish_room`'s +unconditional `ACTIVE_GAMES.dec()` is correct in every real path (one +narrow, pre-existing-condition edge case noted -- a DB commit failing +immediately after a successful `runner.start()` -- already leaves +`room.status` inconsistent before this PR, out of this phase's scope); +`FakeLLMClient.base_url` being a shared constant combined with +`note_llm_call`'s module-level dict never resetting between tests is a +real test-isolation gap in the abstract, but every test already avoids it +correctly (unique `base_url` per test, or before/after baseline diffing) -- +added a one-line comment on `FakeLLMClient.base_url` stating this +explicitly, so a future test doesn't accidentally assert an absolute +value there. + ## Phase 9.7 — done 2026-09-14 (branch phase-9.7-infra-optimization) Infrastructure-only pass: Docker image build, Compose, CI/CD workflows, diff --git a/backend/app/agents/controller.py b/backend/app/agents/controller.py index e933780..a9ad086 100644 --- a/backend/app/agents/controller.py +++ b/backend/app/agents/controller.py @@ -4,6 +4,7 @@ import functools import json +import time from collections.abc import Sequence from typing import Any, ClassVar @@ -96,13 +97,20 @@ async def decide(self, view: PlayerView, ctx: TurnContext) -> dict[str, Any]: keep_alive=self.keep_alive, think=self.think, ) + call_start = time.perf_counter() try: note_llm_call(self.client.base_url, self.model) result = await with_retries( functools.partial(self.client.complete, req) ) except LLMError as exc: - self._metrics(latency_ms=0, ok=False, error=type(exc).__name__) + # Real elapsed wall-clock time, not 0 -- `with_retries` may + # have already spent real time retrying before giving up, + # and this is exactly the call this histogram most wants to + # characterize accurately (a persistent failure, possibly + # after a VRAM-swap-induced slow start). + elapsed_ms = (time.perf_counter() - call_start) * 1000 + self._metrics(latency_ms=elapsed_ms, ok=False, error=type(exc).__name__) raise ControllerError(f"{self.model}: {exc}") from exc reasoning, move = _parse_answer(result.text) if result.reasoning: diff --git a/backend/app/llm/fake.py b/backend/app/llm/fake.py index 5ea3b10..792d8e1 100644 --- a/backend/app/llm/fake.py +++ b/backend/app/llm/fake.py @@ -29,6 +29,14 @@ def __init__( self._fn = responses self.latency_s = latency_s self.requests: list[CompletionRequest] = [] + # Shared across every FakeLLMClient instance on purpose -- but note + # `app.metrics.note_llm_call`'s swap counter keys off `base_url` and + # never resets between tests, so `botpit_model_swaps_total{base_url= + # "fake://test"}`'s *absolute* value is order-dependent across the + # whole test session. Existing tests avoid this correctly (diff + # against a captured before/after baseline, or use a base_url unique + # to that one test) -- keep doing that, don't assert an absolute + # value for this base_url. self.base_url = "fake://test" async def complete(self, req: CompletionRequest) -> CompletionResult: diff --git a/backend/app/metrics.py b/backend/app/metrics.py index 926c171..5755583 100644 --- a/backend/app/metrics.py +++ b/backend/app/metrics.py @@ -29,6 +29,11 @@ "botpit_agent_turn_latency_seconds", "Latency of one LLM completion call within an agent's turn", ["model"], + # `prometheus_client`'s default buckets top out at 10s -- useless here: + # `LLM_TIMEOUT_SECONDS` defaults to 120s, and a slow/VRAM-swapped local + # model call landing anywhere past 10s (exactly what this metric exists + # to characterize) would otherwise collapse into one +Inf bucket. + buckets=(0.5, 1, 2, 5, 10, 20, 30, 60, 90, 120, float("inf")), registry=REGISTRY, ) AGENT_TURN_ERRORS_TOTAL = Counter( diff --git a/backend/tests/observability/test_metrics.py b/backend/tests/observability/test_metrics.py index 1b170a9..be0da57 100644 --- a/backend/tests/observability/test_metrics.py +++ b/backend/tests/observability/test_metrics.py @@ -8,6 +8,7 @@ from __future__ import annotations import asyncio +import contextlib import json from fastapi.testclient import TestClient @@ -123,10 +124,8 @@ async def test_agent_turn_timeout_increments_the_counter() -> None: task.cancel() raise AssertionError("agent turn never timed out within 5s") task.cancel() - try: + with contextlib.suppress(asyncio.CancelledError): await task - except asyncio.CancelledError: - pass assert AGENT_TURN_TIMEOUTS_TOTAL.labels(model=model)._value.get() == before + 1