perf(heartbeat): bound the dispatch head scan independently of queue depth (BLO-20736) by allyblockcast[bot] · Pull Request #1056 · Blockcast/paperclip

allyblockcast · 2026-08-05T20:31:11Z

Thinking Path

Paperclip is the open source app people use to manage AI agents for work

The heartbeat dispatcher decides which of an agent's queued runs starts next, and it does that while holding a strict per-agent start lock

Its head scan filters agent_id = $1 AND status = 'queued' and pages by (created_at, id) with LIMIT 200. PostgreSQL estimates those two equality qualifiers independently and multiplies their selectivities — but they are almost perfectly correlated here: a backlogged agent's rows are overwhelmingly queued, an idle agent has none

On the resulting 43–200x underestimate the planner stops treating the LIMIT as a reason to preserve index order and picks Bitmap Heap Scan + top-N Sort. A sort cannot emit its first row until it has consumed its whole input, so the dispatcher read and sorted the agent's entire queue to return 200 rows — 10,400 rows inspected at depth 5000, growing with the backlog, all under the lock

This pull request reads the page in two phases so the plan no longer depends on that estimate being right

The benefit is that dispatch work is bounded by SCAN_LIMIT instead of by queue depth, exactly when the queue is deep and the lock matters most

Linked Issues or Issue Description

Refs BLO-20736 — no GitHub issue; the work is tracked in Paperclip.

Split out of BLO-20396 / #912, where the underestimate was found while deepening the query-plan fixture. Filed separately because the fix needed its own cost-model evaluation rather than riding along.

Depends on #963 (merged) for migration 0208 and the plan-test fixture this extends.

What Changed

readQueuedDispatchPage (new, server/src/services/heartbeat.ts) — reads one keyset page in two phases.
- Phase 1 projects only (created_at::text, id). Both live in heartbeat_runs_agent_dispatch_idx behind the (agent_id, status) prefix, so the page comes entirely from the index — an ordered Index Only Scan, Heap Fetches: 0, that stops after LIMIT entries.
- Phase 2 hydrates exactly that page by primary key.
- Returns the probe's length and last key, not the hydrated rows'. Deriving either from runs would treat a page thinned by phase 2 as the end of the queue and strand the rest of the backlog.
Head scan and critical lane now go through it.
Removed the now-dead DispatchRun type.
Test — packages/db/src/heartbeat-dispatch-query-plan.test.ts gains "bounds the dispatch head scan independently of queue depth": two depths (1000, 5000) against one shared HEAD_ABSOLUTE_BOUND, on an interleaved + VACUUMed fixture.

Why the projection is the fix, rather than better statistics

With zero heap fetches the ordered path's LIMIT-scaled cost stays ~10 whether the planner believes 117 rows or 5000, while the bitmap alternative must still materialize the whole match set before its sort can emit. The plan is correct despite the bad estimate rather than needing the estimate fixed — which is the second branch of the issue's AC #3, and sturdier than the first.

Two things I tried and rejected, both measured:

Extended statistics on (agent_id, status) does fix the estimate (rows=1107 vs 1000 actual) and then makes the plan worse — the planner switches to a BitmapAnd of two other indexes and still sorts.
Adding AND status = 'queued' to the phase-2 fetch makes the dispatch index look attractive again, so PostgreSQL drives the hydrate from it instead of the primary key and the unbounded shape returns. The dispatcher re-checks status in JS instead.

Deliberately not converted: the recovery lane

The recovery lane has the same unbounded shape but filters context_snapshot ->> 'source', which is JSONB and not in the dispatch index. Phase 1 is only cheap because it is index-covered; applying this there would make it page through all queued rows hunting for recovery rows — strictly worse. It has its own absolute bound and its own test.

Verification

pnpm vitest run packages/db/src/heartbeat-dispatch-query-plan.test.ts — 3/3 passing, embedded Postgres, on this branch rebased onto master. Full monorepo typecheck green.

The assertions are on rowsInspected, which counts rows discarded by filters, so a plan that reads the queue and sorts it cannot pass by reporting its 200 output rows. Both depths share one ceiling — deriving it per-depth would make the claim vacuous.

depth	rows inspected — before	after	exec — before	after	buffers — before	after	planner estimate
1,000	2,400	400	6.156 ms	0.395 ms	1,016	5	5 vs 1000 — 200x low
5,000	10,400	400	28.110 ms	0.411 ms	3,846 hit + 1,229 read	5	117 vs 5000 — 43x low

