fix(orchestrator): never return an already-expired lock lease - #22
Open
waldemort-auto[bot] wants to merge 1 commit into
Open
fix(orchestrator): never return an already-expired lock lease#22waldemort-auto[bot] wants to merge 1 commit into
waldemort-auto[bot] wants to merge 1 commit into
Conversation
fetch_orchestration_item could return an orchestration item whose lock
lease had already expired at the moment it was returned. Every ack
against that lease failed with 'Invalid lock token', so the turn's work
was discarded, the message became visible again immediately, and the
cycle repeated indefinitely -- including the max_attempts poison path,
which commits through the same ack and so could never terminate it.
Migration 0024 rebuilds the procedure on top of 0019:
- pg_try_advisory_xact_lock replaces the blocking pg_advisory_xact_lock.
Candidate selection is deterministic (ORDER BY visible_at, id LIMIT 1),
so every dispatcher converged on the same key and queued behind it.
Contended instances are now skipped and excluded from re-selection
within the call. Same-instance mutual exclusion -- the deadlock guard
-- is preserved; only the waiting is removed.
- The lease is derived from an effective clock, v_now_ms, equal to the
caller's p_now_ms advanced by time actually elapsed inside the call.
Only the elapsed duration comes from the server clock, never an
absolute server timestamp, so the Rust-supplied epoch established by
0006/0012 remains the single time reference.
- The advisory key is scoped to '<schema>.<instance_id>'. PostgreSQL
advisory locks share one database-wide space, so the previous unscoped
key made two duroxide schemas in the same database serialize against
each other on identical instance ids. Blocking acquisition hid this;
non-blocking acquisition would surface it as a spurious skip.
- The retry loop is bounded; exhausting it returns no item, which the
dispatcher already treats as 'nothing available'.
Signature, return shape, and all downstream behavior are unchanged.
Measured on PostgreSQL 17.11 and 18.6 (contended fetch, 1s lock timeout,
3s competing hold):
before: blocked 2.61s, lease returned 1658ms already expired
after: blocked 0.05s, contended instance skipped, live lease
tests/expired_lease_regression_test.rs fails without this migration
('the advisory lock is convoying') and passes with it. Full suite:
353 passed / 0 failed on both 17.11 and 18.6.
Fixes #21
Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Contributor
|
@waldemort-auto[bot] please read the following Contributor License Agreement(CLA). If you agree with the CLA, please reply with the following information.
Contributor License AgreementContribution License AgreementThis Contribution License Agreement (“Agreement”) is agreed to by the party signing below (“You”),
|
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.
Fixes #21.
Problem
fetch_orchestration_itemcould return an orchestration item whose lock lease had already expired at the moment it was returned. Every ack against that lease failed withInvalid lock token, so the turn's work was discarded, the message became visible again immediately, and the cycle repeated indefinitely.The
max_attemptspoison path could not stop it either: poison marking, backoff, and the attempt-count increment all commit through an ack keyed on that same dead lease, so all three failed together. The message was never poisoned, never backed off, and never abandoned with a delay — its retry interval collapsed to the lock lease, the most aggressive retry the system can produce, applied to the message that most needed to be left alone.Two defects combined to produce this, both in the stored procedure:
Deterministic candidate selection followed by a blocking advisory lock.
ORDER BY q.visible_at, q.id LIMIT 1is deterministic, so every dispatcher in the fleet independently computed the same candidate and then blocked on the same advisory key. TheFOR UPDATE ... SKIP LOCKEDre-verification could not prevent this — the blocking had already happened.The lease was computed from a pre-wait timestamp.
p_now_msis minted by the Rust caller before the call and was never refreshed. When the advisory wait exceededp_lock_timeout_ms,locked_untilwas written already in the past. The same stale value was also the liveness reference for candidate visibility and for stealing expired locks, so a long-running call became progressively less able to make progress.These compound: a trapped message never commits, so its
visible_atnever advances, so it remains permanently the oldest row and is selected first by every dispatcher on every poll.Changes
Migration
0024rebuildsfetch_orchestration_itemon top of the0019definition. Signature, return shape, and all downstream behavior (message batching, history/metadata fallback, KV snapshot) are unchanged.pg_try_advisory_xact_lockreplacespg_advisory_xact_lockv_now_ms = p_now_ms + elapsed-inside-callp_lock_timeout_msin the future relative to when it is actually written.<schema>.<instance_id>On the clock
Migrations
0006and0012deliberately moved these procedures onto a Rust-supplied timestamp to avoid app/database clock skew. This change does not walk that back. Only an elapsed duration is taken from the server clock:No absolute server timestamp is ever used, so the caller's epoch remains the single time reference and no cross-clock skew is introduced against
visible_at/locked_untilvalues written elsewhere.Second defect found while fixing the first
PostgreSQL advisory locks live in a single database-wide space, but the key was
hashtext()of the instance id alone. Two duroxide schemas in the same database therefore serialized against each other whenever they happened to use the same instance id — entirely unrelated work contending on one key.While acquisition blocked, this was invisible: the loser waited, then proceeded. With non-blocking acquisition it would surface as a spurious skip. It was caught here because
duroxide's ownprovider_validationsuite (atomicity_tests::test_concurrent_ack_prevention) began failing under parallel test execution, where each test uses its own schema but shares one database. It passes in isolation and passes now that the key is scoped.Rolling-upgrade note: during a mixed deployment, nodes on the previous migration hash the unscoped key while upgraded nodes hash the scoped one, so the advisory layer does not mutually exclude across that boundary for the duration of the rollout. Correctness does not depend on it —
instance_locksplusFOR UPDATE ... SKIP LOCKEDstill serialize the claim — and the provider already retries deadlock (40P01) errors, so the window degrades to the pre-advisory-lock behavior rather than to incorrect results.Verification
Measured against disposable PostgreSQL 17.11 and 18.6 (the versions the downstream consumer supports; CI itself pins
postgres:15). Contended fetch = a competing session holding the instance advisory lock for 3s while the fetch runs with a 1s lock timeout.Full suite, both versions: 353 passed / 0 failed / 9 ignored.
cargo fmt --all --checkclean.The test proves the bug
tests/expired_lease_regression_test.rsfails with migration0024removed, on both 17.11 and 18.6:and passes with it. The competing session holds both the legacy unscoped key and the new scoped key, so the test reproduces contention against the procedure either side of this migration rather than silently failing to contend.
Notes for reviewers
p_now_msalso makes the row invisible viavisible_at <= TO_TIMESTAMP(p_now_ms / 1000.0), so the function returns 0 rows. The real mechanism is a genuine advisory-lock wait with a fresh caller clock. I will correct the issue text.0022is intentionally skipped — reserved by the concurrentworker_queuedequeue PR (perf(worker_queue): partial index + two-phase fetch_work_item dequeue #18). This migration is independent and applies cleanly whether or not0022is present.include_dir!has norerun-if-changed. Adding a migration file alone does not rebuild the crate, and CI restores a cargo build cache keyed onCargo.lock, so a migration-only PR can silently test a stale migration set. This bit during development — the suite reported a failure against a binary that still had the old procedure embedded. Worth considering abuild.rsemittingcargo:rerun-if-changed=migrations.cargo clippyfails on pre-existing code (src/provider.rs:2492,if_same_then_else) on unmodifiedmain. CI does not run clippy; left alone here rather than mixing an unrelated change into this PR.