From 0f1052a4981fe4a8363ad679c428f220f891cb07 Mon Sep 17 00:00:00 2001 From: Alex Date: Thu, 6 Aug 2026 15:49:07 +0100 Subject: [PATCH 1/2] Create 0027_user_logs_agent_lookup_idx.py --- .../0027_user_logs_agent_lookup_idx.py | 84 +++++++++++++++++++ 1 file changed, 84 insertions(+) create mode 100644 application/alembic/versions/0027_user_logs_agent_lookup_idx.py diff --git a/application/alembic/versions/0027_user_logs_agent_lookup_idx.py b/application/alembic/versions/0027_user_logs_agent_lookup_idx.py new file mode 100644 index 00000000..ceb8d545 --- /dev/null +++ b/application/alembic/versions/0027_user_logs_agent_lookup_idx.py @@ -0,0 +1,84 @@ +"""0027 index the per-agent log lookups so /api/get_user_logs stops timing out. + +The per-agent Logs timeline filters ``user_logs`` on two JSONB keys +(``data->>'api_key'`` / ``data->>'agent_id'``) and ``stack_logs`` on +``(agent_id OR api_key)``. None of those had a usable index, so both branches +seq-scanned. + +``user_logs`` is the expensive one, and not for the obvious reason: its heap is +only ~107 MB but ``data`` is a ~1.16 GB TOAST, and filtering on a JSONB key +forces a detoast of *every* row. Measured on prod (99,535 rows): **618,809 +buffer accesses to return 6,012 rows — 4.5 s warm, >90 s cold**, against a 30 s +``STATEMENT_TIMEOUT_MS``. That warm/cold spread is why the endpoint failed +intermittently rather than always. (``stack_logs`` seq-scans too but stays +~38 ms: its filter columns live in the heap, so its own 1.9 GB TOAST is never +touched.) + +The two expression indexes turn that detoast scan into a direct lookup. They +also give the planner statistics on the expressions, which it badly lacked — +it estimated 974 rows where the truth was 6,012. + +``stack_logs (api_key)`` matters for a subtler reason: 0026 added +``ix_stack_logs_agent_id`` and it works well in isolation (1,759 buffers / +11.6 ms), but the query ORs it against the unindexed ``api_key`` and Postgres +cannot BitmapOr when only one side is indexed — so the new index was being +bypassed entirely. Indexing the second arm is what actually activates it. + +Indexes are built ``CONCURRENTLY`` in autocommit blocks (following 0018): a +plain CREATE INDEX would take an ACCESS EXCLUSIVE lock on a 1.3 GB table on a +live database. The ``user_logs`` builds each detoast the full ~1.16 GB once, so +they are not instant; CONCURRENTLY keeps them non-blocking. Idempotent both +ways. + +Revision ID: 0027_user_logs_agent_lookup_idx +Revises: 0026_stack_logs_agent_id +""" + +from typing import Sequence, Union + +from alembic import op + + +revision: str = "0027_user_logs_agent_lookup_idx" +down_revision: Union[str, None] = "0026_stack_logs_agent_id" +branch_labels: Union[str, Sequence[str], None] = None +depends_on: Union[str, Sequence[str], None] = None + + +# Partial: only rows that actually carry the key are ever looked up by it, and +# most user_logs rows (owner chats) carry neither, so this keeps the indexes +# small without changing which rows they can answer for. +_INDEXES = ( + ( + "user_logs_data_api_key_idx", + "user_logs ((data->>'api_key'))", + "(data->>'api_key') IS NOT NULL", + ), + ( + "user_logs_data_agent_id_idx", + "user_logs ((data->>'agent_id'))", + "(data->>'agent_id') IS NOT NULL", + ), + ( + "stack_logs_api_key_idx", + "stack_logs (api_key)", + "api_key IS NOT NULL", + ), +) + + +def upgrade() -> None: + # CONCURRENTLY can't run inside a transaction; the autocommit block lets + # each build run without locking out writers on a multi-GB live table. + for name, target, predicate in _INDEXES: + with op.get_context().autocommit_block(): + op.execute( + f"CREATE INDEX CONCURRENTLY IF NOT EXISTS {name} " + f"ON {target} WHERE {predicate};" + ) + + +def downgrade() -> None: + for name, _target, _predicate in reversed(_INDEXES): + with op.get_context().autocommit_block(): + op.execute(f"DROP INDEX CONCURRENTLY IF EXISTS {name};") From e7acd5979bba23bc2daac0e5518d4d35d460bed7 Mon Sep 17 00:00:00 2001 From: Alex Date: Thu, 6 Aug 2026 16:24:27 +0100 Subject: [PATCH 2/2] fix: minor issue and order --- ....py => 0028_user_logs_agent_lookup_idx.py} | 44 ++++++++++++++++--- 1 file changed, 37 insertions(+), 7 deletions(-) rename application/alembic/versions/{0027_user_logs_agent_lookup_idx.py => 0028_user_logs_agent_lookup_idx.py} (63%) diff --git a/application/alembic/versions/0027_user_logs_agent_lookup_idx.py b/application/alembic/versions/0028_user_logs_agent_lookup_idx.py similarity index 63% rename from application/alembic/versions/0027_user_logs_agent_lookup_idx.py rename to application/alembic/versions/0028_user_logs_agent_lookup_idx.py index ceb8d545..6deb7d20 100644 --- a/application/alembic/versions/0027_user_logs_agent_lookup_idx.py +++ b/application/alembic/versions/0028_user_logs_agent_lookup_idx.py @@ -1,4 +1,4 @@ -"""0027 index the per-agent log lookups so /api/get_user_logs stops timing out. +"""0028 index the per-agent log lookups so /api/get_user_logs stops timing out. The per-agent Logs timeline filters ``user_logs`` on two JSONB keys (``data->>'api_key'`` / ``data->>'agent_id'``) and ``stack_logs`` on @@ -27,11 +27,13 @@ bypassed entirely. Indexing the second arm is what actually activates it. Indexes are built ``CONCURRENTLY`` in autocommit blocks (following 0018): a plain CREATE INDEX would take an ACCESS EXCLUSIVE lock on a 1.3 GB table on a live database. The ``user_logs`` builds each detoast the full ~1.16 GB once, so -they are not instant; CONCURRENTLY keeps them non-blocking. Idempotent both -ways. +they are not instant; CONCURRENTLY keeps them non-blocking. Because a cancelled +concurrent build leaves an INVALID index behind that ``IF NOT EXISTS`` would +then skip forever, each build first clears such a leftover — see +``_rebuild_if_invalid``. Idempotent both ways. -Revision ID: 0027_user_logs_agent_lookup_idx -Revises: 0026_stack_logs_agent_id +Revision ID: 0028_user_logs_agent_lookup_idx +Revises: 0027_schedule_run_error_types """ from typing import Sequence, Union @@ -39,8 +41,8 @@ from typing import Sequence, Union from alembic import op -revision: str = "0027_user_logs_agent_lookup_idx" -down_revision: Union[str, None] = "0026_stack_logs_agent_id" +revision: str = "0028_user_logs_agent_lookup_idx" +down_revision: Union[str, None] = "0027_schedule_run_error_types" branch_labels: Union[str, Sequence[str], None] = None depends_on: Union[str, Sequence[str], None] = None @@ -67,11 +69,39 @@ _INDEXES = ( ) +def _rebuild_if_invalid(name: str) -> None: + """Drop ``name`` only when a previous concurrent build left it INVALID. + + A failed/cancelled ``CREATE INDEX CONCURRENTLY`` does not roll back — it + leaves an index in the catalog with ``indisvalid = false`` that still owns + the name. ``IF NOT EXISTS`` then skips it forever, so the migration reports + success while the planner refuses to use the index: a silent no-op. Clearing + it first makes the rebuild actually happen. + + The check is deliberately conditional rather than an unconditional drop + (0018's approach): the ``user_logs`` builds detoast ~1.16 GB each, so + re-running this migration against a healthy database should not pay that + cost again. ``to_regclass`` returns NULL for a name that doesn't exist, so + the first run selects no row and skips the drop. + """ + invalid = ( + op.get_bind() + .exec_driver_sql( + "SELECT NOT indisvalid FROM pg_index " + f"WHERE indexrelid = to_regclass('{name}')" + ) + .scalar() + ) + if invalid: + op.execute(f"DROP INDEX CONCURRENTLY IF EXISTS {name};") + + def upgrade() -> None: # CONCURRENTLY can't run inside a transaction; the autocommit block lets # each build run without locking out writers on a multi-GB live table. for name, target, predicate in _INDEXES: with op.get_context().autocommit_block(): + _rebuild_if_invalid(name) op.execute( f"CREATE INDEX CONCURRENTLY IF NOT EXISTS {name} " f"ON {target} WHERE {predicate};"