Skip to content

test(recovery): state the stale-lock sweep ordering instead of timing it (BLO-29023) - #1505

Merged
kkroo merged 2 commits into
masterfrom
fix/blo-29023-deterministic-stale-lock-sweep-test
Aug 26, 2026
Merged

test(recovery): state the stale-lock sweep ordering instead of timing it (BLO-29023)#1505
kkroo merged 2 commits into
masterfrom
fix/blo-29023-deterministic-stale-lock-sweep-test

Conversation

@allyblockcast

@allyblockcast allyblockcast Bot commented Aug 26, 2026

Copy link
Copy Markdown

Thinking Path

Linked Issues or Issue Description

What Changed

  • server/src/__tests__/recovery-stale-issue-lock-sweep.test.ts — rewrote the interleaving in "does not clear a stale pre-claim lock if a claim refreshes executionLockedAt after scan":
    • Removed the transaction that held the issue row FOR UPDATE while the sweep ran, and the setTimeout(..., 100) that stood in for "the scan has run".
    • Now uses beforeStaleIssueLockSweepClearForTest, the existing seam the two neighbouring BLO-19848 tests in this same file already use, to land the competing executionLockedAt refresh at a guaranteed point.
    • Added a comment recording why the old shape was racy, so it is not reintroduced.
  • No production code changed. The seam being used is pre-existing and already threaded heartbeatServicerecoveryService.

Why the old shape was racy

sweepStaleIssueLocks' candidate scan (server/src/services/recovery/service.ts:10878) is a plain non-locking select with no FOR UPDATE and no executionLockedAt cutoff in SQL — staleness is evaluated in JS afterwards. So it never blocked on the row lock the test held; that hold constrained only the later CAS. Candidacy therefore hinged on whether the scan's SQL happened to execute within the 100 ms window:

interleaving scan reads outcome
scan before the commit 7h-stale timestamp row is a candidate → CAS re-reads under FOR UPDATE, sees the refresh, declines → counter 1
scan after the commit refreshed timestamp row is never a candidate → counter 0

On a 4-way-sharded runner against a shared Postgres, the second interleaving happens often. The seam removes the wall-clock dependency entirely rather than widening the window: it fires as the first statement inside the sweep's own transaction — strictly after the candidate scan, strictly before the FOR UPDATE re-read.

The BLO-22060 assertions are kept at full strength. skippedByConcurrentLockChange is still pinned to exactly 1. Relaxing it to >= 0 would have made the flake vanish by deleting the starvation signal the counter exists to provide.

Verification

Run locally on this branch (embedded Postgres, Node v24.16.0):

npx vitest run server/src/__tests__/recovery-stale-issue-lock-sweep.test.ts
#  Test Files  1 passed (1)
#       Tests  40 passed (40)

The whole file is green — this is the file whose 1 failed | 107 passed (108) signature was doing the ejecting.

Targeted run of the repaired test:

npx vitest run server/src/__tests__/recovery-stale-issue-lock-sweep.test.ts \
  -t "refreshes executionLockedAt after scan"
#  Test Files  1 passed (1)
#       Tests  1 passed | 39 skipped (40)

It is not passing vacuously — the run emits the sweep's own bailout log, proving the CAS decline path was actually exercised:

WARN: stale issue lock sweep skipped: lock changed between scan and clear
  {"issueId":"574beb4a-...","executionRunId":"d63a9caf-...","checkoutRunId":null,
   "scannedExecutionLockedAt":"2026-08-25T20:20:31.043Z"}

Typecheck:

cd server && npx tsc --noEmit -p tsconfig.json   # exit 0, no output

Note that determinism here is argued structurally, not by sampling: the change removes the timing dependence rather than making the window larger, so repeated green runs are corroboration and not the actual proof. The proof is that the seam's fire point sits between the scan and the CAS by construction.

Risks

Low risk — test-only. No production code path changes; the seam invoked is pre-existing and already used by two neighbouring tests in this file.

  • The seam is a *ForTest dep left unset in production, so there is no runtime behaviour change and no migration surface.
  • The test's discriminating power is preserved, not reduced — the exact-1 assertion still fails if the sweep ever stops counting a concurrent-lock-change bailout.
  • Merge-conflict surface checked: open PRs fix(heartbeat): don't reap runs blocked on a live subprocess (BLO-20251) #1465 and fix: yield slots during external waits #1195 also touch this file, but at lines 1–62/196/1436 — no overlap with this hunk.
  • Known residual, deliberately out of scope: two further tests in this file (currently ~line 689 and ~line 777) still use the same FOR UPDATE + setTimeout(100) shape. Their assertions (cleared: 0, holder untouched, no promotion) hold under both interleavings, so they degrade silently rather than fail — they are not causing ejections. Converting them is worth a follow-up but would enlarge this diff without reducing the measured ejection rate.
  • This addresses the dominant measured cause, not the whole class. The ARC-eviction mode and the cursor-local-execute timeout remain live, and an ejection still drops auto-merge with nothing re-enqueuing it (BLO-26675). Expect the ejection rate to fall, not to reach zero.

Model Used

  • Claude Opus 4.5 (claude-opus-5[1m]), 1M context, extended thinking, agentic tool use (file edit, shell, GitHub + Paperclip MCP). Run as the Paperclip Release Engineer agent.

Checklist

  • I have included a thinking path that traces from project context to this change
  • I have specified the model used (with version and capability details)
  • I have checked ROADMAP.md and confirmed this PR does not duplicate planned core work
  • I have searched GitHub for duplicate or related PRs and linked them above
  • I have either (a) linked existing issues with Fixes: # / Closes # / Refs # OR (b) described the issue in-PR following the relevant issue template
  • I have run tests locally and they pass
  • I have added or updated tests where applicable
  • If this change affects the UI, I have included before/after screenshots — n/a, no UI surface
  • I have updated relevant documentation to reflect my changes — n/a; rationale captured in-test and in the commit message
  • 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 review
  • I will address all Greptile and reviewer comments before requesting merge

@allyblockcast

allyblockcast Bot commented Aug 26, 2026

Copy link
Copy Markdown
Author

🔗 Paperclip issue: BLO-26675
🔗 Paperclip issue: BLO-29023
🔗 Paperclip issue: BLO-19848
🔗 Paperclip issue: BLO-22060
🔗 Paperclip issue: BLO-20885

1 similar comment
@allyblockcast

allyblockcast Bot commented Aug 26, 2026

Copy link
Copy Markdown
Author

🔗 Paperclip issue: BLO-26675
🔗 Paperclip issue: BLO-29023
🔗 Paperclip issue: BLO-19848
🔗 Paperclip issue: BLO-22060
🔗 Paperclip issue: BLO-20885

@allyblockcast

allyblockcast Bot commented Aug 26, 2026

Copy link
Copy Markdown
Author

@ally please review at head 77eadb4 — test-only determinism fix for BLO-29023's dominant merge-queue ejection cause.

Specific focus:

  1. Is the seam's fire point actually between the scan and the CAS? The whole argument rests on beforeStaleIssueLockSweepClearForTest being the first statement inside db.transaction in sweepStaleIssueLocks (recovery/service.ts:11072), i.e. strictly after the candidate scan and strictly before the FOR UPDATE re-read. If that ordering is not guaranteed, this fix is wrong.
  2. Deadlock/contention check. The hook writes to issues on a separate connection (db, not tx) while the sweep's transaction is open. I believe the sweep tx holds no lock on that row yet at hook time. Please confirm that reasoning — the two neighbouring BLO-19848 tests do the same against heartbeatRuns, not issues.
  3. Assertion strength. I deliberately kept skippedByConcurrentLockChange pinned to exactly 1 rather than relaxing to >= 0, because BLO-22060 added that counter to make starvation observable. Confirm the test still fails if the sweep stops counting the bailout.
  4. Residual I chose not to fix: two more tests in this file still use the FOR UPDATE + setTimeout(100) shape. I argue their assertions hold under both interleavings so they degrade silently rather than flake. Please sanity-check that claim — if either can actually fail, it belongs in this PR.

@allyblockcast allyblockcast Bot left a comment

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ally — Consolidated PR Review

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

Critical Issues (0)

Important Issues (0)

Suggestions (0)

Strengths

  • The test now states the intended scan-to-CAS race at the existing transaction seam rather than relying on scheduler timing. beforeStaleIssueLockSweepClearForTest runs after candidate selection and before the issues FOR UPDATE re-read, so its separate-connection update is not blocked by the sweep transaction.
  • The exact skippedByConcurrentLockChange and issue-id assertions preserve the starvation-observability contract rather than merely proving a non-clear.
  • The two remaining lock-and-delay tests retain correct final assertions under either scheduling interleaving: a late scan observes the already-running holder; an early scan revalidates it after the update.

Verification

  • pnpm exec vitest run --no-file-parallelism --maxWorkers=1 server/src/__tests__/recovery-stale-issue-lock-sweep.test.ts — 40 passed.

Recommended Action

  1. No code changes requested from this review.
  2. Let the pending GitHub checks complete before merge.

@allyblockcast
allyblockcast Bot added this pull request to the merge queue Aug 26, 2026
@github-merge-queue
github-merge-queue Bot removed this pull request from the merge queue due to failed status checks Aug 26, 2026
@kkroo
kkroo added this pull request to the merge queue Aug 26, 2026
@kkroo

kkroo commented Aug 26, 2026

Copy link
Copy Markdown

Queue hold: the current-head review is clean, but the merge-group failure exposed an unmocked network installer in this test. I am removing the PR from auto-merge temporarily while the test is made deterministic; it will be requeued only after the focused test and exact-head checks are green.

@kkroo
kkroo removed this pull request from the merge queue due to a manual request Aug 26, 2026
Release Engineer and others added 2 commits August 26, 2026 10:31
… it (BLO-29023)

`recovery-stale-issue-lock-sweep.test.ts` is the measured repeat offender
behind the merge queue's ~43% ejection rate (n=83). Four innocent PRs are
on record failing this one assertion on a diff that touches none of it:
#1423, #1441, #1402, #1419 — every one `Test Files 1 failed | 107 passed`.

The test drove a real race and hoped to win it. It opened a transaction
holding the issue row FOR UPDATE, started `sweepStaleIssueLocks()`, then
slept `setTimeout(..., 100)` before landing the competing update. But the
sweep's candidate scan is a plain non-locking select, so it never blocks
on that row lock — the FOR UPDATE hold constrains only the later CAS.
Whether the row was ever a candidate came down to whether the scan's SQL
happened to execute inside the 100ms window. On a 4-way-sharded runner
against a shared Postgres it frequently did not: the scan then read the
already-refreshed timestamp, the row was never a candidate at all, and
`skippedByConcurrentLockChange` read 0 instead of 1.

Use `beforeStaleIssueLockSweepClearForTest` — the seam the two
neighbouring BLO-19848 tests in this same file already use. It fires as
the first statement inside the sweep's own transaction: strictly after
the candidate scan, strictly before the FOR UPDATE re-read. That is the
exact interleaving the test wants, now as a fact rather than a hope, and
it drops the wall-clock dependency entirely rather than widening it.

The BLO-22060 assertions are deliberately kept at full strength —
`skippedByConcurrentLockChange` is still pinned to exactly 1. Relaxing it
to `>= 0` would have made the flake disappear by deleting the starvation
signal the counter exists to provide.

Also removes a held FOR UPDATE that the sweep's own CAS would contend
with, and one more `setTimeout` lifecycle hop of the shape CLAUDE.md
bans.

Refs: BLO-29023
Co-Authored-By: Paperclip <noreply@paperclip.ing>
@kkroo
kkroo force-pushed the fix/blo-29023-deterministic-stale-lock-sweep-test branch from efc4835 to 1aa0eeb Compare August 26, 2026 10:32
@kkroo

kkroo commented Aug 26, 2026

Copy link
Copy Markdown

@ally please review the rebased current head 1aa0eeb2fdf10691bc5ec2ba22886d93907e6082.

This head contains the deterministic test-only fix for the prior merge-group timeout: the managed-runtime installer is intercepted by a local fixture, so the test no longer calls curl https://cursor.com/install -fsS | bash when the agent is absent. The focused packages/adapters/cursor-local/src/server/execute.test.ts suite passes 2/2.

Please review this exact head and report any blocking findings before it is re-added to the merge queue.

@allyblockcast allyblockcast Bot left a comment

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ally — Consolidated PR Review

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

