Skip to content

Move API SQLite store calls off the event loop; add timed access log - #39

Open
RichSchefren wants to merge 1 commit into
masterfrom
fix/api-event-loop-offload-20260915
Open

RichSchefren wants to merge 1 commit into
masterfrom
fix/api-event-loop-offload-20260915

Conversation

@RichSchefren

Copy link
Copy Markdown
Owner

Summary

  • AtlasMCPServer now runs memory.search, memory.get, memory.list and ledger.verify_chain store calls on a dedicated one-worker ThreadPoolExecutor (atlas-sqlite) via _run_in_store_thread, so a SQLite busy wait or a large read no longer stalls uvicorn's event loop for every queued client.
  • One worker on purpose: the store calls are GIL-bound in row conversion. A measured 20-way memory.list limit=500 burst took 2.7 s on 32 threads against 0.37 s serialized.
  • New AccessLogMiddleware (pure ASGI) logs each request once with a UTC timestamp, client, method, path, status and duration_ms. Registered outermost in create_http_app, so CORS preflights and 401s are timed. Run uvicorn with --no-access-log to avoid double logging.

Verification

  • pytest tests/unit: 392 passed (baseline 380; 12 new tests written failing first)
  • ruff check .: clean
  • Live on the Studio since 2026-09-14 17:54 EDT: /health during a heavy batch 6.9 ms (was 38.4 ms); memory.list limit=500 at 20 concurrent p50 205 ms (baseline 204 ms); the MCC atlas-owner sidecar rode through the deploy with no pid change.

Follow-up (not in this PR)

quarantine.upsert, quarantine.list_pending and memory.forget still call the store inline.

🤖 Generated with Claude Code

uvicorn serves every client from one event loop, and the memory.search,
memory.get, memory.list and ledger.verify_chain handlers ran their SQLite
store calls inline. A busy_timeout wait (up to 5 s) or a large read
stalled every queued request and produced client-side timeouts on
20-40 ms calls (2026-09-14 mcc-atlas-owner incident).

- AtlasMCPServer gains a one-worker ThreadPoolExecutor ("atlas-sqlite")
  and _run_in_store_thread; the four handlers await through it. One
  worker on purpose: the store calls are GIL-bound in row conversion,
  and a measured 20-way memory.list burst took 2.7 s on 32 threads
  against 0.37 s serialized.
- New AccessLogMiddleware (pure ASGI) logs every request once with a UTC
  timestamp, client, method, path, status and duration_ms; registered
  outermost in create_http_app so CORS preflights and 401s are timed
  too. Run uvicorn with --no-access-log to avoid double logging.
- 12 new tests (tests/unit/test_mcp_event_loop_offload.py,
  tests/unit/test_http_access_log.py), written failing first.

Verified live on the Studio: /health during a heavy batch 6.9 ms (was
38.4 ms); memory.list limit=500 at 20 concurrent p50 205 ms (baseline
204 ms).

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant