fix(serving): take the api_usage write off the request path

README.md

@@ -198,8 +198,9 @@ audit-closure sprint:
   (ADR 0011: Order 360, stuck-orders worklist, exception inbox), and the
   three-node demo topology (ADR 0012) implemented and deployed to Hugging
   Face Spaces (the `center` hub and the `spb` edge answer live; `ekb` and
-  the standalone demo Space are paused — the free tier keeps three
-  `cpu-basic` Spaces awake) — plus the G2 audit closure (spec/seed
+  the standalone demo Space are paused — the free tier caps how many
+  `cpu-basic` Spaces one account runs at once, and other projects hold the
+  rest) — plus the G2 audit closure (spec/seed
   consistency, journal-scan hardening, live evidence re-captures).
 
 The tagged line and `main` are in sync as of `v2.0.0`. See the

docs/dv2-multi-branch/RELEASE_STATUS.md

@@ -53,10 +53,16 @@ Scorecard channel (5.8 → 7.0).
 ## Live demo surfaces
 
 Four Docker Spaces exist under `liovina`, all built from the same image.
-The free tier keeps **three** `cpu-basic` Spaces awake at a time, and the
-account runs other projects, so the three-node topology is deployed but not
-fully awake. A paused Space answers `503` until it is restarted; nothing
-about the deployment is missing, only the compute quota.
+The free tier caps how many `cpu-basic` Spaces one account may run at once;
+that cap is currently reached by **four** running Spaces on this account, two of
+which serve other projects. `POST .../restart` on a paused Space is refused
+outright (`403`, "you've reached your cpu-basic quota limit"), and a second
+account is not a way around it — creating an additional free Docker Space is
+refused too (`POST /api/repos/create` → `402`; only static Spaces are free).
+
+So the three-node topology is deployed but not fully awake. A paused Space
+answers `503` until a running one is paused to make room; nothing about the
+deployment is missing, only the concurrent-compute quota.
 
 | Space | Role | Runtime stage | `/v1/health` |
 |-------|------|---------------|--------------|
