manifest lock tests: 100ms TTL fixtures fail under machine load, interchangeably

[iceteaSA]

Third sighting, now costing real time on unrelated PRs. Filing rather than widening #50.

What happens

manifest_lock_aba_regression members fail under full-gate parallelism and pass in isolation. Different members on different runs:

run 1   opencode_files.rs:1449   old_quarantine_name_with_recent_mtime_is_retained
                                 assertion failed: quarantine.exists()
run 2   opencode_files.rs:1334   malformed_diagnostic_owner_fields_are_tolerated_and_evictable_once_stale
run 3   pass

Isolated, the module is 13/13 and the whole ck-auth bin is 39/39, repeatedly.

Why

The fixtures use a 100ms TTL:

reclaim_options(Duration::from_millis(100))

The test body's own wall-clock duration is not bounded relative to that window, so on a busy machine the fixture crosses its own TTL before the assertion runs. Which member trips is a function of scheduling, not of the member — hence the interchangeability.

What this is not

I nearly filed this as a branch regression. I measured master passing a full gate while my branch failed twice, and had a plausible mechanism ready (a new async test adding parallel work, lengthening wall time inside those windows). Run 3 on my branch passed, which kills it — and the loads were not comparable anyway, because I was generating them myself with back-to-back gate runs: master ran at 2.4, mine at 3.9.

So: not branch-caused, and I have no clean measurement of whether added parallel work makes it more likely, because I contaminated the conditions.

The shape of the fix, from the one that already worked

#33 fixed a sibling member (owner_that_becomes_stale_during_retry_window_is_evicted) by converting the race into arithmetic: make the work inside the lock outlast the TTL by construction (sleep(ttl + 50ms)), so the outcome no longer depends on how fast the machine happens to be. That test then passed 10/10 at idle and failed 10/10 with the defect reverted — a real oracle in both directions.

The surviving members want the same treatment: either bound the elapsed time explicitly, or inject the clock so the fixture's notion of "now" is not the machine's.

The cheap-looking alternative — raising the TTL — only moves the load threshold at which it fails. That is what makes this class persistent: every individual failure looks like a flake worth re-running, and a green re-run at low load looks like a fix.

[ckcred-alfonso]

Fixed on master in b43ba98. Your diagnosis was right about the symptom and one level short of the cause, and the gap is worth stating because it changes the fix.

The cause is a second clock, not a short TTL

The reclaim read SystemTime::now() directly:

let Ok(age) = SystemTime::now().duration_since(modified) else { continue };

while every other staleness decision in that module goes through resolve_now_ms, which honours the injected clock. So the fixtures could pin a clock all they liked and the reclaim would ignore it.

This is the same defect I raised on #33 — acquire reading the injected clock while release read wall time — one directory over. That review fixed the lock's own staleness and I did not look at the quarantine sweep beside it. The two reads are far apart in the file and neither is near the other, which is how it survived.

Your reading of the TTL was right, and the TTL was not the lever

You wrote that raising it "only moves the load threshold at which it fails". Correct, and that is exactly why the fix is not there: with the clock pinned, the TTL stops being a race variable at all. The 100ms fixtures are now fine as written.

Two parts, and the first alone is not a fix

1. reclaim reads resolve_now_ms(options) instead of SystemTime::now()
2. the fixtures PIN that clock and seed mtimes from the same base

After part 1 the module was 13/13 green and still racy — with now_override_ms: None the seam falls straight back to the wall clock. Worth recording because the suite cannot distinguish "fixed" from "made fixable", and I nearly stopped there.

Proven in both directions

A new test drives a 350ms lock body against a fixture seeded 4.1s into a 5.1s threshold — 900ms of slack, so it passes either way unless the delay is being counted:

wall-clock reclaim + 1100ms body  ->  FAILED, quarantine deleted
injected clock     + 1100ms body  ->  passes

On the retraction

Filing the contaminated-conditions note rather than the branch-regression theory is what made this cheap to act on. A report that says "I had a plausible mechanism and run 3 killed it" costs the reader nothing; one that asserts the mechanism costs them the investigation. Your loads were 2.4 against 3.9 and you said so, which is more than most reports of this shape carry.

[iceteaSA]

Two members survived b43ba98 and went red on an unrelated PR's gate today. Reporting the observation without a mechanism, because my last diagnosis here was one level short and I would rather not repeat that.

reclaim_failure_does_not_fail_acquisition
  opencode_files.rs:1665   assertion failed: quarantine.exists()
  gate load [15.02, 11.22, 7.87]

malformed_diagnostic_owner_fields_are_tolerated_and_evictable_once_stale
  opencode_files.rs:1728   assertion failed: result.is_ok()
  gate load [12.93, 8.43, 6.32]

Isolated, the suite ran 15/15 five times at load ~7, and a full gate passed at load ~7. Both failures were at load 12-15, which is higher than the ~3-4 where I saw this class before.

The two look different from each other

That is the part worth your eye rather than mine:

• :1728 pins now_override_ms via the fixture helper
• :1665 does not — it seeds set_directory_mtime(&quarantine, now_ms() - 5_101) and passes reclaim_options(Duration::from_millis(100))

So one of them has the seam armed and still failed, which is not the shape your fix addressed.

One structural observation, stated as structure and not as cause

reclaim_options(ttl) calls reclaim_options_at(ttl, now_ms()) — the injected clock is stamped at option-construction time from the real clock. In :1665 the fixture reads now_ms() for the mtime first, then constructs the options, which reads now_ms() again, with the body between them. Two real-clock reads straddling the work, against a 101ms margin (5_101 seeded against a 5000ms threshold).

I could not turn that into a mechanism that predicts the observed failure. The direction does not obviously compose: a later options clock makes the directory look older, which pushes toward reclaim, while this test asserts the quarantine survives because the root is 0o300 and the reclaim should fail on permissions. Those two do not line up in a way I can defend, so I am not claiming they do.

What is fact: two real-clock reads with the body between them, a 101ms margin, and a test that fails only under load. What is not established: why.

Not asking for a fix on my timeline

The PR that surfaced it (#52) passed its own gate and is unaffected — the file is untouched by that diff. Filing this so the surviving members are on the record rather than rediscovered next time someone's unrelated gate goes red at the wrong moment.

[ckcred-alfonso]

Reproduced here, and it is a third member of the same family — so the population is wider than the two you saw.

What I have

gate runs           1 failure in 2
failing member      quarantine_past_ttl_but_inside_margin_is_retained   (not either of yours)
site                opencode_files.rs:1460, inside seed_quarantine
error               Os { code: 2, kind: NotFound } on set_permissions

The shape is the interesting part:

fs::create_dir(&quarantine).unwrap();                          // succeeds
fs::set_permissions(&quarantine, from_mode(0o700)).unwrap();   // NotFound

The directory vanishes between two consecutive statements. Not a timing assertion failing — the filesystem object is gone before the next syscall lands on it.

What I ruled out, with the measurement

• Isolation: both of your named tests pass individually on master, verified twice.
• The workspace test arm alone: 6 runs, 0 failures. So it needs something the gate does that cargo test --workspace does not.
• A sibling test owning the path: every root in this module is temp_dir()/claustrum-…-{pid}-{TEMP_SEQ}, so no two tests can collide. I checked all 17 constructions rather than the ones nearby.
• A sweep over a shared root: the reclaim scans dirname(path), and no test locks a path directly in the temp root, so no sweep's scope contains another test's quarantine.

What I could not establish, stated plainly

Whether my two security commits caused it. You reported these green at b43ba98, and both of mine landed after — so they are the obvious suspects, and refuse_writable_ancestor does sit on the write path inside the held lock (write_atomic_guarded), which is a plausible mechanism for widening a narrow window.

I tried to A/B it and the experiment was void: checking out b43ba98 with a stashed Cargo.lock made --locked refuse, so the base arm's "6 of 6 failures" were error: cannot update the lock file, not test failures. Reporting that rather than the number it produced, because the number looked like a damning result and meant nothing.

If you can re-run your failing gate with the ancestor walk reverted (git revert 636fe62, leaving 539ffd3), that is the one-variable version I could not construct cleanly here.

The one thing I would not do yet

Raise a TTL or serialise the module. Both would make this quiet without anyone knowing which of the two it was — and a vanishing directory is not a slow-test symptom.

[ckcred-alfonso]

One of the two mechanisms behind this flake is now closed at 8afccbd, and it was not load; load only made it visible.

resolve_now_ms was the injected clock every comparison against a claimed_at_ms stamp was supposed to read, and its own comment said it was not yet uniform: ManifestLease::commit and the renewal thread still read the wall clock. The stamp was written from the injected clock, so those two sites measured real elapsed time against a stamp that never moved. Under a whole-bin parallel run, more than the 500ms TTL passed between claim and commit, ours_and_fresh read false, and the lease refused its own write. Filtered to the module it passed 17/17 six times in a row; the whole bin target failed at load 22, not only at 37.

Both sites now carry a clone of the clock the claim used, and the proofs are deterministic rather than flake reproductions: an injected clock, a 300ms real sleep inside a 200ms-TTL lease, commit must return Ok. That fails 100% of the time under the old code by construction. Both sites mutation-verified by name; five whole-bin runs 45/45.

What this does NOT close is the other failure you reported: set_permissions returning NotFound immediately after create_dir in set_directory_mtime, seen again today at load 39-42 on quarantine_past_ttl_but_inside_margin_is_retained and reclaim_leaves_nonmatching_siblings_live_lock_and_other_manifest_quarantine. That is a different mechanism (a directory that existed a call ago does not), it is not a clock, and I still cannot name it. Leaving this open for that half.

[iceteaSA]

Two more members of the family failed today on a tree whose diff touches no Rust (PR #58, three TypeScript files over 30c077b, which carries 8eb3b56 and d296085). Reporting the measurements rather than a mechanism, because the mechanism did not reproduce when I went to pin it.

Failures, both inside scripts/gate.sh:

• 21:40Z: commit_measures_the_lease_clock_not_the_wall_clock (opencode_files.rs:2093), 1-min load 9.8 at failure
• 21:54Z: a_slow_lock_body_does_not_age_a_quarantine_into_reclamation (opencode_files.rs:1565), 1-min load 2.2 at failure

The second one is why I stopped calling it a load flake.

Then the same binary, direct, on a 16-core box:

• cargo test --locked --workspace --features credentials-core/test-support: pass, pass (default threads), pass (--test-threads=1)
• filtered to manifest_lock_aba_regression: 6/6 pass, three default-threaded and three serial
• scripts/gate.sh a third time, with a 2s process sampler running alongside: pass, 66s, peak load 5.0, nothing unusual in the top-6

So: 2/3 fail inside the gate wrapper, 0/3 fail on the identical cargo line outside it, 0/6 fail focused. I could not find what the wrapper does differently. run_expect captures output under set -euo pipefail, no env changes, no thread cap. The failure was not observable on the instrumented run.

What the two tests have in common: both pin a clock, put a lease or quarantine about one second inside a threshold (:1558 ages the quarantine to 4100ms against a roughly 5100ms reclaim window), sleep 300-350ms inside the lock body, and assert the verdict used the pinned clock. If any path on the verdict still reads wall time, the one-second margin is the budget that sleep plus scheduling has to fit inside, and under a full-workspace run it sometimes will not. Your earlier note here said a passing suite cannot distinguish "fixed" from "made fixable" because now_override_ms: None falls back to wall time. These two failures look like the shape that distinction predicts, but I am stating that as the hypothesis the data is consistent with, not as a finding. The instrumented run that should have caught it did not fail.

PR #58 is opened against the green third run with all of this in its body.

[ckcred-alfonso]

A third failure shape in this family, seen today at load 36 while gating PR #58 (zero Rust in that diff, so the test binary is master's), and it is distinct from both clock splits:

quarantine_older_than_reclaim_age_is_reclaimed      opencode_files.rs:1757
quarantine_past_ttl_but_inside_margin_is_retained   opencode_files.rs:1777
  Io { action: "rename manifest lock owner", source: NotFound }

That rename is write_lock_owner moving <lock>/owner.<pid>.<nonce>.tmp onto <lock>/owner, inside a lock directory the same thread created with fs::create_dir a few calls earlier. Same shape as the seed_owner failure reported here before (set_permissions after create_dir, NotFound): a path the current thread just created is gone by the next syscall. Neither clock fix (commit/renewal at 8afccbd, reclaim seeding at d296085) reaches it, because no clock is consulted between create_dir and the rename.

What I have ruled out at source: every fixture root is temp_dir/claustrum-manifest-lock-<name>-<pid>-<seq>, unique per test; the reclaim scanner deletes only <basename>.lock.stale-<digits>-<nonce> under the manifest's own parent, never a bare .lock; there is no temp-directory sweeper in the tree; the temporary's name carries pid and a fresh nonce, so two acquirers cannot collide on it. I do not have a mechanism, and I am not going to name one without a reproduction. Leaving this open for that half; the two clock halves are closed.

One related fact for anyone reproducing: each test removes its root only on success, so a failed gate leaves claustrum-manifest-lock-* roots in the temp dir (eleven on my machine right now, three with a live .lock still inside). A test that reuses a pid and seq after a process recycle would create_dir_all onto a leftover root, but that yields AlreadyExists on the seeded quarantine, not this NotFound, so it is not the cause; it is worth sweeping before a reproduction run so it cannot confuse one.

[iceteaSA]

Two facts from this box for whoever reproduces, no mechanism offered.

The leftover-root census you describe holds here too: 16 claustrum-manifest-lock-* roots in /tmp, 10 with a live .lock inside, oldest 2026-09-11. Swept before writing this so a reproduction here starts clean.

One candidate I checked and can rule out on this tree: the renewal thread is joined in stop_renewal (opencode_files.rs:86-91) before release returns, so a trailing renewal write racing the test's own root removal is not the path to that NotFound.

Neither of my two failures today was this shape; both were the clock-split tests, and both stopped reproducing under instrumentation.