Skip to content

fix: KEEP-1346 index the digest's sponsored-tx count - #2397

Open
OleksandrUA wants to merge 1 commit into
stagingfrom
KEEP-1346-digest-sponsored-count-partial-index
Open

fix: KEEP-1346 index the digest's sponsored-tx count#2397
OleksandrUA wants to merge 1 commit into
stagingfrom
KEEP-1346-digest-sponsored-count-partial-index

Conversation

@OleksandrUA

Copy link
Copy Markdown
Contributor

Closes KEEP-1346.

The problem

The execution digest counts sponsored step runs per organization
(lib/notifications/execution-digest.ts). That query is cancelled by the
statement timeout on prod, so the affected organizations get no digest email at
all.

It fails silently. The CronJob still exits 0. The only trace is an
errors.external.service.total metric with error_context: ExecutionDigest.

Observed on prod, two organizations so far:

when cancelled after cap in force
2026-09-04 14:02:18Z 128.9s 120s parameter group
2026-09-06 14:00:44Z 30.1s 30s app pool
2026-09-08 14:00:39Z 30.5s 30s app pool

Why it is slow

Measured on prod 2026-09-10 with EXPLAIN (ANALYZE, BUFFERS), one single-day
window: 25.3s, 116,611 blocks read (~911 MB), 48 rows returned.

The plan nested-loops from workflows to workflow_executions to
workflow_execution_logs, and the inner probe applies
Filter: (output_raw ->> 'sponsored') = 'true' on every log row of every
execution in the window. output_raw is TOASTed jsonb, so each of the 13,783
loops de-TOASTs about 10 rows and then discards all of them
(Rows Removed by Filter: 10). That single node holds 73.6s of the 73.7s total
I/O time. This is I/O bound, the same shape as KEEP-1333 and KEEP-1334.

Why not just raise the timeout

That was the first instinct and I measured it instead. The same query needs 25s
on a quiet database and more than 129s under contention, so any fixed cap is a
guess. A higher cap also licenses a ~900 MB read during exactly the contention
window where it does the most damage, on an instance that already hit its IOPS
ceiling in KEEP-1333.

Raising APP_STATEMENT_TIMEOUT_MS would also lift the web pods above the 120s
parameter-group backstop that KEEP-1305 just codified, rather than sit under it.
Verified on staging: a connection opened with statement_timeout=180000 reports
source client, which outranks configuration file.

The change

A partial index keyed to the join column, the same shape as the existing
idx_exec_logs_gas_started_at:

CREATE INDEX "idx_exec_logs_sponsored_execution"
  ON "workflow_execution_logs" USING btree ("execution_id")
  WHERE "workflow_execution_logs"."output_raw" ->> 'sponsored' = 'true';

jsonb ->> text is jsonb_object_field_text, which is IMMUTABLE, so the
predicate is legal in an index. Checked against prod pg_proc.provolatile.

Sampling prod with TABLESAMPLE puts sponsored rows at 50 out of 50,201, about
0.1% of the table. So the index holds roughly 25k rows and costs a couple of MB,
against the 453 MB plain execution_id index.

The index is also declared in lib/db/schema.ts, so a dev DB bootstrapped with
db:push builds it too and drizzle does not see it as drift.

Verification

  • The planner matches the predicate. This was the real risk, since Postgres
    only uses a partial index when it can match the query clause to the index
    predicate. On a seeded database the plan shows
    Bitmap Index Scan on idx_exec_logs_sponsored_execution with
    Recheck Cond: ((output_raw ->> 'sponsored'::text) = 'true'::text). It also
    flips the join order so it starts from the sponsored rows instead of looping
    over every execution, which is the behaviour we want on prod.
  • Buffers on that seeded set drop from 323 to 61 with the index present.
  • drizzle-kit generate reports "No schema changes, nothing to migrate".
  • pnpm db:setup-workflow + pnpm db:migrate apply clean on a fresh
    postgres:16, mirroring the migrate-check job.
  • pnpm check, pnpm type-check, pnpm build and pnpm test:unit all pass
    locally (626 test files, 23,067 tests).

Before merge

workflow_execution_logs is ~65 GB on prod, so a plain in-migration
CREATE INDEX would hold an ACCESS EXCLUSIVE lock for minutes during deploy.
The migration therefore carries -- @requires-db-prep and the transaction-safe
IF NOT EXISTS form. An operator builds the index CONCURRENTLY on staging and
sets db-prepped-staging before this merges, then the same on prod at the
staging -> prod release with db-prepped-prod.

Migration number collision: open PRs #2363 and #2344 also claim 0153. Git
will not flag it, because the real conflict is drizzle/meta/0153_snapshot.json.
Whichever of us merges second has to rebase, renumber, and regenerate the
snapshot so prevId chains off the other.

The execution digest counts sponsored step runs per organization. That query
is cancelled by the statement timeout on prod, so the affected organizations
get no digest email at all. It fails silently: the CronJob still exits 0 and
the only trace is an errors.external.service.total metric with error_context
ExecutionDigest.

Measured on prod 2026-09-10 with EXPLAIN (ANALYZE, BUFFERS) over a single-day
window: 25.3 s, 116,611 blocks read (~911 MB), to return 48 rows. The plan
nested-loops from workflows to workflow_executions to workflow_execution_logs
and applies `output_raw ->> 'sponsored' = 'true'` as a filter on every log row
of every execution in the window. output_raw is TOASTed jsonb, so each of the
13,783 loops de-TOASTs about 10 rows and then discards all of them. That one
node holds 73.6 s of the 73.7 s total I/O time.

A higher timeout is not the fix. The same query was cancelled at 128.9 s under
the old 120 s cap during the 2026-09-04 analytics storm, and at ~30 s under the
30 s app-pool bound on 09-06 and 09-08. Quiet it needs 25 s, contended it needs
more than 129 s, so any fixed cap is a guess, and a higher one only licenses a
~900 MB read during the exact contention window where it does the most damage.

Add a partial index keyed to the join column, the same shape as the existing
idx_exec_logs_gas_started_at. Sampling prod puts sponsored rows at about 0.1%
of the table, so the index is a couple of MB against the 453 MB plain
execution_id index. jsonb ->> text is jsonb_object_field_text, which is
IMMUTABLE, so the predicate is legal in an index.

workflow_execution_logs is ~65 GB on prod, so the migration carries
@requires-db-prep and an operator builds the index CONCURRENTLY out of band.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

db-prepped-staging Operator applied lock-free DDL to staging DB; safe to merge no-issue-required PR exempt from the issue-first gate

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant