Skip to content

fix(execution): write the file heartbeat in place — os.replace races concurrent probe reads on Windows (ALP-951) - #356

Merged
jatassi merged 2 commits into
mainfrom
jackson/alp-951-fileheartbeatsink-osreplace-races-concurrent-watchdog-probe
Jun 12, 2026
Merged

fix(execution): write the file heartbeat in place — os.replace races concurrent probe reads on Windows (ALP-951)#356
jatassi merged 2 commits into
mainfrom
jackson/alp-951-fileheartbeatsink-osreplace-races-concurrent-watchdog-probe

Conversation

@jatassi

@jatassi jatassi commented Jun 12, 2026

Copy link
Copy Markdown
Owner

Summary

  • FileHeartbeatSink.beat() now performs a single in-place write_text to the heartbeat path — no .tmp sibling, no os.replace. On Windows, the replace required delete access on the destination, which the watchdog probe's concurrent read_text denies (CPython opens without FILE_SHARE_DELETE) → PermissionError [WinError 5], ~30/day on monitor.heartbeat.
  • The liveness contract is now per-write freshness with read-side tolerance: a probe read landing inside the truncate-write window sees an empty file, which FileHeartbeatProbe.age() already maps to None (startup-grace path, never a restart trigger). Docstrings updated accordingly; no write-temp/os.replace references remain.
  • Tests: a deterministic reproduction of the collision (beat while a reader holds the heartbeat open — red on both platforms under the old implementation), the no-.tmp-sibling + exact-content contract, and the empty-file → None probe path.
  • Also de-fuses the safety core's exposure: its beat() sits outside the per-tick try/except, so once its watchdog resumes probing, the first collision would have killed the process.

Closes https://linear.app/alphamind-jatassi/issue/ALP-951/fileheartbeatsink-osreplace-races-concurrent-watchdog-probe-reads-on

Test plan

  • CI (.github/workflows/ci.yml) green on the PR — lint on Linux + full pytest on Windows
  • Local lint chain clean (ruff check, ruff format --check, mypy, lint-imports)
  • uv run pytest tests/execution/process_supervision/ -n auto — 15 passed
  • ALP-951 acceptance criteria all met

🤖 Generated with Claude Code

…concurrent probe reads on Windows (ALP-951)

FileHeartbeatSink.beat() wrote a .tmp sibling then os.replace'd it onto the
heartbeat path. On Windows, MoveFileEx(MOVEFILE_REPLACE_EXISTING) needs delete
access on the destination, which CPython's open (FILE_SHARE_READ|WRITE, no
FILE_SHARE_DELETE) denies for the duration of the watchdog probe's read_text —
PermissionError WinError 5, ~30/day on monitor.heartbeat. beat() now performs a
single in-place write_text; a probe read landing inside the truncate-write
window sees an empty file, which FileHeartbeatProbe.age() already maps to None
(startup-grace path, never a restart trigger).

Docstrings now state the per-write-freshness + probe None-tolerance contract.
Tests cover the held-open-handle collision, the no-.tmp-sibling contract, and
the empty-file None path.

Closes ALP-951.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@linear

linear Bot commented Jun 12, 2026

Copy link
Copy Markdown
ALP-951 FileHeartbeatSink os.replace races concurrent watchdog-probe reads on Windows — intermittent PermissionError WinError 5 (~30/day on monitor.heartbeat); write the beat in place

Symptom

Since the ALP-941 deploy began writing the monitor's file heartbeat (2026-06-09 ~23:28 MT), MonitorSupervisor._watchdog_loop logs WARNING file heartbeat beat failed with a traceback ending

File "...\process_supervision\heartbeat.py", line 64, in beat
    tmp.replace(self._path)
PermissionError: [WinError 5] Access is denied:
  'C:\\Users\\jacks\\AlphaMind\\logs\\monitor.heartbeat.tmp' -> 'C:\\Users\\jacks\\AlphaMind\\logs\\monitor.heartbeat'

— 28 times on 2026-06-10 (first at 00:20:41 MT) and 33 times on 2026-06-11 (through ~12:00 MT). Failures are isolated singles or pairs spaced exactly 15 s apart. Each failure is caught and the loop continues; no false watchdog restart has occurred yet (every 06-11 restart maps to a real ALP-946 wedge dump).

Evidence (prod logs MT; code at file:line)

  • monitor.log.2026-06-10 / monitor.log: 28 and 33 file heartbeat beat failed WARNINGs respectively, each with the WinError 5 traceback above. Paired occurrences at 01:43:15+01:43:30, 03:04:35+03:04:50, 05:55:59+05:56:14, 09:04:53+09:05:08 — the 15 s spacing equals the monitor watchdog's probe tick (monitor_watchdog_tick_seconds: 15), pointing at the probe's read as the colliding holder.
  • src/alphamind/execution/process_supervision/heartbeat.py:62-64beat() writes monitor.heartbeat.tmp then tmp.replace(self._path) (os.replace).
  • src/alphamind/execution/continuous_monitor/supervisor.py:295-299 — the monitor wraps each beat in try/except and logs the WARNING; the loop keeps running.
  • src/alphamind/execution/process_supervision/heartbeat.py:84-87FileHeartbeatProbe.age() reads the destination via read_text from the separate watchdog process every probe tick.
  • Cross-consumer contrast — the safety core uses the identical shared sink and beats every loop tick (safety_core/loop.py:96), yet safety_core.log 2026-06-08 → 06-11 contains zero beat failures. Its out-of-process watchdog — the only probe reader of safety_core.heartbeat — appears down since ~06-09 (safety_core_watchdog.log has not rotated since 06-09 and its tail is a KeyboardInterrupt shutdown). No concurrent probe reads → no collisions: corroborates the probe read as the colliding handle. (The down safety-core watchdog itself is an operational finding handled outside this issue.)