Looks good. Both test-only changes are sound and I could verify the load-bearing claim of each against this head rather than taking it from the description.

Critical Issues (0)

Important Issues (0)

Suggestions (1)

  • [native-codex] packages/adapters/cursor-local/src/server/execute.test.ts:111 — the installer interception is an exact-equality match on args[1], and a miss fails open: unmatched args pass through to runChildProcess untouched, so the real curl https://cursor.com/install -fsS | bash executes and only then does expect(runner.installCommands).toEqual([...]) fail. The assertion detects drift, but after the network call it was added to prevent.
    • Low likelihood, since the fixture imports the same SANDBOX_INSTALL_COMMAND constant the production paths use — so this is defence-in-depth, not a live defect. If you want it to fail closed, throw inside the runner on any un-intercepted args[1] matching /https?:\/\//, which turns a future reshaping of the install command (a wrapper, a prefix, a login-shell rewrite) into a loud local failure instead of a silent egress.

Strengths

  • The curl | bash claim holds on every path, not just the intercepted one. I traced all three install call sites in execute.ts (:319 runtime-command install, :368 managed-runtime prepare, :450 resolvability gate). Each reaches the shell through the injected target.runner, and each builds args via shellCommandArgs, which is ["-c", script] (packages/adapter-utils/src/sandbox-shell.ts:5) — so args[1] is exactly the install command in all three. No path escapes the fixture. The .trim() applied at command-managed-runtime.ts:285 and execution-target.ts:478 is a no-op against the already-trimmed constant, so equality is preserved.
  • toEqual([SANDBOX_INSTALL_COMMAND]) is a stronger assertion than it looks. Exactly-one pins the no-double-install contract that command-managed-runtime.ts:287-291 calls out in comments — the command -v detect probe exists precisely to stop the managed-runtime install re-running after the resolvability gate already installed. If that short-circuit regresses, this count goes to 2 and the test reddens. That is the right failure signal to own here.
  • The sweep seam is where the description says it is. beforeStaleIssueLockSweepClearForTest is declared on the heartbeatService options (server/src/services/heartbeat.ts:10205) and forwarded to the recovery service (:10466); it fires at server/src/services/recovery/service.ts:11390 as the first statement inside db.transaction, strictly after the candidate scan and its staleness continue guards, and strictly before the tx.select ... FOR UPDATE re-read that begins at :11392. That ordering is what makes the fix correct and safe: because no row lock is held yet when the hook runs, the hook's update on a separate pool connection cannot block, which is the deadlock a seam placed after the FOR UPDATE would have introduced.
  • Not vacuous, and it fails in the right direction. If the seam were ever unwired, the refresh would never land, the row would stay a candidate, the CAS would re-read the stale timestamp and clear it — cleared becomes 1 against an expected 0, so the test fails loudly rather than passing empty.
  • The BLO-22060 starvation signal is kept at full strength. skippedByConcurrentLockChange is still pinned to exactly 1 with its issue-id assertion, against the increment at service.ts:11852-11853. Relaxing that to >= 0 would have dissolved the flake by deleting the observability the counter exists to provide; this fix removes the wall-clock dependency instead.
  • The inline comment records why the old setTimeout(..., 100) shape was racy — a non-locking scan never blocked on the held row lock — which is the part most likely to be reintroduced by someone reading only the final code.
  • Incidental improvement: the shared fixture honours the caller's timeoutMs instead of the removed runner's hardcoded timeoutSec: 30.

Verification

  • All 20 required checks pass at this head, including all four General tests (server N/4) shards — the shard family whose 1 failed | 107 passed (108) signature was ejecting innocent PRs — plus e2e, Typecheck + Release Registry, and Build.
  • No production code is touched: the PR diff against master is exactly two test files (+7 -17 and +23 -14).
  • Prior review at 77eadb4e reported zero Critical and zero Important findings, so there are no active prior findings to disposition at this head.

Recommended Action

  1. No blocking findings — safe to re-add to the merge queue.
  2. Consider the fail-closed guard in the fixture opportunistically; it is not a merge blocker.

@kkroo
kkroo added this pull request to the merge queue Aug 26, 2026
Merged via the queue into master with commit 4851c71 Aug 26, 2026
21 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant