refactor(channel): claim media ledger rows one at a time (MUL-5367) - #5993
Conversation
|
@beastpu is attempting to deploy a commit to the IndexLabs Team on Vercel. A member of the Team first needs to authorize it. |
37ff740 to
24e0865
Compare
Follow-up to multica-ai#5580. The reconciler claimed up to 50 rows in one statement and then processed them serially, so a tail row sat in 'deleting' with its attempt already bumped while earlier rows ran. If the batch outlived the lease, that row could be reclaimed and bumped again before its own DELETE had ever been tried — attempt and backoff counted work that never happened, and the backoff they produced delayed the first real attempt. Rows are now claimed one at a time, immediately before their own settle, so a claim is always a promise the sweep keeps in the next few hundred milliseconds. The per-sweep limit is unchanged (50), and so are the settle, lease, tenancy and state predicates. The per-row lease heartbeat goes with it: it existed because one lease had to span a whole batch. A claim now precedes its row's work directly (delete timeout 30s << lease 2m), and every settle write is already lease-token guarded, so a row reclaimed after an expiry ignores the old owner's writes rather than being corrupted by them. Test replaces the mid-batch reclaim case with the invariant behind it: while the first row's delete runs, the next row is still unclaimed ('pending', attempt 0), and both are still settled by the same sweep. It fails against the batch-claiming implementation. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
24e0865 to
05d7b90
Compare
Bohan-J
left a comment
There was a problem hiding this comment.
Reviewed at 05d7b904c. The product direction is right and the core semantics of the change hold up under testing — I verified the tail-row invariant, the loop-termination argument, and the whole existing suite. One blocking issue on the database side, plus a few non-blocking nits.
Must-fix: the per-row claim loses its bounded cost under backlog
ClaimNextChannelMediaPendingObjectForReconcile orders by next_attempt_at across all three states. The existing index from migration 230 is (state, next_attempt_at), so with state leading it cannot serve that cross-state ordering directly. What the planner does with it depends on how many rows are due, and the two regimes behave very differently.
Measured on a freshly migrated database with 100k ledger rows (EXPLAIN (ANALYZE, COSTS OFF), after VACUUM ANALYZE):
Steady state — 100 rows due out of 100k. Fine. The planner uses the existing index via a BitmapOr and sorts a tiny result:
Sort Method: quicksort Memory: 29kB
-> Bitmap Heap Scan on channel_media_pending_object cand (rows=100)
Execution Time: 0.070 ms
Backlog — 100k rows due. This is where it breaks down. The plan degrades to a full scan plus a full external sort, and FOR UPDATE blocks the bounded top-N optimization, so LIMIT 1 and LIMIT 50 cost the same:
LIMIT 1 (this PR, run up to 50x per sweep)
Sort Method: external merge Disk: 4696kB
-> Seq Scan on channel_media_pending_object cand (rows=100000)
Execution Time: 16.719 ms
LIMIT 50 (previous batch claim, run 1x per sweep)
Sort Method: external merge Disk: 4696kB
-> Seq Scan on channel_media_pending_object cand (rows=100000)
Execution Time: 15.199 ms
Per sweep that is roughly 15 ms and 4.7 MB of temp files before, versus ~835 ms and ~235 MB of temp file writes after — the same work repeated up to 50 times instead of once, because the old code paid the ordering cost once and then addressed each row by primary key through the heartbeat. The round-trip count is essentially unchanged (see the note below), but the database work is not.
The reason I think this blocks: the amplification is worst exactly when object storage is degraded and the ledger has backed up, which is the scenario the reconciler exists to drain. A background cleaner should not get ~50x more expensive as its backlog grows.
Two ways to fix it, either is fine:
-
Add an index that can serve the ordering directly, in its own
CREATE INDEX CONCURRENTLYmigration per the repo convention. A plain btree on(next_attempt_at)was enough in my test — the plan became an orderedIndex Scanwith no temp files:-> Index Scan using idx_test_due on channel_media_pending_object cand (rows=1) Execution Time: 0.322 ms -
Keep the ordering cost at once per sweep without a new migration: select the due keys once, then claim each key by primary key immediately before its work. That preserves the entire point of this PR — the claim is still taken immediately before the work it authorizes, so
attemptstill counts real attempts — while the expensive ordered scan happens once. A key another replica already took simply claims 0 rows and is skipped, which is the same outcomeSKIP LOCKEDgives you today.
Whichever you pick, could you include the EXPLAIN output for the backlog case in the PR so the plan is pinned to evidence rather than to the planner's current mood?
Non-blocking nits
TestChannelMediaReconciler_CancelledSweepIsQuietpromises more than the code delivers. Only cancellation at the claim boundary is quiet. If cancellation lands insidesettle— say duringDeleteObject—release()logssettle failed; backing offunconditionally and then writes with the already-cancelled context, loggingrelease failedtoo, so shutdown still emits two warnings per in-flight row. This is pre-existing, not something this PR introduced, but the test name reads as a broader guarantee than exists. Either rename it toCancelledClaimIsQuiet, or short-circuitrelease()onctx.Err() != nil.- The
settledloop variable counts claim iterations, not settled rows — it increments on failed settles too. Relatedly, with the batch gone a sweep is no longer "at most one attempt per row": a long sweep (50 rows at the 30s delete timeout is ~25 min) can re-claim a row that was released early with a 1-minute backoff. Total work stays capped at 50, so this is bounded and equivalent to what the next sweep would have done anyway — butchannelMediaReconcileSweepLimit's comment, "bounds how many rows one sweep settles", is no longer precise. "settle operations per sweep" would be accurate. - Dropping the
renewed == 0check removes an explicit ownership re-check before the DELETE. The tradeoff looks sound to me — it needs a settle to exceed the 2-minute lease, the delete is capped at 30s, the invariant test pins lease >= 2x that timeout, the DELETE is idempotent by design, and every ledger write is lease-token guarded. Flagging it only so it is a conscious trade rather than an unnoticed one. logs.Len() != 0is a strict assertion — any future debug log inRunOncewill turn that test red.
What checks out
To be clear about what I did verify, since most of this PR is solid:
- No same-sweep spin. This was my main worry with batch to loop, and it holds: the claim predicate requires
next_attempt_at <= now(), and everysettleexit path either pushesnext_attempt_atforward (>= 1 min backoff, >= 15 min tombstone), deletes the row, or leaves the lease held. A permanently failing row cannot be hammered 50 times in one sweep. - The new tests are real regression pins. I reverted the implementation to the parent commit while keeping the new test file: both new tests fail, and
TailRowIsUnclaimedUntilItsTurnfails with exactly the message your description quotes. - 15 reconciler tests plus the
cmd/serverinvariant test pass, including under-race.go vetclean.sqlcregeneration produces no diff. No dangling references to the three removed symbols. - Minor correction in your favour: the Cost section undersells the change. The old path was 1 batch claim + N per-row heartbeats = N+1 round trips; the new one is N claims, so round trips are flat to slightly lower, not "N instead of one". The cost concern here is database work per claim, not round trips.
Nice, careful PR overall — the tombstone and lease reasoning in the comments made this much easier to review.
The per-row claim orders by next_attempt_at across all three states.
Migration 230's index leads with state, so it cannot serve that ordering:
under backlog the planner falls back to a seq scan plus an external merge
sort, and FOR UPDATE blocks the bounded top-N optimization, so every claim in
a sweep pays the full sort. That is exactly backwards — the amplification is
worst when object storage is degraded and the ledger has backed up, which is
the case the reconciler exists to drain.
Measured on a freshly migrated database (EXPLAIN ANALYZE after VACUUM
ANALYZE, the claim statement as sqlc emits it, wrapped in BEGIN/ROLLBACK):
100k rows all due, before: Seq Scan (rows=100000) + external merge 4704kB
70.5 / 70.8 / 73.7 ms, up to 50x per sweep
100k rows all due, after: Index Scan using idx_..._due (rows=1), no sort
0.11 / 0.22 / 0.29 ms
steady state (100 due of 100k), after: same index scan, 0.17 ms
Numbered 232, not 231: main took 231 for the agent-task-queue index after
this branch was cut, and two migrations sharing a version would let the
runner skip the second as already applied.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
CancelledSweepIsQuiet only covered cancellation at the claim boundary. A sweep spends its time in object-storage deletes, so the likely place for shutdown to land is inside settle — and there release() logged "settle failed; backing off", then wrote the backoff with the already-cancelled context and logged "release failed" too: two warnings per in-flight row on every restart, for a write that never had a chance to land. The three ledger writes now return early when ctx is already done. Nothing is lost: the row keeps its lease and is reclaimed after expiry, exactly like a worker that crashed mid-delete, and the tombstone re-delete is idempotent. Test pins the delete path, and the cancelled-sweep test now asserts on warn and above rather than total log silence, so debug tracing added to RunOnce later cannot turn it red. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
With the batch gone, a sweep is no longer "at most one attempt per row": a row released early with a 1-minute backoff can be re-claimed inside a long sweep, and the loop counter increments on failed settles too. Total work is still capped at 50 and equivalent to what the next sweep would have done, but "how many rows one sweep settles" no longer describes it. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
e8f6746 to
04e3e19
Compare
|
Thanks — the backlog measurement reproduced here, and I went with option 1. Pushed as three commits on top of The blocking issue: index the ordering
It is numbered 232, not 231: main took 231 for the agent-task-queue index after this branch was cut. Two migrations sharing a version would be worse than a slow query — the runner keys Same setup as yours — freshly migrated DB, 100k rows, Absolute numbers run ~4x yours (Postgres in Docker here), but the shape matches: the sort and the 4.7 MB of temp files are gone, and the steady-state case does not lose anything to the change — it lands on the same ordered index scan rather than falling back to the old bitmap path. I also measured a third regime neither of us had covered, because it is the one where an index on Identical plan, and this one costs a single scan per sweep rather than 50, since the loop breaks on One open question the change surfaces but does not settle: with the ordering served by 232, migration 230's Nits
Checks
Because the renumber is only safe if the merged set is, I also ran migrations on a fresh database with main's 231 checked out alongside this branch's 232: Both indexes exist afterwards, and the prefix lint passes against that combined set — which is the check that would have caught the collision in the first place. |
Bohan-J
left a comment
There was a problem hiding this comment.
Thanks for the thorough follow-up — all three points are addressed, and the index commit in particular is exactly the right fix with a comment that explains why migration 230 couldn't serve the ordering. Re-reviewed at 04e3e197e, merged into current main locally.
The blocking issue is gone. Re-ran the same measurement on a freshly migrated database with 100k ledger rows:
| Regime | Before | After |
|---|---|---|
| Backlog (100k due) | Seq Scan + external merge Disk: 4696kB, 16.7 ms |
Index Scan using idx_channel_media_pending_object_due, 0.020 ms |
| Steady state (100 due of 100k) | Bitmap scan, 0.07 ms | Index Scan, 0.020 ms |
So the ~50x per-sweep amplification is eliminated rather than just reduced — a full sweep's claim cost at backlog goes from roughly 835 ms and ~235 MB of temp file writes down to about 1 ms with no temp files. I also checked the case I was worried might regress — a large ledger where nothing is due — and it is unaffected: one ~8 ms scan that returns empty and breaks the loop, same as the old batch claim paid there.
On the migration: 232 doesn't collide (main is at 231), CREATE INDEX CONCURRENTLY / DROP INDEX CONCURRENTLY each in their own single-statement file per the repo convention, no foreign keys or cascades. I ran the full down/up chain and both indexes come back indisvalid/indisready.
On the cancellation fix: the ctx.Err() guards in release, tombstoneRow and clearRow are the right shape — leaving the row claimed and letting lease expiry reclaim it is the same path a crashed worker takes, so nothing special-cases shutdown. TestChannelMediaReconciler_CancelledSettleIsQuiet is a real pin: run against the previous implementation it fails with exactly the two warnings I described (settle failed; backing off then release failed). Dropping the test logger to LevelWarn was the better call over asserting total silence — it guards what actually matters without breaking on future tracing.
Also verified on the merge state: all reconciler tests plus the cmd/server invariant test pass, including under -race; internal/migrations and cmd/migrate tests pass; go vet and gofmt clean on the touched files; sqlc regeneration produces no diff. CI is 8/8 green.
One non-blocking follow-up, no need to hold the merge for it: settleDeletedObject still increments DeleteFailures before calling release, so a shutdown that cancels an in-flight DELETE counts as a delete failure in the metrics even though release now correctly treats it as shutdown and records no backoff. It is at most one per replica per shutdown and touches nothing but the counter, so it is purely an observability wrinkle — worth tightening whenever this code is next open.
Merging. Thanks for the care you put into the comments here; the lease and tombstone reasoning made this a genuinely easy PR to review.
Follow-up to #5580, taking the non-blocking point from that review: the reconciler claimed a batch of rows under one lease and processed them serially, so a tail row could expire and be reclaimed before its own DELETE was ever tried, inflating
attempt/backoff for work that never happened — and the backoff it produced then delayed the row's first real attempt.What changes
ClaimChannelMediaPendingObjectsForReconcile(:many,LIMIT @batch_limit) becomesClaimNextChannelMediaPendingObjectForReconcile(:one,LIMIT 1).RunOnceloops claim → settle → claim, up to the same per-sweep limit of 50. A claim is now always taken immediately before the work it authorizes.RenewChannelMediaPendingObjectLease) is removed. It existed only because a single lease had to span a whole batch; with on-demand claiming the lease covers one row's settle (delete timeout 30s ≪ lease 2m), and every settle write is already lease-token guarded, so a row reclaimed after an expiry ignores the previous owner's writes rather than being corrupted by them.What does not change
Due-ness (settle delay for
pending, lease expiry fordeleting,next_attempt_atfor tombstones),FOR UPDATE SKIP LOCKED, the workspace predicate on every settle write, the reference check on every pass including tombstones, the tombstone re-delete schedule, the backoff curve, and the metrics. Deadlines are still computed by Postgres fromnow().Cost
N round-trips per sweep instead of one — at the 50-row cap that is 50 short transactions per minute, against a sweep that already does one object-storage DELETE per row.
Test
TestChannelMediaReconciler_SkipsRowReclaimedMidBatchis replaced byTestChannelMediaReconciler_TailRowIsUnclaimedUntilItsTurn, which pins the invariant the old test was working around: while the first row's DELETE runs, the next row is stillpendingwithattempt = 0, and both rows are still settled by the same sweep withattempt = 1each. Run against the batch-claiming implementation it fails withtail row during the first delete = ("deleting", attempt=1).Validation: full server suite on a freshly migrated database,
-raceoninternal/service,go vet ./....