Skip to content

fix(artifacts): lock library.json's read-modify-write across processes - #4

Open
dudarenok-maker wants to merge 2 commits into
mainfrom
fix/artifact-library-lock
Open

fix(artifacts): lock library.json's read-modify-write across processes#4
dudarenok-maker wants to merge 2 commits into
mainfrom
fix/artifact-library-lock

Conversation

@dudarenok-maker

Copy link
Copy Markdown
Owner

Summary

  • update_artifact_library_live / append_artifact_library_version read-modify-write ~/.ringer/artifacts/library.json with no cross-process coordination
  • Two lanes finishing close together race; a stale-read writer overwrites whatever a concurrent writer just added
  • Confirmed on a real box: cline-glm had real run/report/version files with no matching library.json entry - a quota-limited lane that runs rarely never gets a chance to self-heal the way high-frequency lanes (claude, cline) do
  • Adds artifact_library_lock(), a Windows-safe exclusive-create lockfile mutex (this file's existing catalog_refresh_lock uses fcntl, which silently no-ops on native Windows), around both critical sections, with stale-lock stealing so a crashed holder can't wedge every lane's update forever

Test plan

  • New regression test reproduces the lost-update symptom; verified it fails when the lock is neutralized and passes with the fix (see commit)
  • New test pins the lock's mutual exclusion directly
  • pytest tests/test_artifact_library.py - all pass
  • Full suite (pytest tests/) - same 37 pre-existing, unrelated failures before and after; no regressions

update_artifact_library_live and append_artifact_library_version each read
the whole file, mutate one key, and write it back with no cross-process
coordination - atomic_write_json only makes the final write atomic, not the
read-modify-write cycle around it. Two Ringer lanes finishing close together
race: whichever holds a stale read writes last and silently reverts whatever
the other lane just added. A high-frequency lane (claude, cline) self-heals
within minutes; a quota-limited lane that runs rarely (cline-glm,
cline-qwen-cloud, cline-muse-local, cline-qwen-local) loses its entry for
good the next time a busier lane races past it with a stale read, because
nothing re-adds it until that lane happens to run again.

Confirmed on a real box: cline-glm has real run/report/version files on disk
going back weeks with no matching library.json entry at all.

Adds artifact_library_lock(), an exclusive-create lockfile mutex (Windows-
safe, unlike this file's existing catalog_refresh_lock, which imports fcntl
and silently no-ops on native Windows), wrapping both critical sections.
Steals a stale lock past a timeout so a crashed holder can't wedge every
other lane's library update forever.

Two new regression tests: one reproduces the exact lost-update symptom
(fails without the fix, passes with it - verified by neutralizing the lock
and re-running), one pins the lock's mutual exclusion directly.
@dudarenok-maker

Copy link
Copy Markdown
Owner Author

PR review — pass 1 (head 2a689b3, depth medium)

Scope: ringer.py (artifact_library_lock and its two call sites, plus every other library.json read-modify-write in the file) and tests/test_artifact_library.py. Verified before probing: full file suite green on the branch (10 tests, OK), and the new lost-update test re-run against main's ringer.py to confirm it is a real regression test. Findings below are executed, not reasoned — probe scripts run against the branch on native Windows (Python 3.12.10), the box CONTRIBUTING.md names as the deployment target.

Verdict up front: the lock is correctly placed at the two sites it wraps, and the read is correctly inside the critical section — but the bug the PR set out to fix is still reproducible after the fix, and on Windows the new lock actively drops writes under contention. Three blocking items.

🔴 Blocking — the reported symptom still reproduces: a third read-modify-write site was missed

reconcile_artifact_library_dead_runs (ringer.py:3469-3486) is a full-file read-modify-write on library.json — read at 3470, whole-library write-back at 3486 — and it was not wrapped. It is not a rare path:

  • ringer.py:2259StateWriter.start() calls it at every run start, i.e. every time any lane launches;
  • ringer.py:5916 — the HUD's GET /api/library handler calls it on every dashboard poll, in a separate long-lived process.

So the most frequent writer in the system is still unlocked, and it writes back an entire library snapshot taken before it did its read_active_runs() work. A lane whose locked write lands inside that window is erased wholesale — which is exactly the reported symptom (a rarely-running lane with real run/report/version files on disk but no library.json entry).

Executed repro (probe_d, widening reconcile's natural read→write window by delaying read_active_runs, which sits between the two and needs no change to the code under test):

=== D: unlocked reconcile vs locked live-update ===
  seeded entries: ['Old Lane']
  entries after:  ['Old Lane']
  RESULT: *** LOST UPDATE *** 'Rare Lane' was erased by the unlocked reconcile,
          despite its write holding the lock

Rare Lane's update_artifact_library_live acquired the lock, wrote, and released — and the unlocked reconcile still clobbered it. The PR's own framing ("whoever's STALE read writes LAST wins") describes reconcile better than it describes the two functions that were fixed, because reconcile is the one that rewrites every key from a stale snapshot.

Knock-on: reconcile's stale write-back can also resurrect versions rows that prune_artifact_versions has already deleted the files for, leaving library entries pointing at 404s.

Fix: wrap 3470-3486 in artifact_library_lock(state_dir) — read included, per the same shape used at the other two sites.

🔴 Blocking — on Windows, contended acquisition raises an uncaught PermissionError and aborts the update

ringer.py:3302 acquires with os.open(lock_path, os.O_CREAT | os.O_EXCL | os.O_WRONLY) and catches only FileExistsError at 3306. On Windows a create against a name in the delete-pending window left by the previous holder's unlink() (3319) returns ERROR_ACCESS_DENIED, which Python raises as PermissionError, not FileExistsError. It escapes the handler, propagates out of the context manager before yield, and takes the whole call with it — then the caller's best-effort handler swallows it (ringer.py:2462 / 2486, "artifact library update error (non-fatal)").

Net effect under contention on Windows: the fix converts a probabilistic lost update into a deterministic dropped update.

This is not hypothetical — it fired on the first run of this PR's own test suite, and reproduces at ~7.5% of contended acquisitions:

=== A/B: contention on a live lock (4 threads x 10 trials) ===
  TOTAL entered=37 crashed=3 crash_types={'PermissionError': 3}
  trials where >=1 thread never reached the critical section: 3/10
PermissionError: [Errno 13] Permission denied:
  '...\state\artifacts\library.json.lock'
  File "C:\Claude\ringer\ringer.py", line 3302, in artifact_library_lock
    fd = os.open(lock_path, os.O_CREAT | os.O_EXCL | os.O_WRONLY)

Two consequences for the PR's claims:

  • the comment at ringer.py:3287-3289 — "works identically on Windows and POSIX" — is falsified, and it is the load-bearing justification for choosing this design over catalog_refresh_lock's fcntl;
  • CONTRIBUTING.md's rule 3 says "platform claims must be proven by the job for that platform, not asserted". The Windows job is continue-on-error: true (.github/workflows/tests.yml:35), so it cannot prove this one, and this PR's central claim is Windows-specific.

Fix: catch OSError and re-dispatch on errno/existence rather than catching FileExistsError alone — treating EACCES/EEXIST alike as "someone else holds it, keep polling", while still letting genuine errors (ENOENT on a missing parent, EROFS) out after the deadline.

🔴 Blocking — test_lock_serializes_overlapping_critical_sections cannot fail on that defect

tests/test_artifact_library.py:263-286. Exceptions raised inside a threading.Thread target do not fail a unittest case — they are printed by threading.excepthook and discarded. So in the 3-in-20 runs where the PermissionError above fires, a thread never enters the critical section, and the test still reports ok:

test_lock_serializes_overlapping_critical_sections: 0/20 FAILED,
  3/20 runs logged a swallowed PermissionError in a worker thread

The assertion at 284 is assertEqual(1, max_active), and max_active is monotonically weakened by exactly the failures it should catch — a thread that dies before the lock never increments it. The test passes with as few as one of four threads ever entering, i.e. having demonstrated no concurrency at all. This is why the PR's "verified on a real box" test-plan checkbox did not surface the Windows defect: the instrument cannot report it.

Fix: collect worker exceptions into a list and assertEqual([], errors) after the joins, and assert the number of threads that actually entered (assertEqual(4, entered)) alongside max_active.

🟠 Significant — the stale-steal is a real TOCTOU; two processes can hold the lock at once

ringer.py:3307-3310:

with contextlib.suppress(OSError):
    if time.time() - lock_path.stat().st_mtime > ARTIFACT_LIBRARY_LOCK_STALE_S:
        lock_path.unlink()
        continue

stat() decides staleness about one file; unlink() then removes whatever file is at that path at that instant — which may be a fresh lock another stealer created in between. Worse than a double-entry: the second stealer deletes the first stealer's brand-new lock, and the first stealer's finally at 3317-3319 then unlinks the second's, so the lock file ends up removed by a non-owner and a third process walks straight in.

Executed proof (probe_e, delaying only the first stealer's unlink to widen the window between check and removal — the logic is unchanged):

  stealer-2 IN (concurrent=1)
  stealer-1 IN (concurrent=2)
  max concurrent holders = 2
  RESULT: *** MUTUAL EXCLUSION BROKEN *** two stealers held the lock at once

Honest calibration: with the natural window (two adjacent syscalls) I could not reproduce this in 10 trials of 6 contending threads — it is narrow. But it is an unsound sequence rather than a tight-but-correct one, and its blast radius is the whole guarantee. Fix shape: steal via os.replace(lock_path, unique_name) and verify you got the file you stat'd (write a nonce into the lock body at 3302 and check it after the rename), rather than unlinking by path.

🟠 Significant — the timeout fallback is unreachable-by-steal and completely silent

ARTIFACT_LIBRARY_LOCK_TIMEOUT_S = 10.0 but ARTIFACT_LIBRARY_LOCK_STALE_S = 30.0 (ringer.py:70-72). A waiter that arrives while a holder is alive can therefore never reach the steal path — its own deadline at 3311 always fires first. The steal only ever rescues a lock that was already ≥30 s old on arrival. In the one scenario the lock exists for — a holder wedged mid-critical-section — every waiter proceeds unlocked, at the same moment:

TIMEOUT_S=10.0 STALE_S=30.0
  waiter-0 entered critical section after 10.0s (concurrent writers now = 1)
  waiter-2 entered critical section after 10.0s (concurrent writers now = 2)
  waiter-1 entered critical section after 10.0s (concurrent writers now = 3)
  max concurrent unlocked writers = 3
  diagnostic emitted to stderr = ''

So the fallback reproduces the original lost-update bug with N simultaneous writers and prints nothing — an operator sees precisely what they saw before this PR, which is what made the bug survive so long in the first place. The comment at 3291-3295 argues the trade-off is acceptable; that argument is reasonable for append_artifact_library_version (skipping loses a version permanently), but it needs to be observable. Two changes: emit a print(..., file=sys.stderr) on the unlocked path, matching the file's existing idiom at 2462/2486/2492; and order the constants so STALE_S < TIMEOUT_S, so a wedged holder is actually stolen from rather than bypassed by everyone.

🟡 Minor

  • ringer.py:3308 compares time.time() against st_mtime — wall clock, so an NTP step or a state dir on a share with clock skew mis-classifies staleness. The lock's mtime is also never refreshed while held, so a critical section that legitimately exceeds 30 s becomes stealable. Both are low-impact at the current section length (milliseconds), but they compound the TOCTOU above.
  • tests/test_artifact_library.py:242self.assertTrue(lane_a_reading.wait(timeout=5), "Lane A never started its read") runs inside worker thread B, so if it ever fires the message is discarded and the case fails later at 261 with the unrelated-looking Items in the first set but not the second: 'Lane B'. Same swallowing mechanism as the blocking item above.
  • ringer.py:3307-3313 — if stat() or unlink() raises because the holder released between the failed os.open and the stat, contextlib.suppress(OSError) swallows it and control falls through to time.sleep(POLL_S) instead of retrying immediately, adding up to 50 ms to every handoff. Cosmetic.
  • PR body carries no Closes #NN / Refs #NN. Ringer's CONTRIBUTING.md does not mandate one, so this is informational only.

✅ What is solid

  • test_concurrent_lane_updates_do_not_lose_each_other is a genuine regression test. Verified red against main's ringer.py with the branch's test file, failing for exactly the claimed reason (AssertionError: Items in the first set but not the second: 'Lane B'), green on the branch, 0/20 flakes in isolation. I also instrumented the mock.patch — it is process-global, so the concern that Lane B might also route through slow_read is real in principle, but post-fix Lane B blocks on the lock until Lane A unpatches, and only Lane A goes through it in 5/5 trials. The comment at 213-221 describes what actually happens.
  • The read is inside the critical section at both sites (3388 and 3419), not just the write. That is the part fixes of this shape usually get wrong.
  • prune_artifact_versions outside the lock (3448) is the right call. It is slow filesystem I/O that would extend the critical section for no benefit; every failure path is contextlib.suppress(OSError) so a concurrent double-eviction is a no-op; and its containment guard (root not in resolved.parents, 3461) is sound. The only caveat is its interaction with the missed reconcile site, noted above. Leave it where it is.
  • No descriptor leak. os.close(fd) immediately follows os.open, and acquired = False correctly prevents a timed-out waiter from unlinking a lock it does not own — confirmed in the timeout probe, where the wedged holder's lock file survived all three bypasses.
  • Iterable[None] on the context manager matches the file's own idiom (catalog_refresh_lock, ringer.py:2830), and the comment's claim that that lock imports fcntl and silently no-ops on Windows is accurate (2831-2836). Long explanatory comments are this file's house style (cf. 2279-2286); the new one fits, apart from the falsified sentence flagged above.

Verdict

Request changes. The two locked sites are correct, and the lost-update test is real — but findings 1 and 2 mean the PR does not achieve its stated goal on the platform it targets: the reported symptom still reproduces through reconcile_artifact_library_dead_runs, and contended acquisition on Windows drops the write outright. Finding 3 is why neither showed up in the test plan. Findings 4 and 5 are fixable in the same round and should be, since both are in code this PR introduces.

Pass 1 review of #4 found the create/delete lockfile mutex was wrong in
three ways, each only visible under real syscall contention rather than a
slowed-down/gated repro:

1. Windows raises PermissionError, not FileExistsError, when a create races
   the delete-pending window left by the PREVIOUS holder's own unlink() -
   only FileExistsError was caught, so a real contended acquisition threw
   uncaught out of a best-effort caller. Measured ~7.5% of contended
   acquisitions on this box.
2. The stale-lock steal check (stat the mtime, then unlink) is two syscalls
   with a gap between them - two waiters could each judge the same lock
   stale and both proceed. Reproduced: two concurrent holders.
3. The 10s timeout was SHORTER than the 30s staleness window meant to let a
   waiter steal past a genuinely live holder, so a real holder's presence
   made the timeout fire first every time, silently.

Replaces the whole create/delete design with an OS-level byte-range lock on
a persistent file (msvcrt on Windows, flock on POSIX) - no create/delete
race because the file is never deleted, no staleness question because the
OS releases the lock the instant the holding process's handle closes (crash
included), and no two processes can ever both hold it because the OS
enforces that, not this code.

Also wraps reconcile_artifact_library_dead_runs, a third read-modify-write
site on library.json the first pass missed - it runs at every run start AND
every HUD dashboard poll, making it the system's most frequent
reader-and-writer of the file this whole fix concerns.

Two more defects surfaced by stress-testing the redesign under real (not
slowed-down) heavy contention, past what the review itself caught:

4. os.replace() (MoveFileEx) transiently fails with PermissionError when
   the destination has been momentarily touched by another handle (a virus
   scanner's real-time scan of the file just written) - self-resolving
   within milliseconds, but with no retry it escaped as data loss. Adds a
   bounded retry to atomic_write_text, used by every atomic writer in this
   file, not just the library.
5. The give-up-after-timeout fallback is silent by design - under
   contention that genuinely outlasts the timeout, it reproduces the
   ORIGINAL lost-update bug with zero exception raised. Since the lock is
   now crash-safe there is no longer a reason for a short timeout; widened
   it and made the give-up path print to stderr rather than stay silent.

Test changes: threaded-test exceptions don't fail unittest on their own,
which is why the first pass's own regression test stayed green through a
silently-swallowed PermissionError - every threaded test now routes through
a shared helper that fails on any thread exception. Added a heavy-
contention stress test (20 threads x 25 writes, no pacing) and a test that
forces the timeout path and asserts it is loud, not silent.
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