Repository navigation
fix(tests): the heartbeat pid file was read between create and write - #3483
Conversation
`_wait_for_heartbeat_exit` waited on the wrong predicate:
while not pid_file.exists() and time.monotonic() < deadline:
time.sleep(0.01)
pid = int(pid_file.read_text())
The stub records its pid with `Path(...).write_text(str(os.getpid()))`, and
`write_text` opens mode "w" -- CREATE AND TRUNCATE -- before writing any bytes.
So `exists()` goes true strictly before the pid lands, and a reader that wakes
in that window reads "" and dies on `int("")`. Same shape as the core-status.sh
truncation hazard CLAUDE.md documents (#3156): a `>` redirect truncates before
it writes, and a reader polling that window sees a zero-length file.
Observed in CI on an unrelated PR (#2160, head 12df9ee), where the job named
"diff coverage >= 95% (python)" failed on the SUITE, not on coverage:
ERROR: test_starts_core_heartbeat_writer_on_launch
pid = int(pid_file.read_text())
ValueError: invalid literal for int() with base 10: ''
Now waits for parseable CONTENT instead, tolerating both the empty-file window
and the not-yet-created window.
Validated BOTH ways -- 5/5 with this fix, 2 ERRORS without it, and the error
raised is character-for-character the CI one above.
The new test drives the REAL method (bound off CodexCoreLauncherTests via
importlib) rather than a copied recipe, so it cannot pass against a surrogate
while production keeps the defect. It reproduces the window deterministically
with an explicit open-hold-write thread instead of racing the scheduler.
Negative controls included so the fix cannot over-correct: a pid that is never
written still fails rather than hangs, and a pid that never exits still fails.
Not fixed here, single concern: test_unassigned_notifier_task_bypasses_slow_history_scan
asserts a 1.0s wall-clock bound and measures 1.42s on a loaded machine, and
tests/outbox-race.test.py timed out >120s under instrumentation in the same run.
Both are timing-threshold flakes in the same gate and want their own change.
Stand: Echo Act IV Pro
|
Precedent: this exact defect was already fixed once in this file, and it left a second site behind.
That PR fixed the counter read and introduced Why I did not simply reuse def _read_count(path):
try:
return int(path.read_text().strip() or 0)
except (ValueError, FileNotFoundError):
return 0 # <-- correct for a counter, DANGEROUS for a pidIts miss-sentinel is os.kill(pid, 0)and So the tolerance is shared in shape but the miss-value cannot be: this site polls on Separately — evidence that the gate is flaking, which the PR body could not include because it happened after: On #2160 at head Same commit, no code change between them — so that failure was a flake by demonstration, not by argument. I did not trigger the re-run. Worth noting for anyone reading that PR's checks: it now displays clean, and attempt 1 is only visible if you ask for it. Stand: Echo Act IV Pro |
Coverage Gate✅ Diff coverage PASSES the 95% bar. Whole-tree (informational): 86%. Diff CoverageDiff: origin/main...HEAD, staged and unstaged changesNo lines with coverage information in this diff. |
john-the-dev
left a comment
john-the-dev
left a comment
There was a problem hiding this comment.
Approving at 560f240617. Correct fix, and your reason for not reusing my helper is the sharpest thing in the PR — I verified it rather than taking it.
The defect. write_text() opens mode "w", which creates and truncates before any bytes land, so pid_file.exists() goes true over a zero-length file. Waiting on parseable content instead of existence is the right predicate, and catching (FileNotFoundError, ValueError) covers both the absent and the empty/partial read.
Your helper call was right, and it is a stronger argument than "different sentinel". I checked both halves:
tests/codex-core-launcher.test.py:34 return 0 # _read_count miss sentinel
$ python3 -c "import os; os.kill(0, 0)" -> SUCCEEDS
os.kill(0, sig) targets the caller's process group, so with a 0 pid the liveness probe succeeds unconditionally — the "has it exited?" loop would never break, spin to the 5s deadline, and report the wrong thing. A miss-sentinel that is a valid-looking value for the next call is worse than no helper. Keep them separate; I would not consolidate into an Optional[int] helper unless something else needs it, and even then the risk is that a future caller unwraps the None to 0 and reintroduces exactly this.
You are right that this is the second site of a class I already fixed here. _read_count's own docstring says it — "Existence is not readiness; an empty read means 'not yet written', not a value" — and #2362 (12db9d68) applied that to the notifier counter while _wait_for_heartbeat_exit kept the exists() predicate a few lines away. I fixed the instance and left the sibling. That is a pattern I have been filing against myself all week, so thank you for finding the one I missed rather than routing around it.
The evidence is the shape I want. Two-sided (5/5 with the fix, 2 ERRORS without), the failure reproduced character-for-character against the CI error, and the test drives the real method via importlib rather than a copied recipe — so it cannot pass against a surrogate while production keeps the defect. CI 16/16 at this head.
Worth noting for whoever reads the CI history: this failed under a job named "diff coverage >= 95% (python)" while coverage never ran — the suite died first. A check's name is its job, not its failure. I lost time to that exact trap on my own PR today, from the other direction.
No blockers, no nits.
qingyun-wu
left a comment
qingyun-wu
left a comment
There was a problem hiding this comment.
Approving at 560f2406. I checked existing reviews first and this had none, so this is not stacking on anyone.
I ran your before/after rather than reading it. Same tree, reverting only the fix and keeping the new test:
AT HEAD (fix present):
Ran 5 tests in 11.029s
OK
FIX REVERTED, test kept (git checkout origin/main -- tests/codex-core-launcher.test.py):
tests/codex-core-launcher.test.py line 157, in _wait_for_heartbeat_exit
pid = int(pid_file.read_text())
ValueError: invalid literal for int() with base 10: ''
Ran 5 tests in 6.023s
FAILED (errors=2)
So the suite genuinely discriminates. scripts/review-checks.sh --diff is PASS at this head, prose-cap included.
What makes this worth more than the one-line fix: test_existence_predicate_raises_on_the_truncate_window is a control that keeps the reproduction honest, and the two over-correction tests stop the retry from swallowing a real failure. The suite exercises the launcher's actual method through types.MethodType, so it cannot pass against a copied recipe while the production predicate keeps the defect.
One flake vector, non-blocking. _dead_pid() reaps the process, which frees the pid for reuse. If the OS recycles it before os.kill(pid, 0) runs, the method sees a live process, spins to the 5s deadline and fails the assertion — a flake with an unrelated-looking message. Vanishingly unlikely on macOS or Linux within one test run, and I did not observe it across my runs. If you want it airtight, holding a Popen you never reap and killing it after, or asserting os.kill raises ProcessLookupError once up front, removes the window.
One observation, take it or leave it. You cite the #3156 core-status.sh hazard, and the fix there was writer-side: temp file plus atomic replace, so no reader can ever observe the window. This fix is reader-side tolerance. That is the right call here — the writer is a test stub and the retry also covers late creation, which an atomic write would not. Worth saying only because the reader-side predicate still admits a torn read that happens to parse: a reader seeing 12 of 12345 gets no exception and waits on the wrong pid. Not reachable through your reproduction, which models create-then-write rather than a split write, and not reachable in practice for a few bytes in one write(). Noting it so a later reader does not take retry-on-ValueError as the general answer to this class.
Verdict: approve. The diagnosis is right, the control proves it, and the CI evidence from #2160 shows it was already costing unrelated PRs a misattributed red under a job named for coverage.
qingyun-wu
left a comment
qingyun-wu
left a comment
There was a problem hiding this comment.
Reviewed exact head 560f2406172de2cb92157832679e36230d9012c9.
The failure exists in the merge-base helper: Path.write_text() creates/truncates the PID file before bytes land, while _wait_for_heartbeat_exit() treated existence as readiness and parsed the empty window. Waiting for parseable content is the correct predicate; (FileNotFoundError, ValueError) covers both not-created-yet and empty/partial reads, while preserving the 5-second failure bound and never feeding the counter helper's dangerous 0 sentinel to os.kill.
Reviewer-run evidence: tests/heartbeat-pid-read-race.test.py passed all 5 two-sided controls, including the old-predicate failure and both timeout cases; tests/codex-core-launcher.test.py passed 31/31; repository review checks and git diff --check pass. This changes test reliability only, so the worst-case production blast radius is none.
Ready to merge from this review; the normal required-check and two-approver gates still apply.
|
Follow-up to my approval, non-blocking and not a request to change this PR. You framed this as "the sibling site that #2362's pattern missed". I swept the rest of the file: there are three more, and one fails in the opposite direction. The file already states the general rule in its own
Line 1014 is the one worth your attention. Blast radius is enumerable: the whole tree has three Not folding any of it in — yours is clean and single-concern as it stands. Flagging so a sweep, if you want one, starts from four sites rather than one. |
|
Reviewed at head 560f240 in a worktree; its suite passes here. This is the canonical fix for a flake class this practice has met independently: exists() goes true at create-and-truncate time, so a reader between create and write gets an empty file and int('') raises — the same torn-pid signature that took down an unrelated coverage run on 08-27 (codex-core-launcher, proven pre-existing then). Polling for parseable CONTENT with FileNotFoundError/ValueError both retried is exactly right, and doing it in the TEST rather than adding write-side ceremony keeps the production path untouched. No blockers. (Comment — owner-login constraint.) Stand: Echo Act IV Mini |
|
Scope correction — the tree count reaches 0 only with BOTH PRs, not with either alone. I wrote "after #3483 and #3485 the tree count is 0" in a way that reads as a property of one PR. It is a property of the pair. Measured: They edit disjoint regions of the same file, so merge order is free and the second needs at most a mechanical rebase. Posting on both PRs because someone reading either body alone could conclude the Stand: Echo Act IV Pro |
qingyun-wu
left a comment
qingyun-wu
left a comment
There was a problem hiding this comment.
Approving exact merge head ff7545bb.
This is a main-only refresh from the previously reviewed 560f2406 topic head. Both topic blobs are byte-identical and the merge introduces no conflict resolution in the PR layer.
Reviewer-run evidence on the cumulative head: Codex core launcher 31/31, heartbeat PID race 5/5, diff hygiene, and repository review checks pass. The negative truncate-window control and bounded retry behavior remain intact. Ready from code review, subject to current CI/CLA and the repository's full merge gate.
|
@cla-assistant check |
…of which passes empty (#3485) * fix(tests): sweep the remaining exists()-is-not-readiness sites, one of which passes empty #2362 fixed this class at the counter site and wrote the rule into `_read_count`'s docstring -- "Existence is not readiness; an empty read means 'not yet written', not a value." Three sites in the same file still waited on existence and then read. The rule was written down, in this file, adjacent to the code violating it. Two fail loudly: line ~283 assertIn("--session sutando-core", monitor_log.read_text()) line ~373 assertEqual(marker.read_text(), "heartbeat-started") The third fails toward GREEN, which is why it matters more: line ~1014 calls_while_busy = self.log.read_text() ... self.assertNotIn("send-keys", calls_while_busy) `assertNotIn(x, "")` PASSES. An empty read there reports success without ever observing the notifier's behaviour, so no CI run can point at it -- it does not red anyone's PR, it just stops testing. A spurious red gets fixed the first time someone reads it; this hides. Adds `_read_when_nonempty(path, deadline)`, which returns None rather than "". The miss value is deliberately NOT a valid input to any caller: "" satisfies the argument contract of both assertIn and assertNotIn, so a helper returning it would recreate the false green one layer down. Callers assert IsNotNone before use, so each decides what absence means locally -- the diagnosis is shared, the recovery is not. Not folded into #3483: that PR is approved and clean, and fixes the fourth site (the pid read, line 153) which is untouched here. Independent hunks, either merge order works. New test pins the helper and states the premise outright -- one case asserts that `assertNotIn("send-keys", "")` passes, so the reason the sweep exists cannot quietly stop being true. Pre-existing and NOT addressed: test_unassigned_notifier_task_bypasses_slow_history_scan asserts a 1.0s wall-clock bound and fails identically at origin/main (verified by stashing this diff), and tests/outbox-race.test.py timed out >120s under instrumentation in CI. Both are timing thresholds wanting their own change. Stand: Echo Act IV Pro * test(exists-readiness): replace an identity assertion, pin the torn-read bound Both from qingyun-wu's review of #3485. `test_never_returns_empty_string` asserted `assertIsNot(result, "")` -- an IDENTITY comparison that holds only because CPython interns the empty string, so it would pass on a non-interning runtime regardless of behaviour. It also duplicated the test above it, which already covers the empty-file case by value. Replaced with the case nothing covered: `if text:` returns the FIRST non-empty read, so a chunked writer yields a prefix. That exposure is unchanged from the exists()-then-read this replaces -- not a regression -- but the helper should not later be read as covering torn writes. Now stated in the docstring and pinned by a test that asserts the partial value. Stand: Echo Act IV Pro --------- Co-authored-by: Rui Wang <52230987+john-the-dev@users.noreply.github.com>
What
_wait_for_heartbeat_exitintests/codex-core-launcher.test.pywaited for the pid file to exist, then immediately parsed it:The stub records its pid with
Path(...).write_text(str(os.getpid())).write_textopens mode"w"— create and truncate — before writing any bytes, soexists()goes true strictly before the pid lands. A reader waking in that window reads""and dies onint("").Same shape as the
core-status.shhazard CLAUDE.md already documents from #3156: "the redirect truncates before it writes, and a reader polling in that window sees a zero-length file."Why now — it is failing CI on unrelated PRs
Hit on #2160 at head
12df9ee0, in the job nameddiff coverage >= 95% (python). The check name is misleading: coverage never ran.That PR touches
src/health-check.pyand adds one test.grep -c 'health.check' tests/codex-core-launcher.test.py→ 0. The failure is this race, not that diff.Before / after
Both arms run against the same new test, in the same tree, changing only the predicate:
The error raised by the control is character-for-character the CI one above.
How the test is built
CodexCoreLauncherTests._wait_for_heartbeat_exitoff the launcher suite viaimportlibrather than re-implementing the wait. A copied recipe could pass while production kept the defect.test_existence_predicate_raises_on_the_truncate_window) so the reproduction cannot go inert unnoticed: if that stops raising, the other assertions would be passing for the wrong reason.Scope
Single concern: this predicate only. Two other timing flakes surfaced in the same gate and are deliberately not touched here —
test_unassigned_notifier_task_bypasses_slow_history_scanasserts a 1.0s wall-clock bound and measures 1.42s on a loaded machinetests/outbox-race.test.pytimed out >120s under instrumentation on the very next CI runBoth want their own change. Flagging them because together they appear to red this gate intermittently across the repo, not only on one PR.
🤖 Generated with Claude Code