agnes-the-ai-analyst/docs/development.md

Development guide

Logging

All processes (FastAPI app, scheduler, telegram_bot, ws_gateway, corporate_memory, session_collector, verification_detector, CLI scripts) use app.logging_config.setup_logging to configure the root logger. Each entrypoint calls it once:

from app.logging_config import setup_logging
setup_logging(__name__)

Library modules just do logger = logging.getLogger(__name__) — they NEVER configure root.

Env	Handler	Format
DEBUG=1	rich.logging.RichHandler	colored, clickable file:line, pretty tracebacks
(default)	stdlib StreamHandler	JSON to stderr (ts, lvl, logger, service, msg, optional request_id)

LOG_LEVEL overrides the level (default DEBUG when DEBUG=1, else INFO).

DEBUG and LOG_LEVEL are read at process start by app/main.py to decide whether to mount the toolbar middleware and configure logging handlers. The DuckDB connection wrapper in src/db.py reads DEBUG at call time, so tests can toggle it via monkeypatch.setenv — but the toolbar itself only mounts on initial app construction.

Request correlation

RequestIdMiddleware is mounted unconditionally on the FastAPI app. It assigns or propagates X-Request-ID and exposes it via the request_id_var ContextVar so the JSON formatter and the debug-toolbar logging panel see the same id.

Debug toolbar

What it is

Per-request HTML overlay that surfaces what the server did to produce the page in front of you — headers, routes matched, every DuckDB query, log records, timing — without leaving the browser. Powered by fastapi-debug-toolbar plus a custom DuckDBPanel (see app/debug_panels/duckdb_panel.py) that intercepts every con.execute(sql, params) from src/db.py.

The toolbar is mounted innermost so it sees raw HTML before _SelectiveGZipMiddleware compresses the body, and gated by DEBUG=1 — never imported in production. The dev dependency group (uv pip install ".[dev]") is the only place fastapi-debug-toolbar lives.

Enabling it

DEBUG=1 uv run uvicorn app.main:app --reload --port 8011

Or persist in .env at repo root (auto-loaded by uvicorn):

DEBUG=1
LOG_LEVEL=DEBUG
SESSION_SECRET=<32+ chars>

Visit any HTML page (/setup, /login, /dashboard, /admin/access) → small collapsed handle on the right edge of the viewport → click to expand.

Panels

Panel	Shows
Headers	Request + response headers (incl. x-request-id)
Routes	All registered FastAPI routes; matched route highlighted
Settings	Pydantic settings, instance_config values
Versions	Installed package versions (Python, FastAPI, deps)
Timer	Wall-clock + CPU time for the request
Logging	Every logger.* call during the request, with rid prefix
DuckDB	Every SQL via src/db.py — DB tag (system/analytics/analytics_ro), parameters, duration, row count

Profiling panel (pyinstrument) intentionally omitted — clashes with uvicorn's async task context. Re-enable in app/main.py if you set PROFILER_OPTIONS={"async_mode": "disabled"} or swap profilers.

JSON-only endpoints (Swagger UI at /docs) replay the most recent request's panels via a cookie mechanism — open /docs, fire a request, then navigate to any HTML page to inspect it.

When to reach for it

Symptom	Panel
"Why is this page slow?"	Timer + DuckDB (look for N+1 or unindexed scans)
"Which route handler ran?"	Routes
"Which user / session did the server see?"	Headers + Logging
"Why is this query returning N rows?"	DuckDB (full SQL + params + tag)
"Did this log line fire?"	Logging
"Is rid propagating end-to-end?"	Headers (x-request-id) + Logging (rid prefix on every line)

Forcing an error page (for testing)

Two dev-only routes (mounted only when DEBUG=1, otherwise 404):

URL	Behavior
/_debug/throw/http/{code}	Raises HTTPException(code) → goes through StarletteHTTPException handler → renders error.html for any code (/_debug/throw/http/404, /_debug/throw/http/418, /_debug/throw/http/500, …). Matched route, so the toolbar mounts.
/_debug/throw/exc	Raises unhandled KeyError → goes through _unhandled_exception_handler → renders the 5xx path, including the <details>Traceback</details> block (DEBUG-only). Toolbar NOT injected on this page — see note below.

Both echo the active x-request-id in response header and Reference: <rid> on the rendered error page.

Toolbar gap on unhandled exceptions. fastapi-debug-toolbar uses BaseHTTPMiddleware, which composes poorly with Starlette's ServerErrorMiddleware: when the route raises a bare Exception (not HTTPException), the exception propagates past the toolbar's call_next boundary before any response is sent, so the toolbar dispatch never sees a response body to inject into. The 500 page is produced outside the toolbar. Use /_debug/throw/http/500 instead to eyeball the 500 chrome WITH toolbar panels. Use /_debug/throw/exc only to verify the unhandled-exception code path itself (traceback <details> block, JSON 500 body).

Source

• Mount + show-callback: app/main.py (search for DebugToolbarMiddleware)
• DuckDB panel: app/debug_panels/duckdb_panel.py
• Dev throw routes: app/web/router.py (/_debug/throw/...)

Running locally

uv pip install ".[dev]"
DEBUG=1 LOCAL_DEV_MODE=1 uv run uvicorn app.main:app --reload --port 8000

Open http://localhost:8000/dashboard.

Bot logs

The telegram bot writes to stdout (captured by Docker). Read its logs with:

docker compose logs -f notify-bot

(Previously bots wrote to /data/notifications/bot.log via a FileHandler. That file is no longer produced; use docker logs for runtime tail.)