Skip to content

fix(canary): run the version of run_canary.py that the pull just installed - #583

Merged
ffroliva merged 1 commit into
developfrom
bugfix/582-canary-reexec-after-pull
Aug 26, 2026
Merged

ffroliva merged 1 commit into
developfrom
bugfix/582-canary-reexec-after-pull

Conversation

@ffroliva

Copy link
Copy Markdown
Owner

Closes #582.

The bug

1. Python loads run_canary.py into memory        <- the OLD copy
2. sync_to_develop() fast-forwards the checkout  <- NEW copy now on disk
3. run_tiers() uses the in-memory argv           <- still the OLD one

The script updates its own source and then keeps executing the version it started with. Every runner change was one night late, and invisibly so.

What it cost

#572 added -o junit_logging=all so a preserved RED would carry the client.context_cookie_state line that decides #561. Merged 2026-08-25 12:29 UTC; the 2026-08-26 02:00 run pulled it and produced a RED with zero log output.

git show 230200b:scripts/canary/run_canary.py | grep -c junit_logging   ->  0

Three consecutive REDs untriageable. And the failure reads as "#572 did not work" — I was one step from rewriting a fix that was already correct.

Confirmed #572 is fine: a manual run on the current runner captured 40 system-out entries, 11 context_cookie_state lines, and flow_session_cookie_present. The stale runner was the whole story.

The fix

Re-run once when a successful pull changed the script's own source.

Two independent loop guards, either sufficient alone — a canary that re-execs forever is worse than one that updates late:

  1. GFLOW_CANARY_REEXECED in the child env, checked first.
  2. A content digest — no change, no re-run.

An unreadable digest degrades to "unchanged": updating late is a nuisance, looping is an outage.

subprocess.run, never os.execv — and this is load-bearing on Windows. execv there does not replace the process image; the CRT spawns a new process and terminates this one, so the PID changes and Task Scheduler can read the task as finished. A supervising process keeps the scheduler's view intact and propagates the child's exit code. Asserted by an AST test, because a substring search matches the module's own explanation of why execv is wrong.

⚠️ The fix cannot help its own deployment — the first run after it lands is still the old runner. It applies from the following change onward.

E2E gate — with a control that reproduces the original failure

Scratch clone, real profile, $0:

arm setup result
control clone on the pre-fix runner; pull brings the flag no re-exec (correct — the old runner cannot know about it) · JUnit system-out: 0 ← reproduces the 02:00 failure exactly
treatment clone on the fixed runner; develop ahead with a runner change canary.reexec_after_pull: ffd32333cb9b -> fef66243ee51 · pulled runner in place · ran once, no loop · **JUnit system-out: 42`

The control is the original bug, reproduced on demand. That is what makes the treatment proof rather than coincidence.

Verification

  • 6 new unit tests (digest stability, both loop guards, argv preserved, exit code propagated, AST no-execv)
  • tests/scripts: 184 passed
  • ruff check + format --check clean on the touched files and on the canonical src tests gate
  • repo hygiene (813 files), doc links
  • E2E with a reproducing control arm

Also learned tonight

The canary was GREEN when run manually at 06:06 UTC — same clone, same commit, same profile as the 02:00 RED. Combined with a manual spike returning 200 at ~20:00 UTC, the #561 401 looks time-dependent rather than persistent. Recorded on #561; out of scope here.

…alled

`run_canary.py --pull` fast-forwards the checkout and then keeps executing the
copy Python loaded at startup:

    1. Python loads run_canary.py into memory        <- the OLD copy
    2. sync_to_develop() updates the working tree    <- NEW copy on disk
    3. run_tiers() uses the in-memory argv           <- still the OLD one

Every runner change was silently one night late.

Not theoretical. #572 added `-o junit_logging=all` so a preserved RED would carry
the `client.context_cookie_state` line that decides #561. It merged 2026-08-25
12:29 UTC; the 2026-08-26 02:00 run pulled it and produced a RED with ZERO log
output, because the pre-pull copy was running:

    git show 230200b:scripts/canary/run_canary.py | grep -c junit_logging  -> 0

Three REDs are untriageable as a result. The failure mode is invisible — it reads
as "#572 did not work", which invites rewriting a fix that was already correct.

The runner now re-runs itself once when a successful pull changed its own source.

Two independent loop guards, either sufficient alone:
  - GFLOW_CANARY_REEXECED in the child env, checked first
  - a content digest; no change, no re-run
An unreadable digest degrades to "unchanged": updating late is a nuisance,
re-running forever is an outage.

Uses subprocess.run, never os.execv. On Windows execv does not replace the
process image — the CRT spawns a new process and terminates this one, so the PID
changes and Task Scheduler can read the task as finished. A supervising process
keeps the scheduler's view intact and propagates the child's exit code. A test
asserts this via AST (a substring search matches the module's own explanation of
why execv is wrong).

E2E verified on a scratch clone against a real profile, $0:

  control   clone on the pre-fix runner, pull brings the flag
            -> no re-exec (correct: the old runner cannot know about it)
            -> JUnit system-out: 0        <- reproduces the 02:00 failure exactly

  treatment clone on the fixed runner, develop ahead with a runner change
            -> canary.reexec_after_pull: ffd32333cb9b -> fef66243ee51
            -> pulled runner in place, ran once, no loop
            -> JUnit system-out: 42       <- the pulled flag was actually used

Separately confirmed #572's flag itself works when the runner is current: a
manual canary run captured 11 `context_cookie_state` lines including
`flow_session_cookie_present`. The mechanism was always sound; the stale runner
was the whole story.
@ffroliva
ffroliva merged commit 1178429 into develop Aug 26, 2026
15 checks passed
@ffroliva
ffroliva deleted the bugfix/582-canary-reexec-after-pull branch August 26, 2026 06:28
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.

canary: run_canary.py --pull updates its own source but keeps running the pre-pull copy

1 participant