fix(rollback): announce the post-update probation commit on stderr (#5232)

[sanity]

Problem

#5232 reported that post-update probation is never committed — so a node stays probationary indefinitely after an update, every later clean stop is scored as a crash, and the third one rolls the node back off the release it just installed and pins that release as known-bad. A real user hit exactly that outcome on 0.2.122.

commit_probation was never broken. It fires at exactly 60s on every healthy boot, and this PR changes no rollback decision, threshold, or state transition. What was broken is that you could not see it from where the report was written.

Under the shipped systemd deployment the node's tracing output goes to the rolling log files under the log dir (the console layer is added only when stdout is a terminal, which it is not under a service manager), while the unit records StandardOutput=journal / StandardError=journal. The three other decisions in this flow — the crash count, the rollback, and rollback-unavailable — are all eprintln! in commands::update, so they reach the journal. The commit that disarms them did not. journalctl -u freenet therefore showed strikes accumulating against a probationary version and never once showed a commit.

Evidence that the commit does work, from the same node the issue was filed against, in ~/.local/state/freenet/freenet.*.log and absent from that host's journal:

2026-08-05T13:53:29Z INFO freenet::commands::rollback: Auto-update probation passed ... version="0.2.119"
2026-08-05T17:50:40Z INFO ... version="0.2.120"
2026-08-07T23:25:54Z INFO ... version="0.2.121"
2026-08-08T02:43:00Z INFO ... version="0.2.122"

Four commits, one per version, each exactly 60s after that boot's start banner. Confirmed independently by running the real binary with an armed marker in a scratch HOME: the marker is removed at ~65s.

The issue's other two observations resolve the same way. The 1/3 seen twice was two different nodes: that host's boot banners show 23:15:18Z version="0.2.120" and 23:24:54Z version="0.2.121", so the node that stopped was 0.2.120 while the ExecStopPost binary matching the marker was 0.2.121 — a hand-driven test bench with the binary swapped underneath, not a counter that resets. And the marker and build_info::VERSION strings match exactly (0.2.121 both sides), so the v-prefix concern does not apply here.

Solution

Announce both marker-clearing outcomes on stderr, alongside the decisions they cancel. One line per node start at most, and only when a probation marker exists. The wording lives in commit_announcement, a pure function over CommitOutcome, so both branches are unit-testable — commit_probation itself reads the process-global $HOME and cannot be driven from a test.

Scope note, stated plainly because it goes beyond the reported symptom: the ClearedStale branch is also escalated, from debug! (compiled out of release builds by release_max_level_info, so it was completely silent in the field) to warn! plus the stderr line. That branch discards a marker belonging to a different version without committing anything, so rollback protection for that version disappears. It is indistinguishable from a healthy commit by the state directory alone — both just delete the marker — and it is the branch a version-comparison regression would take, the #5104 v-prefix class.

One case is deliberately left alone and now documented rather than changed: a node parked by freenet service disable (run_disabled_idle) returns before the commit timer is spawned and keeps its marker until the 1h TTL retires it. Committing there would disarm rollback on evidence the mechanism does not have — that process never joined the network, so it has not demonstrated the health probation is testing for.

Testing

crates/core/tests/post_update_probation_commit.rs spawns the real freenet network binary with its own HOME and covers both halves of the contract:

Test	Asserts	Runtime
probation_is_committed_after_a_healthy_uptime_window	up past the window ⇒ marker gone, commit announced on stderr, and the following post-stop freenet update records no crash	~65s
probation_survives_a_stop_inside_the_commit_window	stopped inside the window ⇒ marker retained, the stop IS counted 1/3, and crash_count is persisted	~15s

Three deliberate choices, each load-bearing:

• It drives the real binary. The commit is not a property of commit_probation_at, which is already unit-tested and correct. It is a property of its only caller — a GlobalExecutor::spawn in run_network_node_with_signals that nothing awaits or monitors. A unit test on commit_probation_at passes happily while that task never runs. commands::rollback also lives in the bin crate behind a $HOME-derived state dir, so no in-process harness can reach it.
• It asserts stderr, not the log files. Asserting the log file would pass on a build where the journal is silent again, i.e. it would not hold this fix. (CI also sets RUST_LOG=error, which filters the tracing::info! out entirely.)
• The second test is the positive control for the first. "No crash was recorded" is a negative assertion on a subprocess's stderr, and the preceding assertion has already established the marker is gone — so on its own it could not fail, and would equally have passed with a misspelled FREENET_POST_STOP_EXIT_CODE, a HOME that did not relocate the state dir, an unparseable fixture, or a reworded needle. The in-window test forces the same fixture, env var and needle to produce a crash line. It is also the half that produced the user-visible rollback in Post-update probation commit is invisible in the journal, and has no regression test #5232 (three fast restarts), and it makes no network call — the crash branch exits before freenet update probes GitHub.

Mutation-tested; each of these fails the suite:

Mutation	Result
Delete the commit_probation call (the failure #5232 hypothesised)	FAILED
v-prefix version mismatch — marker removed as stale, never committed	FAILED
Revert this PR's eprintln (tracing-only, pre-fix state)	FAILED

The second is the one that matters for test design: the marker is removed, so a file-existence check alone would have passed it while rollback protection was silently gone.

rollback.rs::tests::both_marker_clearing_outcomes_are_announced pins both announcement strings (and the silent Nothing case) in microseconds, so a reword fails there rather than after the 60s window.

nextest override: 300s period, retries = 0. Retrying brick-safety equipment would turn "the commit sometimes does not happen" — the exact bug class #5232 was filed about — back into a green run.

A worked example of the failure mode this area keeps producing

Worth reading even if you skim the rest, because it happened inside the fix.

commit_probation announces "committed, auto-rollback disarmed". remove_probation_at discarded its remove_file result, so that line printed whether or not the marker was actually gone — and a failed unlink leaves rollback armed inside its 1h TTL. The fix for a misleading journal was itself capable of misleading the journal.

Fixing that introduced a second instance. The new ClearFailed message began "post-update probation passed, but the marker could NOT be removed…" — which contains the exact substring the end-to-end test greps for to conclude the node committed. A failed clear would have passed the guard while rollback was still armed: the same false-green, one level up, inside the test written to prevent it.

Both are now closed: commit_probation_at reports ClearFailed instead of a false Committed, the e2e keys on "committed, auto-rollback disarmed" which only the success branch can produce, and a unit test pins the two disjoint in both directions.

The pattern to watch for: a success signal and a failure signal that share a substring, or a message emitted before the state change it describes. Both produce a green check over a broken invariant.

Review

Three independent lenses (skeptical, testing, code-first). No blocking findings; every should-fix is addressed in the second commit, including several assertions that could not fail, three comments that described things that were not true, a poll that raced the announcement, and the missing ClearedStale coverage.

Not in scope

• Graceful shutdown exits 1, so a clean systemctl stop is counted as a crash and can trigger auto-rollback #5227 (a graceful shutdown exits 1, so it is scored as a crash) is the real cause of the user-visible rollback and is fixed separately in fix(node): exit 0 on a requested graceful shutdown #5230. Rolling back needs three crashes recorded while the marker is alive, and the marker dies 60s into the first healthy boot — so it takes three stops each inside a 60s window, which is a fast restart loop, which is what that user's StartLimitBurst trip says they had.
• Nodes on ≤0.2.121 log Startup update check: failed to parse latest version 'v0.2.121', so update detection is dead there and a node already rolled back onto one cannot auto-update out of it. Separate issue, separately owned. (The known-bad pin is not the trap: it is exact-version, so a newer release is never blocked by it.)

Refs #5232

[AI-assisted - Claude]

[github-actions]

Rule Review: fix(rollback) probation announcement — no blocking issues

Rules checked: git-workflow.md, code-style.md, testing.md
Files reviewed: 3 (.config/nextest.toml, crates/core/src/bin/commands/rollback.rs, crates/core/tests/post_update_probation_commit.rs)

The diff is a focused fix: change (post-update probation clear failures were silently swallowed and never announced) with regression tests at both the unit level (rollback.rs::tests) and end-to-end level (new post_update_probation_commit.rs, gated correctly with retries = 0 in the nextest CI profile to avoid laundering the exact flake class the PR fixes). All new CommitOutcome match sites are exhaustive with no catch-all _ => arms, no .unwrap()/.expect() appear in non-test code, and the remove_probation_at signature change to io::Result<()> is handled via explicit match/if-let at every call site rather than blind unwraps.

Warnings

None.

Info

• crates/core/src/bin/commands/rollback.rs:643-651 — The Some(state) (different-version/"stale marker") branch's new ClearFailed path (removal fails while clearing a stale marker) isn't exercised directly by a test; only the same-version Committed→ClearFailed transition is covered by an_unremovable_marker_reports_clear_failed_not_committed. The two branches share identical error-handling logic, so risk is low, but a boundary/state-transition test for that arm would close the gap per the testing.md "state transitions" edge-case guidance.
• crates/core/src/bin/commands/rollback.rs:583-611 — commit_probation matches over outcome twice: once implicitly inside commit_announcement, once explicitly for the tracing::*! calls. Not a correctness issue, just a minor duplication that could be folded into one match if ever revisited.

---

Rule review against .claude/rules/. WARNING findings block merge.

[sanity]

Review: three independent lenses, all findings addressed

Ran three blind reviewers on ac704ebc0 — skeptical (adversarial bug hunt), testing (coverage and vacuity), and code-first (code before description, to catch claim/implementation drift). No blocking findings. Every should-fix is addressed in 9aa196af8; the dismissals are below with reasons.

Fixed

Assertions that could not fail. All three lenses independently flagged that "no crash was recorded" was unfalsifiable: it is a negative on a subprocess's stderr, and the preceding assertion had already established the marker was gone. It would equally have passed with a misspelled FREENET_POST_STOP_EXIT_CODE, a HOME that did not relocate the state dir, an unparseable fixture, or a reworded needle. probation_survives_a_stop_inside_the_commit_window is now the positive control, and it also covers the untested half of the contract — a stop INSIDE the window keeps rollback armed, which is the half that produced the user-visible rollback. ~15s, no network call.

ClearedStale had no coverage, despite this PR arguing it is the more dangerous branch. The wording moved into commit_announcement, a pure function over CommitOutcome, with a unit test over both branches plus the silent Nothing. Microseconds instead of a second 60s node boot.

A race between the commit poll and the announcement. commit_probation_at deletes the marker before commit_probation prints, so polling the file could observe "gone" microseconds before the line landed, then read stderr exactly once. It now polls the announcement itself. The skeptical lens added the corollary, which is now a comment in the source: do NOT "fix" this by printing before the removal — eprintln! panics on EPIPE, and a panic in front of the state transition would leave a healthy node's marker armed, turning an observability line into a rollback bug.

Three comments that described things that are not true. The other stderr prints are in commands::update and there are three, not two in this module; the commit task's handle is retained and aborted, not dropped; and arm_probation claimed a fixture re-read that does not exist.

An overstated claim. "tracing goes to the log files" holds under the shipped systemd deployment but not for the fallback tracer (no log dir resolvable, or FREENET_LOG_TO_STDERR), which writes to stdout. Since this PR is meant to be the permanent record of why #5232's evidence was misread, that is now qualified.

run_disabled_idle never commits — a genuine gap in the original "every healthy boot" claim, found by the skeptical lens. Documented rather than changed, deliberately: a node parked by freenet service disable never joined the network, so it has not demonstrated the health probation tests for, and committing there would disarm rollback on evidence the mechanism does not have. The 1h TTL retires the marker instead. Bounded in the meantime — an idle node's systemctl stop exits 0, which is NotCrash.

Diagnostics and robustness. The commit deadline now starts when the WS API answers rather than at spawn, so a slow cold start cannot be reported as "the marker is still armed". Failure messages carry the node's exit status and stderr — a port collision or a rejected flag reports itself there, often before tracing is initialised, so the previous diagnostic printed the one file guaranteed to be empty. A stale target/debug/freenet predating a version bump now fails a version precondition instead of taking the ClearedStale branch and looking like a rollback bug. --log-dir points at the state dir, matching production on Linux where the log pruner and the marker share a directory. The shutdown wait is bounded.

nextest override: 300s period, retries = 0. Retrying brick-safety equipment would turn "the commit sometimes does not happen" back into a green run.

Re-mutated after the rework

The suite changed substantially, so the mutation testing was redone. The two tests now fail on disjoint mutations, which is the property worth having — neither is redundant, and the positive control genuinely can fail:

Mutation	committed test	in-window test
Remove the stderr announcement (pre-fix state)	FAILED	ok
classify_stop: status 1 no longer a crash	ok	FAILED

Plus the two from the first round, both still fatal: deleting the commit_probation call, and a v-prefix mismatch where the marker is removed as stale and never committed.

Not taken

• env!("CARGO_BIN_EXE_freenet") instead of the target_dir() helper (two lenses, as a nit). Correct in principle, but persistence_roundtrip.rs and fdev_publish_e2e.rs use the same helper, and changing one of three is worse than changing none. The concrete hazard it guards — a stale binary — is now caught by the version precondition. Worth a follow-up across all three.
• Parameterising the 60s window so the test runs in ~10s (testing lens, raised as a fork in the road rather than a finding). Declining: it puts a new env knob on a brick-safety path and stops exercising the constant at its production value. The cheap test now carries the fixture-canary role that motivated most of the speed argument.
• TCP-reserved port handed to a UDP listener — pre-existing house pattern; the improved diagnostics mean a collision now reports itself as a collision.

[AI-assisted - Claude]

[sanity]

Rebased onto 0.2.123, re-reviewed, re-verified

Force-pushed 9aa196af8 → c6dcd3418. The branch was CONFLICTING after #5230 and the 0.2.123 release landed on main. Because a rebase with a conflict resolution restales both the review and CI, here is what was re-done rather than assumed.

The conflict was in .config/nextest.toml: #5230 added a retries = 0 override for graceful_shutdown_on_sigterm_exits_zero at the same anchor where this branch adds one for the probation tests. Resolved by keeping both — they are independent, non-overlapping filters. A reviewer confirmed both blocks are byte-identical to their respective sides, no markers remain, the TOML is valid, and the two filter expressions neither overlap nor shadow (and the probation regex does not accidentally match probation_roundtrip_and_commit in rollback.rs).

#5230 changes the ground this test stood on, so that got the real scrutiny. A graceful shutdown now exits 0, and classify_stop short-circuits "0" to NotCrash before handle_post_stop_at ever reads the marker. Both tests forward FREENET_POST_STOP_EXIT_CODE=1 explicitly rather than the observed status, which was written as future-proofing and turns out to be load-bearing: forwarding the real status would now mean neither test touched the probation logic at all, and the in-window test would lose its ability to fail entirely.

The assertions were already right. Three pieces of prose were not, and c6dcd3418 fixes them — they had been written against the old behaviour and stated its opposite:

• post_stop_update's rationale said 1 is "what a graceful shutdown exits with today" and hedged about Graceful shutdown exits 1, so a clean systemctl stop is counted as a crash and can trigger auto-rollback #5227's fix landing. It has landed.
• The module doc credited the user-visible rollback to "three fast restarts". Post-fix(node): exit 0 on a requested graceful shutdown #5230 ordinary restarts no longer accumulate strikes, and this PR's own "Not in scope" section already said Graceful shutdown exits 1, so a clean systemctl stop is counted as a crash and can trigger auto-rollback #5227 was the cause. They now agree.
• "the stop IS counted" merged two separable claims. The test asserts both and now distinguishes them: marker retention is demonstrated by a real graceful stop, the 1/3 counting by a forwarded crash status.

Also checked: #5230 does not touch rollback.rs, so there was no semantic collision for the rebase to reconcile silently; classify_stop is unchanged by both sides; and MIN_HEALTHY_UPTIME_FOR_UPDATE_EXIT, which COMMIT_HEALTHY_UPTIME_SECS mirrors, was not modified.

The 0.2.123 bump lines up: NODE_VERSION, build_info::VERSION, and the planted marker all resolve to the same env!("CARGO_PKG_VERSION") of the same package, so Committed stays reachable and ClearedStale is not spuriously triggered. assert_binary_matches_crate_version() is doing real work on a just-bumped base — a target/debug/freenet built before the bump reports 0.2.122, would take the ClearedStale branch, and would otherwise fail as "rollback regression" instead of "rebuild your binary".

Re-verified locally on the rebased head: cargo fmt --check clean, the 31 rollback:: unit tests pass, and both integration tests pass against a freshly built 0.2.123 binary (65s).

[AI-assisted - Claude]

[sanity]

Rebased, plus: the new message could lie, and now cannot

Force-pushed c6dcd3418 → 8cd407b3e. Rebase onto main was a clean fast-forward (no conflicts, no mid-sequence edits), so the earlier review stands on the replayed commits; the new commit is reviewed below on its own terms.

The problem with the message this PR adds

remove_probation_at discarded its remove_file result, so commit_probation printed "committed, auto-rollback disarmed" whether or not the marker was actually gone. A failed unlink leaves the marker armed and inside its 1h TTL, so an ordinary crash in the next hour can still roll the node back off a version it was just told had passed — and the commit timer fires once per process, so nothing retries.

That would have reintroduced the misleading-journal problem at the exact moment of fixing it. The trigger is a read-only or full state directory, which is the same fleet condition behind #5244.

remove_probation_at now returns io::Result — "already absent" counts as success, since the post-condition is "no marker", not "I deleted something" — and commit_probation_at reports a new ClearFailed outcome instead of a false Committed. Its announcement says the marker survived, names the cause, and points at the state directory.

The other removal sites still drop the result, but now explicitly and with the reason bound in the name: the stale-version and TTL branches are not announced and re-attempt the removal on the next stop, and the post-rollback one self-heals because the restored binary's next stop sees a version mismatch and takes the stale branch. Surfacing those properly needs an output channel this process does not have — that is #5244.

A false-green this nearly shipped

The ClearFailed line originally began "post-update probation passed, but the marker … could NOT be removed". That contains the substring the end-to-end test greps for to conclude the node committed. A failed clear would have sailed through that guard while rollback was still armed — the precise false-green this PR exists to prevent, one level up.

The e2e now keys on "committed, auto-rollback disarmed", which only the success branch can produce, and a_failed_clear_is_never_announced_as_a_pass pins the two disjoint in both directions so neither can drift into the other.

Tests

• a_failed_clear_is_never_announced_as_a_pass — the line says STILL ARMED, names the cause, never says "disarmed", and does not contain the e2e's success needle.
• an_unremovable_marker_reports_clear_failed_not_committed — drives commit_probation_at against a marker in a read-only directory and asserts the outcome is not Committed. Skips when running as root, which bypasses the directory permission check; skipping is honest where the test would otherwise be vacuous rather than passing.
• removing_an_absent_marker_succeeds — an idempotent re-commit must not raise a spurious ClearFailed.

34 rollback:: unit tests and both integration tests pass locally; cargo fmt --check and clippy clean.

Related: #5244, filed for the structural cause — the freenet update process installs no tracing subscriber at all, so every tracing::* call in it is a no-op, and an update can install with rollback protection never armed and no trace anywhere.

[AI-assisted - Claude]