Root cause (confirmed)

  1. os.replace on Windows is MoveFileEx(..., MOVEFILE_REPLACE_EXISTING), which requires delete access on the destination. CPython opens files with FILE_SHARE_READ | FILE_SHARE_WRITE but not FILE_SHARE_DELETE, so for the duration of the probe's read_text open the destination cannot be replaced — the writer's beat() gets ERROR_ACCESS_DENIEDPermissionError [WinError 5] (heartbeat.py:64). With a beat every ~2.5 s and a probe read every 15 s, occasional collisions are expected and match the observed ~30/day. The sink's own docstring chose write-temp + replace for read-side atomicity; the probe's docstring already anticipates the mirror-image collision ("Windows briefly locking it around the writer's os.replace").
  2. Exposure differs by consumer. The monitor catches per-beat (supervisor.py:295-299) → WARNING only. The safety core's heartbeat.beat() (loop.py:96) sits outside its per-tick try/except — once its watchdog resumes probing, the first collision propagates out of the safety loop and kills the process (NSSM restarts it; recurring crash-churn at the monitor's observed collision rate).
  3. Tail risk on the monitor: a destination handle held longer than the stall bound (stuck SMB handle, AV scan/quarantine) fails every beat for that duration; after monitor_watchdog_tick_seconds × watchdog_cadence_multiplier (150 s) of failed beats the external watchdog restarts a healthy monitor.

Why it escaped tests

tests/execution/process_supervision/test_heartbeat.py exercises sink and probe sequentially in one process; the defect needs a concurrent reader holding the destination open at the instant of os.replace under Windows share-mode semantics. CI runs on Windows but never runs sink and probe concurrently. The fix removes the replace dependency rather than attempting to simulate the race.

Scope — write the beat in place; the probe's existing None-tolerance is the atomicity contract

(A) In-place write. FileHeartbeatSink.beat() (heartbeat.py:55-64) writes directly: self._path.write_text(repr(self._now()), encoding="utf-8") — no .tmp sibling, no os.replace, nothing for a concurrent reader to deny. A probe read landing inside the truncate-write window sees an empty file, which FileHeartbeatProbe.age() already maps to None (one missed probe tick on the startup-grace path — never a restart trigger, heartbeat.py:73-91).

(B) Docstrings. Update the module docstring (heartbeat.py:17-18) and beat() docstring: the liveness contract is per-write freshness with the probe tolerating an empty/malformed read as None, replacing the write-temp + os.replace atomicity claim.

(C) Tests. Update tests/execution/process_supervision/test_heartbeat.py: beat() leaves only the heartbeat file (no .tmp sibling) and its content parses to the injected clock value; keep/cover the probe's None on an empty file.

Acceptance criteria

  • beat() performs a single direct write_text to the heartbeat path; no .tmp path is created or replaced — unit test asserts the directory contains only the heartbeat file after beats and the content equals repr of the injected clock.
  • FileHeartbeatProbe.age() returns None for an empty heartbeat file — covered by a unit test.
  • heartbeat.py docstrings describe the in-place write + probe None-tolerance contract; no reference to write-temp/os.replace remains.
  • Lint chain green: uv run ruff check . && uv run ruff format . && uv run mypy && uv run lint-imports.

Verification

  • uv run pytest tests/execution/process_supervision/ -n auto (sink, probe, watchdog tests).
  • Authoritative gate: the ci workflow (full suite, Windows, -n auto).
  • Post-deploy prod spot-check: monitor.log accumulates no new file heartbeat beat failed WARNINGs across a full trading day (was ~30/day).

One-time prod data cleanup

No bulk cleanup needed. The failures only skipped individual heartbeat refreshes; no DB state is involved. The stale monitor.heartbeat.tmp left behind by failed replaces is overwritten by subsequent beats and becomes unused after the fix; it may be deleted on the prod box but nothing reads it.

Related

  • ALP-941 — introduced the file heartbeat + out-of-process watchdog this sink serves; the 150 s stall bound is the false-restart threshold in root-cause step 3.
  • ALP-946 — the investigation that surfaced this defect (its "Separate observation" section); all watchdog restarts observed there are real wedges, not false positives from this race.

Review in Linear

…c prefix is unobservable

The watchdog restarts on a single stale probe, so a torn read parsing to an
ancient epoch would be a false restart; beat()'s docstring now states the
all-or-nothing visibility of the single small write that rules it out.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@jatassi
jatassi merged commit 54df5bc into main Jun 12, 2026
0 of 3 checks passed
@jatassi
jatassi deleted the jackson/alp-951-fileheartbeatsink-osreplace-races-concurrent-watchdog-probe branch June 12, 2026 00:33
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