Before grows 4.3x with the backlog; after is flat, and stays flat while the estimate is still 43x wrong.

Plan report artifact — EXPLAIN (ANALYZE, BUFFERS), before/after, both depths

Reproduce with BLO20396_PLAN_REPORT=/path/to/report. UUID lists collapsed for readability; everything else verbatim.


===== depth 1000: head scan BEFORE (SELECT *) =====
Limit  (cost=24.07..24.08 rows=5 width=1457) (actual time=6.019..6.067 rows=200.00 loops=1)
  Buffers: shared hit=1016
  ->  Sort  (cost=24.07..24.08 rows=5 width=1457) (actual time=6.016..6.037 rows=200.00 loops=1)
        Sort Key: created_at, id
        Sort Method: top-N heapsort  Memory: 228kB
        Buffers: shared hit=1016
        ->  Bitmap Heap Scan on heartbeat_runs  (cost=4.33..24.01 rows=5 width=1457) (actual time=3.143..5.380 rows=1000.00 loops=1)
              Recheck Cond: ((agent_id = '22222222-2222-4222-8222-222222222222'::uuid) AND (status = 'queued'::text))
              Heap Blocks: exact=1000
              Buffers: shared hit=1016
              ->  Bitmap Index Scan on heartbeat_runs_agent_dispatch_idx  (cost=0.00..4.33 rows=5 width=0) (actual time=2.871..2.871 rows=1000.00 loops=1)
                    Index Cond: ((agent_id = '22222222-2222-4222-8222-222222222222'::uuid) AND (status = 'queued'::text))
                    Index Searches: 1
                    Buffers: shared hit=16
Planning:
  Buffers: shared hit=4
Planning Time: 0.410 ms
Execution Time: 6.156 ms
-- rows inspected: 2400

===== depth 1000: head probe (created_at, id only) =====
Limit  (cost=0.28..4.40 rows=5 width=56) (actual time=0.054..0.337 rows=200.00 loops=1)
  Buffers: shared hit=5
  ->  Index Only Scan using heartbeat_runs_agent_dispatch_idx on heartbeat_runs  (cost=0.28..4.40 rows=5 width=56) (actual time=0.052..0.293 rows=200.00 loops=1)
        Index Cond: ((agent_id = '22222222-2222-4222-8222-222222222222'::uuid) AND (status = 'queued'::text))
        Heap Fetches: 0
        Index Searches: 1
        Buffers: shared hit=5
Planning:
  Buffers: shared hit=4
Planning Time: 1.001 ms
Execution Time: 0.395 ms
-- rows inspected: 400

===== depth 1000: head probe, resumed =====
Limit  (cost=0.28..4.42 rows=5 width=56) (actual time=0.143..2.988 rows=200.00 loops=1)
  Buffers: shared hit=6
  ->  Index Only Scan using heartbeat_runs_agent_dispatch_idx on heartbeat_runs  (cost=0.28..4.42 rows=5 width=56) (actual time=0.141..2.957 rows=200.00 loops=1)
        Index Cond: ((agent_id = '22222222-2222-4222-8222-222222222222'::uuid) AND (status = 'queued'::text) AND (ROW(created_at, id) > ROW((now() - '25:00:00'::interval), '00000000-0000-4000-8000-000000000000'::uuid)))
        Heap Fetches: 0
        Index Searches: 1
        Buffers: shared hit=6
Planning:
  Buffers: shared hit=4
Planning Time: 0.354 ms
Execution Time: 3.042 ms
-- rows inspected: 400

===== depth 1000: page hydrate by primary key =====
Bitmap Heap Scan on heartbeat_runs  (cost=818.05..1515.70 rows=200 width=1457) (actual time=1.043..1.380 rows=200.00 loops=1)
  Recheck Cond: (id = ANY ('{04bbd9ac, 3a3dc7c5, 705092ff, … 197 more …}'::uuid[]))
  Heap Blocks: exact=200
  Buffers: shared hit=743
  ->  Bitmap Index Scan on heartbeat_runs_pkey  (cost=0.00..817.50 rows=200 width=0) (actual time=0.995..0.995 rows=200.00 loops=1)
        Index Cond: (id = ANY ('{04bbd9ac, 3a3dc7c5, 705092ff, … 197 more …}'::uuid[]))
        Index Searches: 181
        Buffers: shared hit=543
