Conversation
sjawhar
marked this pull request as ready for review
August 23, 2026 16:42
request_logs has no index on created_at, so any time-windowed query against it forces a full-table Parallel Seq Scan. In production this is a fixed, traffic-independent cost that grows with the table: the capture-liveness monitor (agent-c's luthien_capture_monitor Lambda) runs a 15-minute-window query every 5 minutes forever, and at 4M+ rows / 3.7GB that scan took ~380ms of CPU on every single invocation regardless of load. Adds idx_request_logs_created_at via CREATE INDEX CONCURRENTLY (the table is live and multi-million-row) with a matching SQLite migration and the copy into utils/sqlite_migrations/ per migrations/AGENTS.md. Verified locally: seeded 2.6M synthetic rows, confirmed EXPLAIN ANALYZE goes from Parallel Seq Scan (99ms) to Index Only Scan (<1ms) once the index and ANALYZE are present.
legion-implementer
Bot
force-pushed
the
fix/request-logs-created-at-index
branch
from
August 23, 2026 16:43
6d9ed85 to
9e8c040
Compare
legion-implementer Bot
pushed a commit
to trajectory-labs-pbc/luthien-proxy
that referenced
this pull request
Aug 23, 2026
psql -f ran without -v ON_ERROR_STOP=1, so a migration with a failing statement would print the error, keep running later statements in the same file, and still exit 0 -- letting the migration get recorded as applied. Every psql call now goes through an ON_ERROR_STOP=1 wrapper, and the one pipe that could mask a psql exit code (the "already applied?" check, via | tr -d ' ') is gone in favor of -t -A. Also closes the CREATE INDEX CONCURRENTLY IF NOT EXISTS retry trap: that clause matches by name only, so an index left INVALID by an interrupted concurrent build is silently accepted as already-there on a retried deploy, with no error for ON_ERROR_STOP to catch. After a migration applies, the runner now checks pg_index.indisvalid for any index it builds CONCURRENTLY before recording success -- protecting idx_request_logs_created_at (LuthienResearch#811) from shipping invalid. Adds a 12-test integration suite pinning both behaviors against a real Postgres, and wires it into CI (scoped to this file -- the broader integration marker has pre-existing unrelated failures that have never run in CI, a separate concern flagged but not fixed here). PR LuthienResearch#812
legion-implementer Bot
pushed a commit
to trajectory-labs-pbc/luthien-proxy
that referenced
this pull request
Sep 8, 2026
…ompleted_at T-form mismatch Round-2 reviewer findings on LuthienResearch#806: (1) Migration number collision: 022 is already claimed by sibling PR LuthienResearch#811 (migrations/{postgres,sqlite}/022_add_request_logs_created_at_index.sql) and 023 by LuthienResearch#813. Renumbered this migration's three copies (postgres, sqlite, bundled) to 024, the next free prefix. (2) request_logs.started_at/completed_at are written via to_timestamp(?) (a float unix-epoch bind, translated by _translate_params to SQLite's native datetime(?, 'unixepoch')), never a raw datetime bind -- so the previous commit's _convert_arg fix never touched them, and SQLite's own datetime(unixepoch) always emits a space separator, permanently (a migration alone cannot fix this for future rows). request_log/service.py's after/before filters bind a raw datetime (datetime.fromisoformat), which after the previous commit becomes T-form via the now-fixed _convert_arg. Without this fix, a same-day after/before filter would silently return wrong results forever -- not just for legacy rows, for every row written after the previous commit landed. Fixed by wrapping the to_timestamp(?) translation in replace(..., ' ', 'T'). Migration 024 also now backfills existing request_logs.started_at/completed_at (added the two UPDATE statements; same LIKE-gated, idempotent shape as the other four columns). red (test_to_timestamp_write_comparable_with_datetime_bind_filter against the to_timestamp(?) → datetime(?, 'unixepoch') translation, no replace()): AssertionError: assert '2026-08-10 12:00:00' == '2026-08-10T12:00:00' also red: test_to_timestamp (asserted bare 'datetime(?, ...)' output before) green (same tests, replace(..., ' ', 'T') wrap restored): uv run pytest tests/luthien_proxy/unit_tests/utils/test_db_sqlite.py -k 'test_to_timestamp or test_to_timestamp_write_comparable' -q --no-cov -> 2 passed green (full file + repo-wide gate on the changed files): uv run pytest tests/luthien_proxy/unit_tests/utils/test_db_sqlite.py -> 46 passed uv run pytest tests/luthien_proxy/unit_tests/utils/test_migration_naming.py tests/luthien_proxy/unit_tests/utils/test_sqlite_migrations_are_native.py -> all pass uv run pytest tests/luthien_proxy/unit_tests -> exit 0 ruff format --check / ruff check / pyright on changed files -> clean Omp-Session: 01a081d4-2514-7000-b8e2-ff8548776146
This branch has not been deployed
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
request_logshas no index oncreated_at(10 other indexes exist on this table, none oncreated_at). Any time-windowed query against it forces a full-tableParallel Seq Scan— most notably a downstream deployment's capture-liveness monitor Lambda, which runs a "rows in the last 15 minutes" check every 5 minutes forever via an EventBridge schedule. At 4.08M rows / 3.7GB, that scan reads ~475k buffer pages and takes ~380ms on every single invocation, regardless of traffic — a fixed, ever-growing tax on the production Aurora cluster's CPU.This PR is one of two required parts (see Companion PR below) — the index alone or the companion query rewrite alone is not sufficient; both are needed together (confirmed empirically:
EXISTS()without this index can be as slow as, or slower than, the originalcount(*), since the planner has no way to find a matching row early without an index).What changed
migrations/postgres/022_add_request_logs_created_at_index.sql:CREATE INDEX CONCURRENTLY IF NOT EXISTS idx_request_logs_created_at ON request_logs (created_at);—CONCURRENTLYbecauserequest_logsis a live, multi-million-row production table; a plainCREATE INDEXwould hold a lock blocking every in-flight INSERT for the full build duration.migrations/sqlite/022_add_request_logs_created_at_index.sql+ the matching bundled copy insrc/luthien_proxy/utils/sqlite_migrations/(permigrations/AGENTS.md) — plainCREATE INDEX IF NOT EXISTS(noCONCURRENTLY; SQLite doesn't have/need it).Production rollout note (read before deploying)
This migration runs automatically at gateway container startup (
docker/start-gateway.sh->docker/run-migrations.sh) on the next deploy. Two things reviewers/operators should know before that happens:docker/run-migrations.shinvokespsql -fwithout-v ON_ERROR_STOP=1. By default,psqlscripts can exit 0 even after a SQL error mid-script, and the runner unconditionally records the migration as applied in_migrationsright after. For most migrations this is low-risk; for this one specifically, an interrupted/failedCREATE INDEX CONCURRENTLYcan leave an invalid index behind under the same name, whichIF NOT EXISTSwould then treat as "already there" on any retry — silently leaving production without a usable index while the tracker says it's applied. This is a pre-existing gap in the migration runner (not introduced by this PR, and out of scope for it), but it's a real risk specifically for this migration. Recommend fixingrun-migrations.shto pass-v ON_ERROR_STOP=1before/alongside this landing, and verifyingpg_index.indisvalidforidx_request_logs_created_atafter deploy regardless.health_check_grace_period_seconds=120"covers normal boot; heavy one-time migrations should still be decoupled from app startup."CREATE INDEX CONCURRENTLYon a live 3.7GB table is exactly that kind of heavy one-time migration — if it runs long, new ECS tasks could sit unbound behind the ALB, exceed the grace period, get killed mid-build, and loop the deployment. Recommend running this migration once as a standalone step (e.g. the existingmigrationsDocker image /Dockerfile.migrations, built for exactly this) against production ahead of the next gateway deploy, then verifyingEXPLAINshows an index scan before rolling the gateway service.I do not have write access to production Aurora to apply or verify this migration myself (only
luthien_admin_iam, a read-onlySELECT/EXPLAINrole — confirmed via a liveCREATE INDEXattempt returningERROR: must be owner of table request_logs), so I could not execute either recommendation above myself.Verification
uv run pytest tests/luthien_proxy/unit_tests/utils/test_migration_naming.py -m "not integration"-> 54 passed.uv run pytest tests/luthien_proxy/integration_tests/test_migration_sync.py -m integrationagainst a fresh localpostgres:16-alpine-> 1 passed (Postgres and SQLite migration sets produce equivalent schemas, including this migration).docker/run-migrations.sh) against a fresh local Postgres and confirmed it applies cleanly and is correctly tracked/skipped on re-run.request_logsrows spread over 30 days and ranEXPLAIN ANALYZEbefore/after:count(*)query ->Parallel Seq Scan, 99.3ms, "Rows Removed by Filter: 863718".ANALYZE): both the oldcount(*)query and the newEXISTS(...)query (see companion PR) ->Index Only Scan, <1ms.luthien_admin_iam) confirmed viaEXPLAIN (ANALYZE, BUFFERS)that the currentcount(*)monitor query is still aParallel Seq Scantoday (382.670ms, 475128 buffer hits, "Rows Removed by Filter: 1394125") and that nocreated_atindex exists yet on the live table.Companion PR
A companion change in a downstream deployment rewrites the capture-monitor Lambda's query from
count(*)toEXISTS(...).