Skip to content

Commit 7db39f1

Browse files
brownjuly2003-codeJuliaEdomclaude
authored
fix(serving): stop a usage-accounting write from 500-ing a served request (#172)
Every authenticated request appends an api_usage row from a worker thread, and the analytics/admin routers build a throwaway store per request. Each of those opened its own duckdb.connect() on the usage file. The last close destroys the DuckDB instance, so a close racing an open leaves the file attached by two instances and DuckDB raises BinderException: Unique file handle conflict That escaped AuthMiddleware and turned requests that had already succeeded into 500s: the 2026-07-09 Load Test on main saw 19 of 1712 fail across all six endpoints, every traceback ending in record_api_usage -> connect_duckdb. Root cause: EmbeddedControlPlaneStore now holds one owning connection per usage-db path for the life of the process and hands out .cursor() children, the shape DuckDBPool already uses for the serving database. Call sites are untouched — they still close() what they are given, and closing a cursor leaves the connection alive. 80 concurrent usage writes: 80 connects -> 1. Defence in depth: record_api_usage still raises on exhausted retries (its caller depends on that to skip the audit publish), but the middleware now catches it, counts agentflow_usage_record_failures_total, logs api_usage_record_skipped, and serves the request. Accounting is a side-channel and must not fail the request it was counting. Four tests pinned the old per-call-connect mechanism rather than the behaviour; they now drop the cached connection before injecting their fault and assert on retry attempts instead of connect counts. Verified: 1670 unit + 263 integration pass locally; the middleware regression test fails on the pre-fix tree with the exact BinderException. The race's timing reproduces only on the CI runner, so the new tests pin the mechanism that removes it rather than the timing. Co-authored-by: JuliaEdom <uedomskikh@gmail.com> Co-authored-by: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
1 parent 617bbb7 commit 7db39f1

10 files changed

Lines changed: 2234 additions & 1855 deletions

File tree

‎CHANGELOG.md‎

Lines changed: 27 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,33 @@ All notable changes to AgentFlow are documented in this file.
44

55
## [Unreleased]
66

7+
### Fixed — a usage-accounting write could turn a served request into a 500
8+
9+
- **The usage database is now opened once per process.** Every authenticated
10+
request appends an `api_usage` row from a worker thread, and the
11+
analytics/admin routers build a throwaway `EmbeddedControlPlaneStore` per
12+
request; each of those used to call `duckdb.connect()` on the same file. The
13+
last close destroys the DuckDB instance, so a close racing an open left the
14+
file briefly attached by two instances and DuckDB raised
15+
`BinderException: Unique file handle conflict`. `EmbeddedControlPlaneStore`
16+
now keeps one owning connection per usage-db path and hands out `.cursor()`
17+
children — the shape `DuckDBPool` already uses for the serving database.
18+
Callers are unchanged: they still `close()` what they are given, and closing
19+
a cursor leaves the connection alive. Measured on the store's own path: 80
20+
concurrent usage writes went from 80 physical connects to 1.
21+
- **The exception no longer reaches the client.** `record_api_usage` still
22+
raises on exhausted retries — `record_usage` depends on that to skip its
23+
audit publish — but `AuthMiddleware` now catches it, increments the new
24+
`agentflow_usage_record_failures_total` counter, logs
25+
`api_usage_record_skipped`, and serves the request. Accounting is a
26+
side-channel; a dropped row must not fail the request it was counting.
27+
- Caught by the Load Test on `main` (2026-07-09): 19 of 1712 requests returned
28+
500 across all six endpoints, each with `record_api_usage → connect_duckdb`
29+
in the traceback. Regression tests pin both invariants
30+
(`tests/unit/test_usage_db_connection_reuse.py`,
31+
`tests/unit/test_auth_usage_write_failure.py`); the race's timing reproduces
32+
only on the CI runner, so the tests pin the mechanism that removes it.
33+
734
### Changed — one Flink version across pip extra and container runtime (audit 07.07 F2)
835

936
- **The Docker runtime moves 2.2.1 → 2.3.0**, matching the `[flink]` extra

‎src/serving/api/auth/middleware.py‎

Lines changed: 21 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,7 @@
1212
from starlette.concurrency import run_in_threadpool
1313

1414
from src.constants import DEFAULT_RATE_LIMIT_WINDOW_SECONDS, FAILED_AUTH_WINDOW_SECONDS
15-
from src.serving.api.metrics import AUTH_FAILURES
15+
from src.serving.api.metrics import AUTH_FAILURES, USAGE_RECORD_FAILURES
1616
from src.serving.api.security import redact_sensitive_headers
1717

1818
from .manager import _CURRENT_TENANT_ID, TenantKey, get_auth_manager
@@ -110,7 +110,26 @@ async def __call__(
110110
# record_usage opens a DuckDB connection, writes, and retries with a
111111
# blocking sleep; running it inline froze the event loop on every
112112
# authenticated request. Offload to a worker thread. (audit_28_06_26.md #13)
113-
await run_in_threadpool(manager.record_usage, tenant_key, path)
113+
#
114+
# Usage accounting is a side-channel. The store deliberately raises on
115+
# exhausted retries (`ControlPlaneStore.record_api_usage`) so that
116+
# `record_usage` skips its audit publish — but that exception used to
117+
# escape here and turn an otherwise-successful request into a 500
118+
# (seen under load, 2026-07-09). Count the dropped row and serve the
119+
# request; the counter is the thing to alert on, not the client.
120+
try:
121+
await run_in_threadpool(manager.record_usage, tenant_key, path)
122+
except Exception:
123+
from src.serving.api import auth as auth_package
124+
125+
USAGE_RECORD_FAILURES.inc()
126+
auth_package.logger.warning(
127+
"api_usage_record_skipped",
128+
tenant=tenant_key.tenant,
129+
key_name=tenant_key.name,
130+
path=path,
131+
exc_info=True,
132+
)
114133
is_allowed, remaining, reset_at = await manager.check_rate_limit(tenant_key)
115134
rate_limit_headers = {
116135
"X-RateLimit-Limit": str(tenant_key.rate_limit_rpm),

‎src/serving/api/metrics.py‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -26,3 +26,10 @@
2626
"HTTP requests served by the API, labelled by method, route template, and status code.",
2727
labelnames=("method", "route", "status"),
2828
)
29+
30+
# Usage accounting is a side-channel: a dropped row must never fail the request
31+
# it was counting. Non-zero means per-tenant request counters under-report.
32+
USAGE_RECORD_FAILURES = Counter(
33+
"agentflow_usage_record_failures_total",
34+
"Authenticated requests served without their api_usage row being written.",
35+
)

0 commit comments

Comments
 (0)