Planning:
  Buffers: shared hit=4
Planning Time: 0.508 ms
Execution Time: 1.435 ms
-- rows inspected: 400

===== depth 5000: head scan BEFORE (SELECT *) =====
Limit  (cost=438.58..438.88 rows=117 width=1457) (actual time=27.951..28.013 rows=200.00 loops=1)
  Buffers: shared hit=3846 read=1229 written=316
  ->  Sort  (cost=438.58..438.88 rows=117 width=1457) (actual time=27.948..27.974 rows=200.00 loops=1)
        Sort Key: created_at, id
        Sort Method: top-N heapsort  Memory: 228kB
        Buffers: shared hit=3846 read=1229 written=316
        ->  Bitmap Heap Scan on heartbeat_runs  (cost=9.48..434.56 rows=117 width=1457) (actual time=3.623..24.073 rows=5000.00 loops=1)
              Recheck Cond: ((agent_id = '22222222-2222-4222-8222-222222222222'::uuid) AND (status = 'queued'::text))
              Heap Blocks: exact=5000
              Buffers: shared hit=3846 read=1229 written=316
              ->  Bitmap Index Scan on heartbeat_runs_agent_dispatch_idx  (cost=0.00..9.45 rows=117 width=0) (actual time=1.748..1.749 rows=5000.00 loops=1)
                    Index Cond: ((agent_id = '22222222-2222-4222-8222-222222222222'::uuid) AND (status = 'queued'::text))
                    Index Searches: 1
                    Buffers: shared hit=69 read=6 written=2
Planning:
  Buffers: shared hit=4
Planning Time: 0.422 ms
Execution Time: 28.110 ms
-- rows inspected: 10400

===== depth 5000: head probe (created_at, id only) =====
Limit  (cost=0.28..11.21 rows=117 width=56) (actual time=0.051..0.352 rows=200.00 loops=1)
  Buffers: shared hit=5
  ->  Index Only Scan using heartbeat_runs_agent_dispatch_idx on heartbeat_runs  (cost=0.28..11.21 rows=117 width=56) (actual time=0.050..0.313 rows=200.00 loops=1)
        Index Cond: ((agent_id = '22222222-2222-4222-8222-222222222222'::uuid) AND (status = 'queued'::text))
        Heap Fetches: 0
        Index Searches: 1
        Buffers: shared hit=5
Planning:
  Buffers: shared hit=4
Planning Time: 0.389 ms
Execution Time: 0.411 ms
-- rows inspected: 400

===== depth 5000: head probe, resumed =====
Limit  (cost=0.29..11.20 rows=106 width=56) (actual time=0.040..0.342 rows=200.00 loops=1)
  Buffers: shared hit=6
  ->  Index Only Scan using heartbeat_runs_agent_dispatch_idx on heartbeat_runs  (cost=0.29..11.20 rows=106 width=56) (actual time=0.039..0.289 rows=200.00 loops=1)
        Index Cond: ((agent_id = '22222222-2222-4222-8222-222222222222'::uuid) AND (status = 'queued'::text) AND (ROW(created_at, id) > ROW((now() - '25:00:00'::interval), '00000000-0000-4000-8000-000000000000'::uuid)))
        Heap Fetches: 0
        Index Searches: 1
        Buffers: shared hit=6
Planning:
  Buffers: shared hit=4
Planning Time: 0.407 ms
Execution Time: 0.399 ms
-- rows inspected: 400

===== depth 5000: page hydrate by primary key =====
Bitmap Heap Scan on heartbeat_runs  (cost=818.05..1514.70 rows=200 width=1457) (actual time=1.323..1.694 rows=200.00 loops=1)
  Recheck Cond: (id = ANY ('{4c657e79, 7b133d72, f1c9a56c, … 197 more …}'::uuid[]))
  Heap Blocks: exact=200
  Buffers: shared hit=737
  ->  Bitmap Index Scan on heartbeat_runs_pkey  (cost=0.00..817.50 rows=200 width=0) (actual time=1.256..1.256 rows=200.00 loops=1)
        Index Cond: (id = ANY ('{4c657e79, 7b133d72, f1c9a56c, … 197 more …}'::uuid[]))
        Index Searches: 179
        Buffers: shared hit=537