@@ -65,7 +71,8 @@ about the deployment is missing, only the compute quota.
 | [`agentflow-edge-ekb`](https://liovina-agentflow-edge-ekb.hf.space) | edge branch `ekb` | PAUSED | `503` |
 | [`agentflow-demo`](https://liovina-agentflow-demo.hf.space) | standalone demo | PAUSED | `503` |
 
-Probed 2026-07-09 (`GET /v1/health` + `GET /api/spaces/liovina/{name}`).
+Probed 2026-07-09 (`GET /v1/health` + `GET /api/spaces/liovina/{name}`; the two
+quota errors above were reproduced the same day).
 The cross-node evidence ("Verify live" in `deploy/hf-space/three-node/DEPLOY.md`)
 was captured on 2026-07-06 while `ekb` was awake.
 

docs/perf/usage-write-bifurcation-2026-07-09.md

@@ -0,0 +1,124 @@
+# The `Load Test` was not bimodal because of the runner
+
+**Date:** 2026-07-09 · **Status:** root cause found and fixed · **Supersedes:** the
+"CI runner speed" reading of finding N1 in `plan_07_07_26.md`.
+
+## What we thought
+
+`Load Test` runs split into two clusters — roughly 44 rps at p99 ~150 ms, or
+roughly 29 rps at p99 ~1500 ms against thresholds of 900–1200 ms. Runs of both
+kinds existed before and after the B1 usage-write fix, so the split was read as
+runner speed and filed as "not code". The proposed remedies were all variations
+on making the gate tolerate it: re-run on red, take the best of two runs, or
+normalise the threshold against measured rps.
+
+## Why that reading does not survive arithmetic
+
+Across the red/green runs, rps varies by 1.5× while p99 varies by 10×. A
+machine that is 1.5× slower does not produce a 10× tail; it produces a 1.5×
+tail. The nonlinearity means something in the system amplifies a small change
+in service time, which is the signature of a queue, not of a slow CPU.
+
+The decisive clue is in the spread. If the red branch were "an unlucky runner",
+red runs would scatter. They do not:
+
+| branch | runs | aggregate rps |
+|--------|------|---------------|
+| red    | 3    | 29.4 · 29.1 · 28.9 — spread 1.7% |
+| green  | 9    | 37.0 … 46.2 — spread 25% |
+
+Three independent red runs land within 1.7% of each other. That is an
+attractor, not bad luck.
+
+## The mechanism
+
+Every authenticated request wrote its own `api_usage` row before the response
+was produced (`AuthMiddleware` → `run_in_threadpool(record_usage)` →
+`EmbeddedControlPlaneStore.record_api_usage`). DuckDB serializes writers and
+commits per row, so each request queued behind one fsync.
+
+The load client is closed-loop: 15 users, `wait_time = between(0.1, 0.5)`. Let
+`s` be the usage-write service time.
+
+- **Unsaturated branch.** The writer keeps up, so rps is bounded by think time:
+  `15 / (0.3 + L) ≈ 48.9` at small `L`. Observed green maximum: 46.2 rps.
+- **Saturated branch.** Requests queue at the serialized writer, so
+  `L ≈ C·s` where the server-side concurrency is `C = rps · L`. Substituting
+  gives `rps = 1/s` — **independent of the number of users**. That is why the
+  red runs agree with each other: they are all sitting on `1/s`.
+
+At 29 rps the implied `s` is ≈ 34 ms, a plausible fsync on a slow shared disk.
+The bifurcation point is `s ≈ 1/48.9 ≈ 20 ms`: below it the run is think-time
+bound and fast, above it the run collapses onto `1/s`. The runner's disk merely
+decides which side of 20 ms the commit lands on. **The cap is ours.**
+
+## Evidence
+
+**1. The writer serializes (isolated, `duckdb 1.5.1`, one connection, cursors
+per call, the shipped retry loop).** p50 grows linearly with concurrency and
+throughput saturates — the shape of a single-server queue. The retry/backoff
+path was never entered, so it is not the amplifier:
+
+| threads | 1 | 2 | 4 | 8 | 15 | 30 |
+|---------|---|---|---|---|----|----|
+| p50 (ms) | 2.6 | 4.1 | 9.0 | 18.0 | 34.8 | 62.7 |
+| inserts/s | 148 | 244 | 275 | 326 | 325 | 374 |
+
+**2. The collapse reproduces on the shipped code.** Serving the real API with
+the CI load profile and `sleep(s)` injected into `record_api_usage`:
+
+| `s` | rps | p50 (ms) | p99 (ms) |
+|-----|-----|----------|----------|
+| 0 ms | 43.9 | 27 | 100 |
+| 10 ms | 37.8 | 76 | 250 |
+| 25 ms | 36.6 | 82 | 320 |
+| **34 ms** | **31.4** | **160** | 430 |
+| 60 ms | 8.3 | 110 | 21000 |
+
+At `s = 34 ms` the harness lands on 31.4 rps / p50 160 ms; CI's red branch is
+29.1 rps / p50 161 ms.
+
+**3. Taking the write off the request path removes the sensitivity.** Same
+injected `s`, rows enqueued to a background writer:
+
+| `s` | in-path | off-path |
+|-----|---------|----------|
+| 34 ms | 31.4 rps · p99 430 | 37.9 rps · p99 340 |
+| 60 ms | 8.3 rps · p99 21000 · **FAIL** | 37.2 rps · p99 320 · PASS |
+
+Off-path throughput is flat in `s`. In-path throughput is `1/s`.
+
+## The fix
+
+`src/serving/api/auth/usage_writer.py`. The request enqueues a `UsageRow` and
+returns; one background thread drains the queue and writes.
+
+Batching is not an optimisation here, it is part of the fix. A per-row
+background writer would still commit at `1/s` rows per second — below the
+request rate the API can otherwise serve — so the ceiling would simply move
+from request latency into a queue that silently overflows. `record_api_usage_batch`
+puts one commit under N rows, lifting the accounting ceiling to `N/s`.
+
+## What this costs
+
+Durability moves from "committed before the response" to "committed shortly
+after". A crash loses at most the queued rows. `api_usage` backs one admin read
+(`GET /v1/admin/usage`) — it is not billing and not rate limiting — and rows
+were already droppable when the store exhausted its retries. Reads that must
+see their own writes call `flush_usage`; the API lifespan closes the writer on
+shutdown. A full queue sheds rows into `agentflow_usage_rows_dropped_total`
+rather than stalling the request it was counting.
+
+## What this does not claim
+
+The CI disk is still variable, and a heavily degraded runner can still miss a
+p99 threshold. What is gone is the *amplifier*: a 1.5× slower commit now costs
+a 1.5× slower commit, not a collapse of the whole API onto `1/s`. Finding N1
+therefore needs no threshold normalisation — the gate was reporting a real
+defect, and the honest response was to fix it rather than widen the gate.
+
+## Beyond CI
+
+This was never only a CI property. Any deployment on the embedded control plane
+served at most `1 / commit_latency` authenticated requests per second, and every
+request paid the queueing delay. The Load Test was the only place it was visible.

src/serving/api/auth/key_rotation.py

@@ -196,6 +196,9 @@ def shutdown(self) -> None:
     def old_key_usage_by_key_id(self) -> dict[str, int]:
         # ADR 0010 slice 4: routed through the ControlPlaneStore port —
         # was a direct connect_duckdb(self._manager.db_path) query.
+        # api_usage rows are written off the request path, so every reader of
+        # the table drains the writer first or it counts a stale total.
+        self._manager.flush_usage()
         return self._manager.store.get_old_key_usage_by_key_id()
 
     def old_key_usage_last_hour(self, key_id: str) -> int:
@@ -204,6 +207,7 @@ def old_key_usage_last_hour(self, key_id: str) -> int:
     def _usage_by_key(self) -> dict[tuple[str, str], int]:
         # ADR 0010 slice 4: routed through the ControlPlaneStore port —
         # was a direct connect_duckdb(self._manager.db_path) query.
+        self._manager.flush_usage()
         return self._manager.store.get_usage_by_key()
 
     def write_config(self, config: ApiKeysConfig) -> None:

src/serving/api/auth/manager.py

@@ -191,8 +191,12 @@ def __init__(
         if rate_limiter is None and resolved_redis_url is None:
             self.rate_limiter._redis = None
         from .key_rotation import KeyRotator
+        from .usage_writer import UsageWriter
 
         self._key_rotator: KeyRotator = KeyRotator(self)
+        # Constructed eagerly, but its thread starts on the first submitted row
+        # — most AuthManagers (tests, CLI) never record a request.
+        self._usage_writer = UsageWriter(self.store, self.audit_publisher)
 
     def load(self) -> None:
         with self._config_lock:
@@ -444,16 +448,42 @@ def is_entity_allowed(self, tenant_key: TenantKey, entity_type: str) -> bool:
         return entity_type in tenant_key.allowed_entity_types
 
     def record_usage(self, tenant_key: TenantKey, endpoint: str) -> None:
+        """Write the row synchronously and durably. Kept for callers that want
+        the row on disk when this returns; the request path uses
+        ``submit_usage`` instead."""
         from .usage_table import record_usage
 
         record_usage(self, tenant_key, endpoint)
 
+    def submit_usage(self, tenant_key: TenantKey, endpoint: str) -> bool:
+        """Hand the row to the off-path writer. Never blocks, never raises."""
+        from src.serving.control_plane.store import UsageRow
+
+        return self._usage_writer.submit(
+            UsageRow(
+                tenant=tenant_key.tenant,
+                key_name=tenant_key.name,
+                endpoint=endpoint,
+                key_id=tenant_key.key_id,
+                key_slot=tenant_key.matched_slot,
+            )
+        )
+
+    def flush_usage(self, timeout: float = 5.0) -> bool:
+        """Block until queued usage rows are written — read-your-writes."""
+        return self._usage_writer.flush(timeout)
+
+    def close_usage_writer(self, timeout: float = 5.0) -> None:
+        self._usage_writer.close(timeout)
+
     def list_keys_with_usage(self) -> list[dict]:
+        # KeyRotator._usage_by_key flushes — every api_usage reader does.
         return self._key_rotator.list_keys_with_usage()
 
     def usage_by_tenant(self) -> list[dict]:
         from .usage_table import usage_by_tenant
 
+        self.flush_usage()
         return usage_by_tenant(self)
 
     def create_key(self, payload: KeyCreateRequest) -> TenantKey:

src/serving/api/auth/middleware.py

@@ -9,10 +9,9 @@
 import structlog
 from fastapi import Header, HTTPException, Request, Response
 from fastapi.responses import JSONResponse
-from starlette.concurrency import run_in_threadpool
 
 from src.constants import DEFAULT_RATE_LIMIT_WINDOW_SECONDS, FAILED_AUTH_WINDOW_SECONDS
-from src.serving.api.metrics import AUTH_FAILURES, USAGE_RECORD_FAILURES
+from src.serving.api.metrics import AUTH_FAILURES
 from src.serving.api.security import redact_sensitive_headers
 
 from .manager import _CURRENT_TENANT_ID, TenantKey, get_auth_manager
@@ -107,28 +106,25 @@ async def __call__(
             )
 
         manager.clear_failed_auth(client_ip)
-        # record_usage opens a DuckDB connection, writes, and retries with a
-        # blocking sleep; running it inline froze the event loop on every
-        # authenticated request. Offload to a worker thread. (audit_28_06_26.md #13)
+        # Usage accounting is a side-channel: it may not fail the request it is
+        # counting, and it may not pace it either. Writing the row here — even
+        # offloaded to a worker thread — put a serialized DuckDB commit on the
+        # critical path of every authenticated request, capping the API at
+        # `1 / commit_latency` rps and tipping the CI load test into a
+        # saturated equilibrium whenever the runner's disk was slow
+        # (docs/perf/usage-write-bifurcation-2026-07-09.md).
         #
-        # Usage accounting is a side-channel. The store deliberately raises on
-        # exhausted retries (`ControlPlaneStore.record_api_usage`) so that
-        # `record_usage` skips its audit publish — but that exception used to
-        # escape here and turn an otherwise-successful request into a 500
-        # (seen under load, 2026-07-09). Count the dropped row and serve the
-        # request; the counter is the thing to alert on, not the client.
-        try:
-            await run_in_threadpool(manager.record_usage, tenant_key, path)
-        except Exception:
+        # Hand the row to the writer thread and move on. A full queue sheds the
+        # row and counts it; a failed write counts it too. Both counters are
+        # what to alert on, never the client.
+        if not manager.submit_usage(tenant_key, path):
             from src.serving.api import auth as auth_package
 
-            USAGE_RECORD_FAILURES.inc()
             auth_package.logger.warning(
                 "api_usage_record_skipped",
                 tenant=tenant_key.tenant,
                 key_name=tenant_key.name,
                 path=path,
-                exc_info=True,
             )
         is_allowed, remaining, reset_at = await manager.check_rate_limit(tenant_key)
         rate_limit_headers = {