Planning:
  Buffers: shared hit=4
Planning Time: 0.599 ms
Execution Time: 1.768 ms
-- rows inspected: 400```

</details>

## Risks

**Low, with two worth naming.**

- **No migration, no schema change, no index change** — this is a read-path change only, and it is a strict reduction in what the dispatcher reads.
- **A page can now be shorter than what was probed.** Phase 1 and phase 2 are separate statements, so a row that leaves the queue between them is dropped. That is why exhaustion and cursor advance are driven by `probed`, never by `runs.length` — using the latter would end the scan early and strand the backlog. Rows are re-checked as `queued` in JS before dispatch, so the change cannot dispatch a row that has already left the queue.
- **Two statements instead of one**, so the page is not read atomically. It never was consistent in a meaningful sense — the previous single query also raced anything that changed the queue after it ran — and every row is re-validated under the start lock before it is claimed.

Behaviour under `deferredRunIds` is preserved: the exclusion moved into phase 1, so deferred runs are filtered before the cursor advances rather than after.

## Model Used

Claude Opus 5 (`claude-opus-5`), 1M context, extended thinking, agentic tool use (Claude Code).

## Checklist

- [x] I have included a thinking path that traces from project context to this change
- [x] I have specified the model used (with version and capability details)
- [x] I have checked ROADMAP.md and confirmed this PR does not duplicate planned core work
- [x] I have searched GitHub for duplicate or related PRs and linked them above (#912, #963)
- [x] I have either (a) linked existing issues OR (b) described the issue in-PR
- [x] I have run tests locally and they pass (3/3 plan suite, full typecheck)
- [x] I have added or updated tests where applicable
- [x] If this change affects the UI, I have included before/after screenshots — n/a, no UI surface
- [x] I have updated relevant documentation to reflect my changes — the rationale is in code comments at the helper, which is where the next person hits it
- [x] I have considered and documented any risks above
- [ ] All Paperclip CI gates are green — pending first CI run on this PR
- [ ] Greptile is 5/5 with no open P2s, recommendations, or follow-ups — pending first review
- [x] I will address all Greptile and reviewer comments before requesting merge

…depth (BLO-20736) The dispatcher's keyset scan filters agent_id = $1 AND status = 'queued' and orders by (created_at, id) with LIMIT 200. PostgreSQL estimates the two equality qualifiers independently and multiplies their selectivities, but they are almost perfectly correlated: a backlogged agent's rows are overwhelmingly queued, an idle agent has none. Measured on a 200k-row interleaved fixture the estimate is 250x low at queue depth 1000 (rows=4 vs 1000) and 42x low at depth 5000 (rows=118 vs 5000). On an estimate that small the planner stops treating LIMIT as a reason to preserve index order and picks Bitmap Heap Scan + top-N Sort. A sort cannot emit until it has consumed its whole input, so the dispatcher read and sorted the agent's ENTIRE queue to return 200 rows, under the strict per-agent start lock, getting worse as the backlog deepened. Read the page in two phases instead. Phase 1 projects ONLY (created_at, id) -- both live in heartbeat_runs_agent_dispatch_idx behind the (agent_id, status) prefix, so the page comes from an ordered Index Only Scan with no heap access that stops after SCAN_LIMIT entries. Phase 2 hydrates exactly that page by primary key. Measured, at both depths: 1000 -> 200 and 5000 -> 200 rows actually read. The projection is what makes the plan insensitive to the estimate rather than dependent on fixing it: with no heap fetches to pay for, the ordered path's LIMIT-scaled cost stays ~10 whether the planner believes 118 rows or 5167, while the bitmap alternative must still materialize the whole match set before its sort emits. The plan stays correct at a still-42x wrong estimate. Deliberately NOT fixed with extended statistics: CREATE STATISTICS ON (agent_id, status) does correct the estimate and then makes the plan worse -- the planner switches to a BitmapAnd of two other indexes and still sorts. Measured at both depths, and inconsistent between them. Phase 2 takes the id list as its only SQL predicate and re-checks status in JS. Adding AND status = 'queued' there makes the dispatch index attractive again and PostgreSQL drives the fetch from it instead of the primary key, reintroducing the unbounded shape phase 1 exists to remove. Callers advance the cursor from the probe rather than from the hydrated rows, so a page thinned by a row leaving the queue between the two statements is not mistaken for the end of the backlog. The new plan test asserts both properties at two depths against one shared ceiling, on a fixture whose queued rows are interleaved one per heap page rather than packed at the tail -- against tight clustering bitmap+sort genuinely is the better plan, so the packed fixture would be asserting the wrong thing. Co-Authored-By: Claude <noreply@anthropic.com>

allyblockcast · 2026-08-05T20:31:14Z

🔗 Paperclip issue: BLO-20396
🔗 Paperclip issue: BLO-20736

allyblockcast · 2026-08-05T20:40:12Z

Ally — Consolidated PR Review

Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex.
Reviewed head: 9575d9c

Important Issues (2)

[gstack/review] server/src/services/heartbeat.ts:18053 — excludeRunIds makes the new probe's work grow with the deferred backlog. Emergency admission refusals accumulate in dispatchDeferredRunIdsByAgent, and NOT IN (...) is evaluated while walking the ordered index. Returning 200 non-deferred rows, or proving none remain, can therefore inspect every older deferred row under the start lock. Probe an unfiltered bounded page, filter deferred IDs after the cursor-bearing probe, and advance from that raw page; add a plan/liveness case with many deferred IDs.
[pr-review-toolkit] packages/db/src/heartbeat-dispatch-query-plan.test.ts:635 — the regression test explains a hand-written copy of the intended SQL instead of exercising or capturing readQueuedDispatchPage. It remains green if production later widens phase 1, adds a plan-breaking predicate, or diverges from the duplicated SQL, and it does not cover the documented row-leaves-queue race between probe and hydration. Drive the production query path against the deep fixture (or assert on captured generated SQL/plans), and add an inter-phase status-change case that verifies cursor progress and backlog liveness.

Suggestions (1)

[gstack/review] packages/db/src/heartbeat-dispatch-query-plan.test.ts:618 — retain a non-all-visible fixture alongside the VACUUMed happy path. The implementation comments acknowledge that visibility-map lag can restore bitmap-plus-sort, but the test currently guarantees the favorable state rather than measuring that known degradation.

Strengths

Cursor and exhaustion bookkeeping correctly derives from the probe rather than the potentially thinned hydration result.
The exact-head plan evidence demonstrates a substantial bounded-path improvement for the common all-visible case.
The primary-key hydration deliberately avoids reintroducing the broad dispatch-index scan.

Recommended Action

Address the deferred-ID bound and couple the plan regression test to the production query path.
Re-run the exact-head query-plan and queue-convergence suites.
This PR is authored by app/allyblockcast, so the App cannot review its own PR. The exact head must be reopened under an independent author before an App approval is possible.

kkroo · 2026-08-06T02:08:24Z

Superseded by #1069, which addresses the deferred-ID probe bound review finding, adds the deferred backlog plan/liveness case, and is opened from a human-authored branch for Ally review.

kkroo mentioned this pull request Aug 6, 2026

perf(heartbeat): keep deferred runs out of dispatch probe SQL (BLO-20736) #1069

Open

13 tasks

kkroo closed this Aug 6, 2026

Navigation Menu

Uh oh!

perf(heartbeat): bound the dispatch head scan independently of queue depth (BLO-20736) - #1056

perf(heartbeat): bound the dispatch head scan independently of queue depth (BLO-20736)#1056
allyblockcast[bot] wants to merge 1 commit into
masterfrom
cto/blo-20736-dispatch-plan

allyblockcast Bot commented Aug 5, 2026

Uh oh!

allyblockcast Bot commented Aug 5, 2026

Uh oh!

allyblockcast Bot commented Aug 5, 2026

Uh oh!

kkroo commented Aug 6, 2026

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

1 participant

Uh oh!

Conversation

allyblockcast Bot commented Aug 5, 2026

Thinking Path

Linked Issues or Issue Description

What Changed

Why the projection is the fix, rather than better statistics

Deliberately not converted: the recovery lane

Verification

Uh oh!

allyblockcast Bot commented Aug 5, 2026

Uh oh!

allyblockcast Bot commented Aug 5, 2026

Ally — Consolidated PR Review

Important Issues (2)

Suggestions (1)

Strengths

Recommended Action

Uh oh!

kkroo commented Aug 6, 2026

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

1 participant