diff --git a/.claude/rules/bug-prevention-patterns.md b/.claude/rules/bug-prevention-patterns.md index 8757d22696..75733054bc 100644 --- a/.claude/rules/bug-prevention-patterns.md +++ b/.claude/rules/bug-prevention-patterns.md @@ -1,6 +1,7 @@ --- paths: - "crates/core/src/bin/**" + - "scripts/**" --- # Bug Prevention Patterns (freenet-core) @@ -59,6 +60,103 @@ A future revert of any of these null-stdio calls fails CI with a specific, issue-numbered error message rather than shipping the regression silently. +## Log markers that a CI gate greps for + +A gate that decides whether a release ships by grepping the node's log is only +as real as the marker it greps for. Two independent mechanisms silently turn +such a gate into one that cannot fail, and #5236 hit both at once — in the +canary whose entire purpose was to stop a vacuous release signal. + +**1. Level.** `crates/core/Cargo.toml:124` enables tracing's +`release_max_level_info`, which compiles out everything below INFO *in release +builds*. A `debug!` marker therefore does not exist in the binary the gate +inspects. It is present in every debug build, so it looks fine locally and in +any test that runs a debug binary; the gate observes nothing and can only pass +vacuously. The `Startup update check complete` marker was a `debug!`, which made +the most common healthy outcome ("finished, staying on this version") produce no +log ending at all — byte-for-byte indistinguishable from a node killed +mid-request. + +**2. Anchor.** A whole-file `grep -F` for the marker is satisfied by ANY +occurrence in the file, including a `//` comment — very often one inside the +file's own `#[cfg(test)] mod tests` block, where log excerpts get pasted as +documentation. The source pin then tracks the comment, not the code. + +| Marker | How it broke | +|--------|--------------| +| `Startup update check complete` | Emitted at `debug!`, so absent from every release binary. The canary's "did the check finish?" assertion could never observe it. | +| `failed to parse latest version` | Occurs twice in `auto_update.rs`: the production `tracing::warn!` (the format literal `Startup update check: failed to parse latest version '{}'`) and a prose comment inside that file's own `#[cfg(test)] mod tests` (`// WARN failed to parse latest version 'v0.2.121':`). Both are quoted rather than cited by line number on purpose — the first version of this row cited `:1546`/`:1757`, which this very commit's +23 lines had already shifted to `:1569`/`:1780`. A line number in a rule about stale pins rots faster than the thing it describes. Rewording the production line left all 22 assertions green — including `ok - source pin: parse-failure marker` — while a node carrying the #5221 bug then logged check-ran + reworded-warn + check-complete and the canary reported `OK: parsed GitHub's response`. An ordinary log reword deletes the gate, with CI green throughout. | +| (no marker at all) | The gate had nothing to say WHICH release the node compared against, so its healthy verdict was byte-identical to a silently-wrong comparator's — see the positive-fact rule below. Closed by `MARKER_LATEST_SEEN`. | +| `triggering auto-update` | A fixed string, so it never matched `freenet.rs:609`'s "triggering IMMEDIATE auto-update". A node that took the urgent path read as one that never decided to update, for as long as that site had existed. Fail-closed, hence unnoticed. Closed by `MARKER_TRIGGERED_RE` plus a count pin. | + +### The rule + +- Emit any gate-observed marker at **`info!` or above**. Never `debug!`/`trace!`. +- **Pin the emitting call, not the file.** Match the macro together with its + literal (`tracing::warn!("`), whitespace-stripped on both sides so a + rustfmt reflow cannot disarm it. A bare file grep is satisfied by prose. +- **Pin every arm that shares the marker.** `compare_versions_for_startup` has + two parse-failure arms; a pin on one lets the other drift. +- Prefer a marker string that is **specific enough not to appear in prose** — + keeping the `Startup update check: ` prefix is what stops the test-module + comment quoted above from matching at all. +- **Assert a POSITIVE fact, not the absence of an error.** "No error appeared" + is satisfied by a component that is silently WRONG as well as by one that + works: a `version_from_tag` regressed to a constant, or a normaliser + truncating `0.2.121` to `0.2.12`, parses, compares, declines to update and + logs a clean completion — a log byte-identical to a healthy node's. Make the + code log the value it acted on, and have the gate compare it against an + independently-obtained expected value. Resolve that expected value from the + **same source the code uses** (here, the `releases/latest` redirect, not + `api.github.com`): two sources that are allowed to disagree produce failures + that are not bugs. +- **Pin the COUNT when a marker is supposed to match a SET of call sites.** A + fixed-string `MARKER_TRIGGERED` missed `freenet.rs:609` ("triggering + IMMEDIATE auto-update") for as long as that site existed, so a node taking + the urgent path read as one that never decided to update. It failed CLOSED, + which is exactly why nobody noticed — **fail-closed is not the same as + correct, and it is the condition under which a wrong enumeration survives + longest.** But **the count must not be derived from the marker it audits.** + The first version of that pin computed the actual site count as + `grep -cE "$MARKER_TRIGGERED_RE"` — the very regex under audit — so a site + the regex failed to match was missing from the count too, and the two errors + cancelled. Demonstrated: adding a sixth trigger site worded "triggering a + fresh auto-update" left the suite fully green, including the assertion + claiming exactly five sites. It caught a REWORDED existing site (count drops) + and nothing else, which is the weaker half of what it advertised. Derive the + expected count from a **structural** anchor the marker cannot influence — + here `update_tx.send(new_version)`, the call that actually requests the + update — then assert the marker matches all of them. Same shape as the + "metric re-derived at the call site" row below: an audit whose two operands + come from one source cannot report a disagreement. +- **A skip branch in a gate is a vacuous-pass waiting to happen.** If the gate + can only run its check when some input is present, pin the caller that + supplies it. `assert_detection_healthy` skips the equality check when + `CANARY_EXPECTED_LATEST` is unset — correct for keeping the function pure and + fixture-testable, but it makes the check only as real as `cmd_preflight`, so + that assignment is itself pinned. + +### Audit + +Every marker a script greps for must resolve to production code at every +occurrence, and its pin must be mutation-tested by rewording the real call and +confirming the pin goes RED. + +```bash +grep -n '^MARKER_' scripts/auto-update-canary.sh +# then, for each marker, confirm no occurrence is a comment: +grep -n "" crates/core/src/bin/commands/auto_update.rs \ + crates/core/src/bin/freenet.rs +``` + +Source-level regression pins live in +`scripts/auto-update-canary_test.sh`: `pin_warn_literal` for the parse-failure +arms, the INFO-level checks on `MARKER_CHECK_COMPLETE` and +`MARKER_LATEST_SEEN`, the trigger-site COUNT pin, and the pin that +`cmd_preflight` still arms the equality check. The gate's own WIRING — that the +canary still runs, and still runs before `--draft=false` — is pinned by +`scripts/release_canary_wiring_test.sh`. + ## Self-satisfying `include_str!` source-scrape pins A source-scrape pin — a test that `include_str!`s its own crate's source @@ -106,3 +204,112 @@ not known to work. ```bash grep -rn 'include_str!("' crates/core/src/bin/ | grep -v assets ``` + +## SIGPIPE under `pipefail`: a present marker reads as absent + +In a script that sets `set -o pipefail`, piping a producer into a consumer that +**short-circuits** — `grep -q`, `head -n`, `read` — makes the producer die with +SIGPIPE (exit 141) as soon as the consumer stops reading. `pipefail` then +promotes 141 to the pipeline's status. So: + +```bash +set -uo pipefail +if printf '%s' "$logs" | grep -qF "$MARKER"; then # WRONG +``` + +reports **false for a marker that is present**. The `if` is not testing whether +the marker is there; it is testing whether the producer finished writing. + +Three properties make this worse than an ordinary bug: + +**It is volume-dependent, so it is intermittent.** Below the 64 KB pipe buffer +the producer finishes before `grep -q` exits and nothing happens. Above it, the +producer is still writing and takes the signal. Every small fixture passes; the +failure waits for a real input. Measured on #5236's canary, same log content +with only trailing volume varied: 1 KB → `rc=0`; 200 KB → `rc=1` with a wrong +diagnosis; a real 3.65 MB node log → `grep -acF` finds the line (count 1) while +the piped `grep -q` exits **141** and the direct `grep -q` exits 0. + +**It corrupts the diagnosis, not just the verdict.** The gate blamed +"the startup update check never ran" — pointing the next reader at auto-update +detection when the fault was a shell pipeline. It hit 2 of 3 real preflight +runs and `cmd_preflight` does not retry an rc=1, so a healthy release was +blocked by an error about the wrong subsystem. + +**Framing decides whether it fires, invisibly.** Whether the consumer can +short-circuit early depends on where the match falls and how the stream is +split into lines, neither of which is visible at the call site. Same file, same +consumer, match on line 1 of a 165 KB source: + +```bash +sed 's/\\$//' "$AU" | grep -qF 'Auto-update' # rc=141 +sed 's/\\$//' "$AU" | tr -d '[:space:]' | grep -qF '…' # rc=0 +``` + +The second is safe only because `tr` deletes every newline, leaving one line +grep must read to EOF before it can report. `pin_marker` depended on that +accident without knowing it — deleting the `tr` as a "simplification" would +have armed the hazard on every source pin in the file at once. + +### Repeat offender history + +| Site | How it broke | +|------|--------------| +| `node_decided_to_update`, `node_check_settled` (`scripts/auto-update-canary.sh`) | Diagnosed and fixed when the mechanism was first found. Latent — canary logs never got large enough. | +| Four checks in `assert_detection_healthy`, same file, same commit | NOT fixed by that pass, and not latent: Gate A's normal path leaves the node logging ~33 KB/s until it is killed seconds later, so the markers sit far behind the buffer. | +| `pin_marker` (`scripts/auto-update-canary_test.sh`) | Safe only by accident of an intervening `tr -d '[:space:]'`, as above. | +| `printf '%s' "$WRONG_OUT" \| grep -qF` (`scripts/auto-update-canary_lifecycle_test.sh`) | Latent; would have reported "the wrong diagnosis" for the right one. | + +### The rule + +**When you fix this, fix every instance in the repo, not the one you were +reading.** That is the actual lesson of #5236: the same commit correctly +diagnosed the mechanism, wrote the explanation down in a comment, fixed two +helpers — and left four call sites inside the very function those helpers +serve. Grep first, fix the set, then write the comment. + +Safe forms, in order of preference: + +- **Grep the file directly** rather than slurping it into a variable and piping + it: `grep -aqF -- "$needle" "$dir"/*.log`. No pipe, no producer to kill. +- **Match the variable with a bash glob**: `[[ "$out" == *"$needle"* ]]`. Also + cheaper than forking grep. +- **Take a count and test it**: `[ "$(grep -acF …)" -gt 0 ]` — the pipeline's + value is used, not its status. +- **`|| true`** where the producer's status genuinely does not matter — but + prefer one of the above, since `|| true` also swallows real errors. + +`head` in a command substitution (`v="$(cmd | head -1)"`) is the same class but +is normally fine: the value is used and the status discarded. It is only a +hazard when something consumes the pipeline's status. + +### Audit + +```bash +# which scripts are exposed at all +grep -ln 'pipefail' scripts/*.sh + +# candidate sites; cross-reference against that list +grep -rnE '\|[[:space:]]*(grep[[:space:]]+-[a-zA-Z]*q|head[[:space:]]|read[[:space:]])' scripts/ +``` + +A hit matters when the pipeline's **status** is consumed — an `if`/`elif`, +`&&`/`||`, a `while` condition, or a function whose last command it is. A hit +whose stdout is captured and whose status is ignored is benign. + +The release-gate scripts that set `pipefail` are pinned against regression by +`scripts/auto-update-canary_test.sh` ("no 'pipe into grep -q' …"), which fails +if the form reappears in any of them. Regression tests in the same file drive +>64 KB fixtures through `assert_detection_healthy` in both directions, since a +small-fixture test cannot see this class at all. + +**The rest of `scripts/` is NOT pinned and has not been audited site by site.** +As of #5236 the greps above return 20 scripts setting `pipefail` and ~69 +candidate sites across all of `scripts/`. Two that look worth a closer read +when someone next touches those files, neither investigated here: +`deploy-to-gateways.sh`'s health check pipes 100 journalctl lines into +`grep -q` and consumes the status, and `deploy-local-gateway.sh` pipes +`systemctl list-unit-files` (47 KB on one ordinary host, and it grows with the +machine) into `grep -q` at five sites. Both would fail in the safe direction — +reporting a healthy service as unhealthy — which is precisely the direction +that survives unnoticed. diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index a8cd9f7a57..e9348eb752 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -185,14 +185,56 @@ jobs: - name: Self-test merge-queue concurrency guard run: bash scripts/merge_group_concurrency_test.sh + # Regression gate for the release driver's cross-compile wait: under + # `set -euo pipefail` a bare `var=$(gh ...)` aborts the whole driver on a + # transient GitHub blip, AFTER the release publishes but BEFORE the + # gateways are updated and the release is announced. Pins that a failing + # `gh` makes the poll loop retry, while a genuinely failed attach job and + # an unknown publish gate still stop the release loudly. + - name: Self-test release wait_for_binaries gh resilience + run: bash scripts/release_wait_for_binaries_test.sh + + # Pins the WIRING of the blocking pre-flight canary, which is what + # makes it a gate at all: it must run inside attach-to-release, after + # the assets upload and BEFORE `gh release edit --draft=false`, and + # not be disabled in place. Also pins release.sh's ATTACH_JOB_NAME + # against the job's name in cross-compile.yml -- the driver polls for + # that string and a rename on either side is otherwise silent. + - name: Self-test release canary wiring + run: bash scripts/release_canary_wiring_test.sh + + # Regression gate for #5221/#5222: auto-update was broken fleet-wide for + # TWO releases (v0.2.120, v0.2.121) and nothing noticed, because every + # signal was one-sided — the release built, published, installed and ran. + # scripts/auto-update-canary.sh is the release canary that catches it; + # this pins its two-sided assertion. The load-bearing cases are the + # VACUOUS ones: a log with no update check, and a node running with + # auto-update disabled, both contain no error line and would sail past a + # "grep for the error" check. Fixtures are verbatim log lines from real + # v0.2.119 (healthy) and v0.2.121 (broken) runs. + - name: Self-test auto-update release canary + run: bash scripts/auto-update-canary_test.sh + + # Lifecycle half of the same canary: drives the real `run_node_until_check` + # and `cmd_preflight` against a FAKE node binary. The pure test above + # cannot see process management, and that is where the two real bugs were + # — a gate that failed even a healthy binary, and a node left running + # after the gate returned (holding its ports, starving the next attempt). + # Case 4 is the load-bearing one: reintroduce the leak and it fails. + - name: Self-test auto-update canary lifecycle + run: bash scripts/auto-update-canary_lifecycle_test.sh + # install.sh now sets up a supervised service by default (issue #4073) so # new nodes auto-update. The system-vs-user + lingering decision is the # load-bearing new logic; these smoke tests pin it without needing real # root/sudo. shellcheck guards the installer/uninstaller scripts too. - name: Install shellcheck run: sudo apt-get update && sudo apt-get install -y shellcheck + # The canary scripts are linted here too. They were claimed shellcheck + # clean when they landed but were not actually in this list, so nothing + # held them to it. `-x` because the two test scripts `source` the canary. - name: Lint install/uninstall scripts (shellcheck) - run: shellcheck scripts/install.sh scripts/uninstall.sh scripts/test-install-sh.sh scripts/test-uninstall-sh.sh + run: shellcheck -x scripts/install.sh scripts/uninstall.sh scripts/test-install-sh.sh scripts/test-uninstall-sh.sh scripts/auto-update-canary.sh scripts/auto-update-canary_test.sh scripts/auto-update-canary_lifecycle_test.sh scripts/release_wait_for_binaries_test.sh scripts/release_canary_wiring_test.sh scripts/release.sh - name: Self-test install.sh service-mode decision run: sh scripts/test-install-sh.sh - name: Self-test uninstall.sh diff --git a/.github/workflows/cross-compile.yml b/.github/workflows/cross-compile.yml index 1f71c7c547..159a5adc67 100644 --- a/.github/workflows/cross-compile.yml +++ b/.github/workflows/cross-compile.yml @@ -361,7 +361,12 @@ jobs: attach-to-release: name: Attach binaries to GitHub release runs-on: ubuntu-latest - timeout-minutes: 10 + # Raised from 10 for the auto-update pre-flight canary (#5222). The job + # itself takes ~40s; the canary adds ~70s on the happy path but up to ~8 + # min if it has to retry an unreachable GitHub. At the old budget a retry + # got the job CANCELLED before the `Publish release` step ran, leaving a + # permanently stuck draft — the exact failure the retry existed to avoid. + timeout-minutes: 25 needs: [build-x86_64-linux, build-arm64-linux, build-arm64-macos, build-x86_64-macos, build-x86_64-windows, build-macos-dmg] if: startsWith(github.ref, 'refs/tags/v') @@ -578,15 +583,175 @@ jobs: gh release upload "$TAG_NAME" $ASSETS \ --repo ${{ github.repository }} \ --clobber + echo "✅ Assets uploaded to draft release $TAG_NAME" + + # --------------------------------------------------------------------- + # Gate A of the auto-update canary (#5222) — BLOCKS PUBLICATION. + # + # #5104 made the node's release-tag fetch return the tag verbatim + # ("v0.2.121") and normalised it at only one of its two consumers. The + # DETECTION path kept the raw tag, semver parsing failed, and auto-update + # was dead fleet-wide for v0.2.120 AND v0.2.121 — silently, for two + # releases, until ~1,100 nodes had to be updated by hand. A broken + # updater cannot deliver its own fix, which is what makes this class of + # bug worth a blocking gate rather than a report. + # + # This runs the binary we are ABOUT to ship and asserts its updater can + # read GitHub's current release tag. It sits here, between upload and + # un-draft, deliberately: + # - the assets exist, so we are testing the real artifact; + # - the release is still a DRAFT, so nothing has reached a user yet and + # a failure costs us a stuck draft rather than a broken fleet; + # - it is a `needs`-chained step, not a `release: published` listener, + # so it cannot silently stop running if RELEASE_PAT lapses (that + # token already suppresses downstream events when unset — see #4118). + # + # It adds ~1 minute: the node's startup check fires after a 0-60s jitter + # and the script returns as soon as it has a verdict. + # + # IF THIS FAILS: the release stays an unpublished draft, which is the + # correct fail-closed state. Do NOT un-draft it by hand to "unblock" the + # release — the updater in that binary is broken and publishing it + # strands the fleet on the previous version. Fix the detection path on + # the release branch, then re-run this workflow for the tag. + # --------------------------------------------------------------------- + # This job downloads artifacts and never checks out the repo, so the + # canary script is not on disk. Sparse-checkout just that one file into + # its own subdirectory: `actions/checkout` cleans its target path, and + # the release assets live in the workspace ROOT, so scoping the path is + # what keeps this from wiping the very artifacts we are about to publish. + # The default ref for a tag push is the tag itself, so the script version + # matches the release it is gating. + - name: Check out the canary script + uses: actions/checkout@v7 + with: + path: _canary + sparse-checkout: scripts/auto-update-canary.sh + sparse-checkout-cone-mode: false + + - name: Auto-update pre-flight canary (blocks publish) + # Step-level bound so a hung canary is reported as the canary timing + # out, not as the whole publish job dying for unclear reasons. + timeout-minutes: 12 + run: | + tar xzf freenet-x86_64-unknown-linux-musl.tar.gz -C /tmp + chmod +x /tmp/freenet + bash _canary/scripts/auto-update-canary.sh preflight /tmp/freenet - # Publish the release now that binaries are attached. - # The release is created as a draft by release.sh/release.yml to - # prevent the installer from seeing a version before binaries exist. + - name: Publish release + env: + # Coalesce on RELEASE_PAT so `--draft=false` fires a + # `release.published` event that downstream workflows + # (`gateway-update.yml`, `release-announce.yml`) can react to. + # GITHUB_TOKEN suppresses workflow-triggering events as an + # anti-recursion safeguard, which broke the v0.2.57 release cascade + # and required manual `workflow_dispatch`. See issue #4118 and + # `AGENTS.md` → "Release Workflow & RELEASE_PAT". + GH_TOKEN: ${{ secrets.RELEASE_PAT || secrets.GITHUB_TOKEN }} + run: | + TAG_NAME="${GITHUB_REF#refs/tags/}" + # Publish the release now that binaries are attached AND the shipping + # binary's updater has been verified. The release is created as a + # draft by release.sh/release.yml to prevent the installer from + # seeing a version before binaries exist. gh release edit "$TAG_NAME" \ --repo ${{ github.repository }} \ --draft=false echo "✅ Release $TAG_NAME published with all binaries attached" + # ----------------------------------------------------------------------- + # Gate B of the auto-update canary (#5222) — end-to-end, after publication. + # + # Gate A proved the binary we shipped can PARSE GitHub's release tags. This + # proves the transition that actually matters to the fleet: a node on the + # PREVIOUS release detects this one, exits 42, and self-replaces via + # `freenet update`. Not "the log looks right" but "the old version ends up + # on the new one". + # + # It necessarily runs AFTER publication: the node's detection path is + # hardwired to GitHub's `/releases/latest`, and a draft release does not + # appear there, so there is no way to exercise the real path earlier. That + # is why Gate A exists as the blocking half — this one is the alarm. + # + # A failure here means the fleet will NOT converge onto this release on its + # own. The release is already public at that point, so the job is red and + # notifies rather than blocking; the response is to ship a fix and/or roll + # the fleet by hand, exactly as v0.2.120/v0.2.121 required. + # ----------------------------------------------------------------------- + auto-update-selfupdate-canary: + name: Auto-update self-update canary (previous release -> this one) + runs-on: ubuntu-latest + timeout-minutes: 20 + needs: attach-to-release + if: startsWith(github.ref, 'refs/tags/v') + permissions: + contents: read + steps: + - uses: actions/checkout@v7 + + - name: Resolve the previous published release + id: prev + env: + GH_TOKEN: ${{ secrets.GITHUB_TOKEN }} # coalesce-exempt: read-only `gh api` release listing; emits no downstream event + run: | + set -euo pipefail + TAG_NAME="${GITHUB_REF#refs/tags/}" + THIS_VERSION="${TAG_NAME#v}" + # Newest published, non-draft, non-prerelease release that is not the + # one we just cut. Drafts and prereleases are excluded because the + # fleet never runs them, so they are not the version we need to prove + # a transition from. + PREV_TAG=$(gh api "repos/${{ github.repository }}/releases?per_page=30" \ + --jq "[.[] | select(.draft==false and .prerelease==false) | .tag_name] + | map(select(. != \"$TAG_NAME\")) | .[0] // empty") + if [ -z "$PREV_TAG" ]; then + echo "::error::could not resolve a previous published release to canary from." + exit 1 + fi + echo "this_version=$THIS_VERSION" >> "$GITHUB_OUTPUT" + echo "prev_version=${PREV_TAG#v}" >> "$GITHUB_OUTPUT" + echo "Canarying ${PREV_TAG} -> ${TAG_NAME}" + + - name: Previous release self-updates to this release + run: | + bash scripts/auto-update-canary.sh selfupdate \ + "${{ steps.prev.outputs.prev_version }}" \ + "${{ steps.prev.outputs.this_version }}" + + # A red job in a release run is the primary signal, but nobody is guaranteed + # to be watching Actions at release time — and a silent fail-closed is + # indistinguishable from working. Mirror it into the dev room. + # Covers BOTH gates. An earlier revision hung this off Gate B alone, which + # left the BLOCKING gate silent: a Gate A failure fails `attach-to-release`, + # which SKIPS Gate B, so `needs.auto-update-selfupdate-canary.result` is + # 'skipped' and no message went out — leaving a release stuck as an + # unpublished draft with nobody told. That is precisely the + # silent-fail-closed shape this whole change exists to remove. + notify-auto-update-canary-failure: + name: Notify dev room if the release pre-flight failed + runs-on: ubuntu-latest + timeout-minutes: 20 + needs: [attach-to-release, auto-update-selfupdate-canary] + if: | + always() && startsWith(github.ref, 'refs/tags/v') && + (needs.attach-to-release.result == 'failure' || + needs.attach-to-release.result == 'cancelled' || + needs.auto-update-selfupdate-canary.result == 'failure' || + needs.auto-update-selfupdate-canary.result == 'cancelled') + continue-on-error: true + steps: + - uses: actions/checkout@v7 + - uses: ./.github/actions/river-dev-notify + with: + # Deliberately does NOT assert which failure happened. The job can be + # red because the updater is broken OR because GitHub was unreachable, + # and a message that overstates ("the fleet is stranded") on a network + # blip trains people to ignore the channel. + message: "\U0001F6A8 RELEASE PRE-FLIGHT did not pass for ${{ github.ref_name }} (publish job: ${{ needs.attach-to-release.result }}, auto-update self-update canary: ${{ needs.auto-update-selfupdate-canary.result }}). Check WHICH step failed before concluding anything: the publish job also does artifact download, checksumming and signing, so a red result here is not by itself an auto-update fault. If the publish job failed, the release is STUCK AS A DRAFT and needs a decision. If the self-update canary failed, a node on the previous release may not be able to auto-update to this one (#5221 failure mode — the fleet would need `freenet update` by hand). ${{ github.server_url }}/${{ github.repository }}/actions/runs/${{ github.run_id }}" + bot-config: ${{ secrets.RIVER_DEV_BOT_CONFIG }} + room-id: ${{ secrets.RIVER_DEV_ROOM_ID }} + gateway-url: ${{ secrets.RIVER_GATEWAY_URL }} + verify-signing-key: name: Verify release signing key (dry-run) runs-on: ubuntu-latest diff --git a/crates/core/src/bin/commands/auto_update.rs b/crates/core/src/bin/commands/auto_update.rs index 5724eafc52..b24c100414 100644 --- a/crates/core/src/bin/commands/auto_update.rs +++ b/crates/core/src/bin/commands/auto_update.rs @@ -1519,6 +1519,29 @@ where return None; } }; + // The OBSERVED half of the check, as distinct from the DECISION. + // + // Every other line on this path reports what the node decided; none reports + // what it was deciding ABOUT. That left the release canary (#5236) able to + // assert only the ABSENCE of an error, and absence is satisfied by a + // comparator that is silently wrong rather than loudly broken: a + // `version_from_tag` that regressed to a constant, or a normaliser that + // truncated `0.2.121` to `0.2.12`, still parses, still compares, still + // declines to update, and still logs a clean completion. The log was + // byte-identical to a healthy one, so Gate A could not tell them apart. + // + // Emitting the value makes the gate's assertion POSITIVE: the canary + // compares this against the tag GitHub actually published and fails on a + // mismatch. INFO, not `debug!` -- release builds set + // `release_max_level_info`, so a `debug!` here would not exist in the + // binary the gate inspects (the mistake that made the completion marker + // unobservable in the first place). `scripts/auto-update-canary.sh` greps + // for this text and `scripts/auto-update-canary_test.sh` pins it against + // this call, so do not reword it without updating both. + tracing::info!( + latest = %latest, + "Startup update check: GitHub reports latest release" + ); compare_versions_for_startup(current_version, &latest) } diff --git a/crates/core/src/bin/freenet.rs b/crates/core/src/bin/freenet.rs index 83261fa712..708f74548b 100644 --- a/crates/core/src/bin/freenet.rs +++ b/crates/core/src/bin/freenet.rs @@ -540,7 +540,27 @@ async fn run_network_node_with_signals( return; } } - tracing::debug!("Startup update check: no newer version found"); + // INFO, not `debug!`: release builds set `release_max_level_info` + // (crates/core/Cargo.toml), so a `debug!` here is compiled OUT of every + // shipped binary. That left the startup check with no observable ENDING + // on the outcome it takes most often. "The check finished and decided to + // stay put" looked exactly like "the check was killed mid-request", and + // the release canary (#5222) cannot pass a binary safely without telling + // those apart: absence of a parse error is evidence that parsing worked + // only if the check is known to have finished. Without this line Gate A + // would wave through a binary carrying the #5221 bug whenever GitHub + // answered slowly enough that the canary stopped the node first. + // + // Reached on EVERY non-triggering outcome -- already up to date, GitHub + // unreachable, unparseable tag, #4073 locally-blocked version -- so it + // claims only that the check ended. The WARN above it, if any, says why. + // Do not reword it into a claim about the version, and do not change the + // leading phrase: scripts/auto-update-canary.sh greps for it, and + // scripts/auto-update-canary_test.sh pins it against this file. + tracing::info!( + current = build_info::VERSION, + "Startup update check complete: staying on the current version" + ); /// Parse our version string into a (major, minor, patch) tuple for comparison. fn parse_our_version() -> Option<(u8, u8, u16)> { diff --git a/docs/RELEASING.md b/docs/RELEASING.md index c39ac039a5..37c68601e4 100644 --- a/docs/RELEASING.md +++ b/docs/RELEASING.md @@ -452,6 +452,193 @@ when invoked directly, the agent doesn't. Set both if you ever need to run `release.sh` while the workflow is also in play. +## Auto-update canary (#5222) + +Auto-update was broken fleet-wide for **two consecutive releases** (v0.2.120 +and v0.2.121) without anything noticing. #5104 made the node's release-tag +fetch return the tag verbatim (`v0.2.121`) and normalised it at only one of its +two consumers; the detection path kept the raw tag, `semver` parsing failed, +and every update was dropped with a `warn!`. ~1,100 nodes had to be told to run +`freenet update` by hand, because a broken updater cannot deliver its own fix. + +Every signal we had was one-sided — the release built, published, installed and +ran. Two gates now close that, both driven by `scripts/auto-update-canary.sh`: + +**Gate A — pre-flight, BLOCKING** (`attach-to-release` job in +`cross-compile.yml`, between asset upload and un-draft). Boots the binary that +is about to ship and requires its updater to read GitHub's current release tag. +Runs while the release is still a draft, so a failure costs a stuck draft +rather than a stranded fleet. Adds about a minute. + +**Gate B — self-update, post-publish** (`auto-update-selfupdate-canary` job). +Takes the *previous* release and requires it to detect this one, exit 42, and +self-replace via `freenet update`. This is the transition the fleet actually +makes. It cannot run earlier: the detection path is hardwired to GitHub's +`/releases/latest`, and a draft release does not appear there. A failure is +loud (red job plus a River dev-room message) but does not block, since the +release is already public by then. + +Both assertions are deliberately **two-sided**: the `Startup update check +against GitHub` line must be PRESENT *and* there must be no +`Startup update check: failed to parse` warning (the marker stops at +`parse` so it covers the current-version arm as well as the latest-version +one). Absence of the error on its own +proves nothing — it is equally consistent with the check never running, which +is exactly what `--disable-auto-update` or a dirty build produces. The canary +also fails if the node under test has auto-update disabled at all, so +"the canary was silently turned off" is a red build rather than something +someone has to remember. (It had been forgotten: `framework`, the designated +real-NAT pre-release smoke peer, ran with `--disable-auto-update` for nine days +after a #5040 measurement window, which is why it never caught this.) + +### What the gates do NOT cover + +Worth knowing before you conclude "we have an auto-update canary, why didn't it +catch this?" + +**Gate A proves exactly one chain: fetch → tag normalise → semver parse → +compare.** That is the #5221 break and nothing more. It does *not* exercise +signature verification, checksum-manifest matching, asset download, the binary +swap, the exit-42 supervisor plumbing, or crash-loop rollback. A release whose +*detection* works and whose *installer* is broken passes Gate A cleanly. + +**Gate B does cover download, signature, checksum and swap — but it runs the +PREVIOUS release's binary**, because a node can only self-update *from* +something. So a break in the installer half of the binary you are shipping is +caught by Gate B one release later, when that binary becomes the previous one. +Gate B is also post-publish and non-blocking, so even then it reports rather +than stops. + +**Gate A cannot see a wrong COMPARISON of correct values.** Since #5236 it +checks the version the node says it observed (`latest=`) against the tag +`releases/latest` actually resolves to, so a fetch or normaliser that returns +the wrong string is caught. The comparison that follows it is not covered. +Mutate `compare_versions_for_startup`'s `latest_ver > current_ver` +(`crates/core/src/bin/commands/auto_update.rs`) to `<` and Gate A stays green: +the fetch is right, the parse is right, the observed value is right, and every +marker the gate reads is exactly what a healthy run produces. + +This is structural, not something the gate is failing to do properly. Gate A's +subject is by construction NEWER than `releases/latest` — the release it +belongs to is still a draft — so there is no newer release for it to find and +"decided not to update" is the correct outcome of a healthy run. A gate whose +input can only produce one answer cannot distinguish comparators by their +answer. + +Worth being precise about the direction, because the obvious reading is the +wrong way round: inverting that operator does not make the node quietly do +nothing. `latest < current` is TRUE for a Gate A run, so the node returns the +OLDER release and requests an update to it — a self-downgrade. Gate A reports +green on it, because a trigger is one of the outcomes it accepts. (Gate A's +verdict comes only from `assert_detection_healthy`; it does not assert that +the shipping binary declined to update. Adding that assertion would close this +particular hole, at the cost of failing any release cut from a branch whose +version is genuinely below `releases/latest` — a hotfix on an older line. It +has not been added.) + +What does cover the comparison is the Rust unit tests on +`compare_versions_for_startup` (same file, `mod tests`), which assert both +directions and the equal case. Gate B covers it end-to-end for real, but only +for the PREVIOUS release's binary. + +**An orphaned node was observed once, and the pin cannot see it.** After a real +`preflight` returned, a `timeout 240 target/release/freenet network …` was still +alive about four minutes later, its workdir already deleted by the EXIT trap. It +did not reproduce: 0 leaks in 9 subsequent runs, so there is no known rate and +no mechanism. Lifecycle case 4 pins exactly this property, but against a bash +fake node with none of a real node's SIGTERM handling or graceful shutdown, so +the environment that test runs in cannot produce the fault — a green case 4 is +not evidence the leak is gone. If a canary run ever seems to hang or a later run +reports "the startup update check never ran" for no clear reason, check for a +stray `freenet network` process first; a leaked node holds its ports and burns +CPU, which is how this surfaced before (see the lifecycle test's case 2 notes). + +**Gate B's own code is never executed by any test.** The two gaps above are +about what the gates cannot observe when they run. This one is about the tests +*behind* the gates, and it is worth stating separately because it is easy to +mistake a large green suite for coverage it does not have. + +`scripts/auto-update-canary_test.sh` runs the canary's pure helpers against +fixtures and source-scrapes the rest. `cmd_selfupdate` — the whole of Gate B — +is never invoked, and neither is `resolve_expected_latest`. So nothing at any +level runs the previous release's tarball download, the extraction check, the +exit-42 assertion, `freenet update --quiet`, or the `awk '{print $3}'` field +split that reads the updated binary's version. Those run for the first time +during a real release, against a real GitHub. + +What the suite does pin around that code is real, and the distinction matters +when reading a failure: the version gate that decides whether Gate B's equality +check arms is tested behaviourally (`prev_emits_latest_seen`), and the call +site that consumes it is pinned including its `if ` prefix, so neither a +negation nor a reworded call can disarm the gate silently. That is the decision +logic. The I/O sequence it guards has no test. + +Practical consequence: a Gate B failure is more likely to be the canary's own +plumbing than the fleet's updater, and it is non-blocking either way. Read the +job log before concluding anything about auto-update. Closing this needs a +runtime test with a stubbed release archive; it is a known gap, deliberately +deferred, not an oversight. + +Net: the installer half of a shipping binary has no blocking gate, and neither +does its comparison logic. Treat a green Gate A as "this binary can still fetch +and read new release tags", not as "auto-update works". + +### If Gate A fails + +The release stays an **unpublished draft** with all assets attached. That is +the correct state — do not un-draft it by hand to unblock the release. The +updater in that binary cannot read GitHub's release tags, so publishing it +strands every node on the previous version and the fix cannot be delivered +automatically. (`scripts/release.sh` will also refuse to publish while the +cross-compile run is unfinished or failed, for the same reason.) + +**Know the state you are in first.** `release.yml` publishes to crates.io +*before* it pushes the tag, so at this point `freenet`/`fdev` vX.Y.Z are +already live on crates.io with no published GitHub release. That is a real +split state: `cargo binstall freenet` will 404 until it is resolved, and the +nightly `binstall-smoke-test` will go red. crates.io versions cannot be +un-published, so **do not delete the tag** — a yanked-looking crate pointing at +a tag that no longer exists is worse than the draft. + +1. Read the job log. It distinguishes a genuine parse failure from `UNVERIFIED` + (GitHub was unreachable) or a port collision (exit 43, another node or + canary run on the host — re-run the job). + + It does not always name an offending *line*, and an earlier version of this + step said it did. The parse-fail and fetch-fail branches echo the offending + log lines; the two branches most likely to fire on a healthy release — "the + check never ran" and "started but never logged an outcome" — have no single + line to name. Those now print a `canary node evidence` group holding the tail + of `node.out` and of the node log, because the canary deletes its workdir on + exit and a blocking run used to leave nothing at all behind. Read that group + first: a startup failure there (gateway-list fetch, config, port bind) means + the node never reached the update task, and the update path is not the + problem. +2. **If the failure was `UNVERIFIED` or a job timeout**, it is infrastructure, + not a bug: use **Re-run failed jobs** on the cross-compile run. The build + artifacts persist, so `attach-to-release` re-runs on its own and publishes + if the canary passes. +3. **If the updater is genuinely broken**, fix the detection path + (`crates/core/src/bin/commands/auto_update.rs`) and cut the next patch + release. Leave vX.Y.Z's tag and draft in place; publish the draft only if + you have decided the broken updater is acceptable, knowing the fleet will + not auto-update off it. +4. To reproduce locally, run the canary against a **clean release build**: + + ```bash + bash scripts/auto-update-canary.sh preflight ./target/release/freenet + ``` + + Note that a build from a dirty working tree disables auto-update entirely + (`build_info::GIT_DIRTY`), so the canary will report *auto-update is + DISABLED* rather than reproducing the parse failure. Commit or stash first. + +### If Gate B fails + +The release is already public and the fleet will **not** converge onto it on +its own. Ship a fix release, and expect to roll existing nodes by hand +(`freenet update`) as v0.2.120/v0.2.121 required. + ## Post-release verification After the cascade completes, do these checks (or use the `freenet-release` @@ -466,6 +653,9 @@ verification skill if you have it): 4. Matrix room shows the announcement. 5. `sudo journalctl -u freenet-gateway --since "30 min ago"` on each gateway shows no errors. +6. The `Auto-update self-update canary` job in the tag's `cross-compile` run + is green — a node on the previous release reached this one on its own. If + it is red, the fleet is stranded; see "Auto-update canary" above. [PR #4135]: https://github.com/freenet/freenet-core/pull/4135 [river#241]: https://github.com/freenet/river/issues/241 diff --git a/scripts/auto-update-canary.sh b/scripts/auto-update-canary.sh new file mode 100755 index 0000000000..73bd7ccb7a --- /dev/null +++ b/scripts/auto-update-canary.sh @@ -0,0 +1,964 @@ +#!/usr/bin/env bash +# +# Auto-update release canary (#5222). +# +# WHY THIS EXISTS +# --------------- +# #5104 changed the node's release-tag fetch to return the tag VERBATIM +# ("v0.2.121") and normalised it at only one of its two consumers. The node's +# DETECTION path kept the raw tag, `semver::Version::parse("v0.2.121")` failed, +# and every update was dropped with a `warn!`. Auto-update was broken +# fleet-wide for v0.2.120 AND v0.2.121 -- silently, for two releases -- until +# ~1,100 nodes had to be told to run `freenet update` by hand. A broken +# updater cannot ship its own fix. +# +# Nothing caught it. Every existing signal was one-sided: the release built, +# published, installed and ran. The one machine positioned to notice +# (`framework`, the real-NAT pre-release smoke peer) had been running with +# `--disable-auto-update` since a #5040 measurement window nine days earlier. +# +# THE ASSERTION IS TWO-SIDED, AND THAT IS THE WHOLE POINT +# ------------------------------------------------------- +# "No `failed to parse latest version` in the log" is NOT evidence that +# parsing works. It is equally consistent with the check never running at all +# -- which is exactly what `--disable-auto-update`, a dirty build, or a node +# that never reached the update task all produce. A canary that can only go +# green is worth nothing. +# +# So `assert_detection_healthy` requires ALL of: +# (+) the "Startup update check against GitHub" INFO line is PRESENT +# -- proves the check actually STARTED +# (+) a terminal outcome line is PRESENT -- either "Startup update check +# complete" or a trigger +# -- proves the check FINISHED. Absence of a parse error is evidence +# that parsing worked only if the check is known to have got that +# far; a run stopped mid-request has no parse error either. See +# `run_node_until_check` for the specific way that used to happen. +# (-) no "failed to parse latest version" WARN +# -- proves it parsed what GitHub returned +# (-) no "Auto-update is DISABLED" WARN +# -- proves nobody silenced the canary itself (the #5040 drop-in failure +# mode, now a red build instead of a thing someone has to remember) +# +# TWO GATES +# --------- +# preflight -- Gate A, BLOCKING, runs before the release is un-drafted. +# Does the binary we are ABOUT to ship parse the tag of the +# CURRENT latest release? This is the gate that would have +# caught #5104 at v0.2.120, before it reached anyone. +# +# selfupdate -- Gate B, runs after publication. Does the PREVIOUS release +# actually detect this one, exit 42, and self-replace via +# `freenet update`? End-to-end proof of the real fleet +# transition. It cannot run before publication: the node's +# detection path is hardwired to GitHub's `/releases/latest`, +# and a draft release does not appear there. +# +# Run either locally. Both keep their FILES to their own temp directory +# (isolated HOME, config, data and log dirs), so nothing outside it is touched. +# +# PORTS are the exception, and an earlier version of this header overstated it +# by calling the runs "safe to run on a machine already running a node". They +# bind real ports, so a run collides with anything already holding them -- +# including ANOTHER canary run, which is the likelier case. The node then exits +# 43 (EXIT_CODE_ALREADY_RUNNING, `freenet.rs`). Two mitigations, neither a +# guarantee: the ports are drawn from a random per-run block (below) rather than +# fixed constants, and a 43 is classified as ENVIRONMENTAL so the gate retries on +# a fresh block instead of reporting an auto-update fault. Reproduced before +# that: two `preflight` runs started 2s apart, the second reporting "the startup +# update check never ran" for what was purely a port collision. +# +set -uo pipefail + +# --- log markers (must match crates/core/src/bin/) -------------------------- +# freenet.rs -- emitted unconditionally at the top of the startup check +MARKER_CHECK_RAN='Startup update check against GitHub' +# auto_update.rs -- the #5221 regression signature. Deliberately stops at +# `parse` so it covers BOTH arms of compare_versions_for_startup: the LATEST +# version (the #5221 break) and the CURRENT one. Both return None, both then +# reach the completion line, so a node that failed the current-version parse +# looked identical to a healthy one under the longer marker. The +# `Startup update check: ` prefix is load-bearing, not decoration -- without +# it the string also occurs in a comment inside auto_update.rs's own test +# module, which is enough to satisfy a whole-file source pin. +MARKER_PARSE_FAIL='Startup update check: failed to parse' +# auto_update.rs -- GitHub unreachable / rate-limited: infrastructure, not a bug +MARKER_FETCH_FAIL='failed to fetch latest version' +# freenet.rs -- either --disable-auto-update or a dirty build +MARKER_DISABLED='Auto-update is DISABLED' +# freenet.rs -- detection succeeded and an update was requested. There are +# FIVE such sites and one REFUSAL that shares the phrase: +# :524 "Startup check: newer version on GitHub, triggering auto-update" +# :609 "Urgent update confirmed on GitHub, triggering immediate auto-update" +# :670 "Update confirmed on GitHub after stagger, triggering auto-update" +# :751 "Newer version confirmed on GitHub, triggering auto-update" +# :873 "Periodic re-poll: newer version on GitHub, triggering auto-update" +# :519 "...repeated install failures); not triggering auto-update (#4073)" +# Matching the bare substring counts the refusal as a trigger; anchoring on any +# ONE site's full phrase misses the others, reporting "did not decide to +# update" for a node that did. So: match the phrase, subtract the refusal. +# +# A REGEX, not a fixed string, and that is the whole point: the urgent site at +# :609 says "triggering IMMEDIATE auto-update", so the fixed substring +# `triggering auto-update` did not match it. A node that took the urgent path +# was reported as never having decided to update. It failed CLOSED (Gate B +# refuses rather than passes), so nothing broke visibly -- which is precisely +# why an enumeration that had been wrong since the urgent path was added went +# unnoticed. `auto-update-canary_test.sh` pins the count of +# `update_tx.send(new_version)` call sites -- a structural anchor this regex +# cannot influence -- and then requires this regex to match all of them. A +# sixth site therefore cannot be added silently whether or not the regex +# happens to match its wording. (Deriving the expected count FROM this regex, +# as the first version of that pin did, made a site the regex missed invisible +# to the count as well: the two errors cancelled.) +MARKER_TRIGGERED_RE='triggering ([a-z]+ )?auto-update' +# Kept for the negative subtraction and for messages: the refusal is a fixed +# string and matching it loosely would swallow real triggers. +# shellcheck disable=SC2034 # read by auto-update-canary_test.sh, which sources +# this file and pins the literal against freenet.rs; the regex above is what the +# runtime detector uses. +MARKER_TRIGGERED='triggering auto-update' +MARKER_NOT_TRIGGERED='not triggering auto-update' +# freenet.rs -- the check ENDED without requesting an update. Emitted on every +# non-triggering outcome (already up to date, GitHub unreachable, unparseable +# tag, #4073 locally-blocked version), so it is a completion signal, not a +# verdict: it says the check got to the end, and the WARN above it, if any, +# says what it found. This was a `debug!` until #5236, which release builds +# compile out entirely (`release_max_level_info`) -- so on a shipped binary the +# most common outcome of the whole check was invisible, and "finished, staying +# put" was indistinguishable from "killed mid-request". +# +# A binary built BEFORE #5236 never emits it. That matters only in Gate B, +# whose subject is the PREVIOUS release: a healthy one triggers an update and +# settles on that, but an old one that neither triggers nor fails now reports +# UNVERIFIED instead of "did NOT decide to update". Still a refusal, and still +# the right one -- just a less specific message, and only until the previous +# release is itself post-#5236. +MARKER_CHECK_COMPLETE='Startup update check complete' +# auto_update.rs -- the OBSERVED latest release, emitted with a `latest=` field +# as soon as the fetch succeeds and before the comparison happens. +# +# Every other marker here is about what the node DECIDED. This one is about what +# it decided ABOUT, and that difference is what lets the gate assert a positive +# fact. Without it the healthy verdict is "no error appeared", which a silently +# WRONG comparator satisfies just as well as a correct one: a `version_from_tag` +# regressed to a constant, or a normaliser that truncated `0.2.121` to `0.2.12`, +# parses, compares, declines to update and logs a clean completion. The log is +# byte-identical to a healthy node's. With this marker the canary can compare +# the value against the tag GitHub actually published (see +# CANARY_EXPECTED_LATEST) and fail on a mismatch. +MARKER_LATEST_SEEN='Startup update check: GitHub reports latest release' +# The first release whose binary EMITS the line above. It is new in #5236, and +# Gate B's subject is the PREVIOUS release -- so for exactly one release the +# binary under test predates the marker and has no observed-latest line to +# compare. Arming the equality check against it would fail the gate for a line +# that binary was never built to emit: a release blocked by its predecessor's +# age. Gate B therefore arms the check only from `prev_version` onwards, which +# makes this self-retiring -- permanently true from the release AFTER this +# constant's value. +# +# If a Gate B run reports "never logged which release it compared against" for +# a previous release at or above this version, the marker was REMOVED (a real +# finding) or this constant is set one release too early (bump it). +MARKER_LATEST_SEEN_SINCE='0.2.124' + +MUSL_ASSET='freenet-x86_64-unknown-linux-musl.tar.gz' +RELEASE_BASE='https://github.com/freenet/freenet-core/releases/download' + +# The node's exit code for "another instance already holds my WS port" +# (EXIT_CODE_ALREADY_RUNNING in crates/core/src/bin/freenet.rs). Environmental, +# not an updater fault -- see where it is classified in the gate commands. +EXIT_CODE_ALREADY_RUNNING=43 + +# Ports deliberately off the node defaults (31337 / 7509) so a canary run does +# not collide with a real node on the same host. +# +# Drawn from a random 8-port BLOCK per run rather than fixed constants. Fixed +# ports made two canary runs on one host collide by construction: reproduced +# with two `preflight` runs started 2s apart, the second dying with exit 43 and +# being reported as "the startup update check never ran". CI is a fresh VM per +# job today, but other jobs in this repo already use self-hosted runners, where +# that becomes a silent and permanently-misdiagnosed release blocker -- and it +# breaks the local-debugging path this file's header invites, which is exactly +# when someone is trying to understand a blocked release. +# +# Block of 8 with the WS port at +4, so the per-attempt increments below (at +# most +2, for CANARY_ATTEMPTS=3) can never walk the network port onto this +# run's own WS port. Both stay overridable; the lifecycle test pins them. +CANARY_PORT_BLOCK="${CANARY_PORT_BLOCK:-$(( 39000 + (RANDOM % 320) * 8 ))}" +CANARY_NETWORK_PORT="${CANARY_NETWORK_PORT:-$CANARY_PORT_BLOCK}" +CANARY_WS_PORT="${CANARY_WS_PORT:-$(( CANARY_PORT_BLOCK + 4 ))}" + +# How long to let the node run before giving up on the startup check. The +# check fires after a 0-60s anti-thundering-herd jitter, so this must clear +# 60s by a healthy margin; it is a ceiling, not a wait (both gates return as +# soon as they have their answer, typically ~40s). +CANARY_TIMEOUT_SECS="${CANARY_TIMEOUT_SECS:-240}" +# Validated like its two neighbours below. Without this a non-numeric override +# reaches the `$((...))` in the lifecycle guard and, under `set -u`, kills the +# canary with a shell arithmetic error rather than a canary verdict -- a +# release-blocking failure whose message says nothing about the release. +case "$CANARY_TIMEOUT_SECS" in + ''|*[!0-9]*|0) CANARY_TIMEOUT_SECS=240 ;; +esac + +# Retry budget for the INDETERMINATE (GitHub unreachable) case only. Kept +# small on purpose: this sits on the release critical path inside a job with a +# fixed timeout, and an over-generous retry budget turns a network blip into a +# cancelled job and a permanently stuck draft -- worse than the failure it was +# trying to ride out. +CANARY_ATTEMPTS="${CANARY_ATTEMPTS:-2}" +# A non-numeric or zero override would make the retry loop body never execute +# and the script report "could not reach GitHub in 0 attempts" -- a blocking +# failure backed by no attempt at all. +case "$CANARY_ATTEMPTS" in + ''|*[!0-9]*|0) CANARY_ATTEMPTS=2 ;; +esac +CANARY_RETRY_SLEEP="${CANARY_RETRY_SLEEP:-20}" + +# How long to wait, AFTER the "check started" line appears, for the check to +# log an outcome. The floor is set by production, not by taste: the check's +# network round trip is bounded by PROBE_CHAIN_TIMEOUT (10s, whole-chain -- +# DNS, connect, redirects; crates/core/src/bin/commands/auto_update.rs), the +# parse is immediate after it, and the "check started" line is logged BEFORE +# the request begins. So any outcome that is ever going to be logged is logged +# within ~10s of that line, and this is 2x that. Below PROBE_CHAIN_TIMEOUT the +# canary stops the node mid-request and reads the resulting silence as health +# (#5236). +CANARY_OUTCOME_WAIT_SECS="${CANARY_OUTCOME_WAIT_SECS:-20}" +case "$CANARY_OUTCOME_WAIT_SECS" in + ''|*[!0-9]*|0) CANARY_OUTCOME_WAIT_SECS=20 ;; +esac + +log() { printf '%s\n' "$*"; } +fail() { printf '::error::%s\n' "$*" >&2; } +# An UNVERIFIED result, not a detected fault. Deliberately not `::error::`: +# annotating an unreachable GitHub as a workflow error trains people to ignore +# the annotation, and the caller decides whether to retry or fail. +note() { printf '%s\n' "$*" >&2; } + +# True when the logs show the node DECIDED to update. See the marker comments +# above for why this is a subtraction rather than a single grep. +# +# No trailing `| grep -q .`: `grep -q` exits at its FIRST match and closes the +# pipe, so the upstream grep takes SIGPIPE and dies 141. Under `set -o pipefail` +# (set at the top of this file) 141 becomes the pipeline's status, and the +# function reports "did not decide to update" for a node that plainly did. +# Measured: rc=0 at 400 matching lines, rc=141 at 700, 30/30 reproducible once +# the output passes the 64 KB pipe buffer. Canary logs never get that big, so +# this was latent rather than live -- but it fails in the direction of a wrong +# answer, not a loud one, and the fix is to not truncate the reader. +node_decided_to_update() { + local logdir="$1" hits + hits="$(grep -ahE "$MARKER_TRIGGERED_RE" "$logdir"/freenet.*.log 2>/dev/null \ + | grep -vF "$MARKER_NOT_TRIGGERED")" + [ -n "$hits" ] +} + +# True when the startup check reached a TERMINAL outcome -- any outcome, healthy +# or not. Either it ran to the end (MARKER_CHECK_COMPLETE, emitted on every +# non-triggering path) or it decided to update and returned early. +# +# This is the difference between "the check found nothing wrong" and "we stopped +# watching before it said anything", which every negative assertion in this file +# silently depends on and none of them can see on its own. +# No pipe here either, for the SIGPIPE reason documented on +# `node_decided_to_update`: `grep -q` reads the files directly instead. +node_check_settled() { + local logdir="$1" + if grep -aqF "$MARKER_CHECK_COMPLETE" "$logdir"/freenet.*.log 2>/dev/null; then + return 0 + fi + node_decided_to_update "$logdir" +} + +# Fixed-string presence / extraction over the node's log FILES. +# +# These exist because the obvious spelling is broken in the same way the two +# functions above are, and it bit a REAL run rather than staying latent: with +# the logs slurped into a shell variable, `printf '%s' "$logs" | grep -aqF ...` +# has `grep -q` exit at its first match and SIGPIPE the `printf`, which dies +# 141; `set -o pipefail` (top of this file) promotes that to the pipeline's +# status, so the `if` reads a marker that IS PRESENT as ABSENT. +# +# It only fires once the log passes the 64 KB pipe buffer, which is why the +# fixtures never saw it -- but Gate A's normal path does: when the shipping +# binary is newer than latest the node does not exit 42, so it keeps logging +# (~33 KB/s measured) until the canary kills it 1-4s later. Measured on a real +# 3.65 MB node log: `grep -acF` = 1 (the line is there), piped `grep -q` = 141, +# direct `grep -q` = 0. Same content with only trailing volume varied: 1 KB +# passes, 200 KB reports "the startup update check never ran". It hit 2 of 3 +# preflight runs, and `cmd_preflight` does not retry an rc=1 -- so a healthy +# release was blocked by an error naming the wrong subsystem. +# +# `grep -a`: the node writes some non-UTF8 bytes, and without it grep treats the +# file as binary. Keep it -- but for the opposite reason an earlier version of +# this comment gave. It claimed dropping `-a` "would silently satisfy every +# NEGATIVE check", i.e. a vacuous pass. Measured on GNU grep 3.11 with a NUL in +# the log, that is wrong: `grep -q` still reports matches in a binary file, so +# `log_has` is unaffected in BOTH directions (present -> rc=0, absent -> rc=1). +# What breaks is `log_lines`, whose STDOUT goes empty ("binary file matches" +# goes to stderr instead of the line). The first consumer to notice is the +# equality check's `seen_line`, which reads empty and fails with "the node never +# logged which release it compared against" -- a spurious BLOCKED release, not a +# vacuous pass. Fail-closed, so the direction matters to whoever is diagnosing +# it at the time. +log_has() { + # log_has + grep -aqF -- "$2" "$1"/freenet.*.log 2>/dev/null +} +log_lines() { + # log_lines -- matching lines on stdout, no headers + grep -ahF -- "$2" "$1"/freenet.*.log 2>/dev/null +} + +# NOTE on the glob above: `freenet.*.log` also matches `freenet.error.*.log`, +# which the node writes as a WARN+ subset of the same events. So a WARN-level +# marker is read from two files and matches twice. Harmless for every consumer +# today -- `log_has` only wants presence, and `log_lines` output is consumed by +# `head -2` or `tail -1` -- but a future count-based assertion would silently +# double for WARN markers and not for INFO ones. Narrow the glob before adding +# one. + +# dump_node_evidence -- the node's own output, to stderr. +# +# Gate A blocking with no evidence is the failure mode this exists for. The two +# branches most likely to fire on a HEALTHY release -- "the check never ran" and +# "started but never logged an outcome" -- printed no node output at all, unlike +# the parse-fail and fetch-fail branches which echo the offending lines. The +# EXIT trap then deletes the workdir, so a real blocking run left nothing +# behind, while `docs/RELEASING.md` told the operator to "read the job log; it +# names the offending line" -- true for a parse failure, false for exactly the +# two branches most likely to block a good release. +# +# Called by the gate commands rather than from inside `assert_detection_healthy` +# on purpose: that function is pure (log dir in, verdict out), which is what +# makes it unit-testable against fixtures, and it never sees the workdir. +dump_node_evidence() { + local work="$1" + printf '::group::canary node evidence (%s)\n' "$work" >&2 + if [ -s "$work/node.out" ]; then + printf -- '--- node.out (last 40 lines) ---\n' >&2 + tail -40 "$work/node.out" >&2 + else + printf -- '--- node.out is empty or absent ---\n' >&2 + fi + # `ls` first: "which log files exist" is itself the answer when none do. + printf -- '--- %s/logs ---\n' "$work" >&2 + ls -la "$work/logs" >&2 2>/dev/null || printf 'no log directory\n' >&2 + if grep -aq '' "$work/logs"/freenet.*.log 2>/dev/null; then + printf -- '--- node log (last 40 lines) ---\n' >&2 + tail -q -n 40 "$work/logs"/freenet.*.log >&2 2>/dev/null + fi + printf '::endgroup::\n' >&2 +} + + +# One workdir for the whole run, cleaned by a single EXIT trap. +# +# This was originally a `local` in each gate with a `trap ... RETURN`. Under +# `set -u` the trap fired after the local had gone out of scope, so EVERY gate +# exited 1 -- including a healthy binary. A canary that reports failure on +# success is worse than no canary: the first person to hit it learns to +# override it, and then it never catches anything real. +CANARY_WORKDIR="$(mktemp -d)" +if [ -z "$CANARY_WORKDIR" ] || [ ! -d "$CANARY_WORKDIR" ]; then + # Without this, a failed mktemp leaves CANARY_WORKDIR empty and the later + # `rm -rf "${work:?}"` operates on "/preflight" -- non-empty, so `:?` does + # not catch it. The guard only protects against unset/empty, not against a + # wrong-but-non-empty path. + printf '::error::%s\n' "could not create a temp workdir for the canary" >&2 + exit 1 +fi +cleanup() { rm -rf "$CANARY_WORKDIR"; } +trap cleanup EXIT + +# --------------------------------------------------------------------------- +# assert_detection_healthy +# +# The two-sided assertion. Pure: reads log files, writes a verdict, touches +# nothing else -- which is what makes it unit-testable (see +# auto-update-canary_test.sh, which drives it with both a green and a red +# fixture; a canary nobody has ever seen go red is not a canary). +# +# Exit: 0 healthy, 1 broken, 2 indeterminate (GitHub unreachable -- infra, retry) +# --------------------------------------------------------------------------- +assert_detection_healthy() { + local logdir="$1" + + # Every read below goes through `log_has`/`log_lines`, which grep the FILES. + # Slurping them into a variable and piping it is what produced the + # pipefail+SIGPIPE misreads documented on `log_has` -- do not reintroduce it. + # + # Emptiness is likewise tested without slurping: `grep -q ''` matches any + # line, so this is "at least one non-empty log file exists". A missing glob + # makes grep fail to open the literal name, which is also (correctly) empty. + if ! grep -aq '' "$logdir"/freenet.*.log 2>/dev/null; then + # Distinct wording on purpose: this is NOT evidence that the updater is + # broken. The update task is spawned well inside network-node startup, so + # anything that stops the node booting (port bind, config, gateway list) + # lands here. Saying "auto-update is broken" would point whoever is on + # call at the wrong subsystem. + fail "canary produced no node logs at all in $logdir -- the node never started, so the updater was never reached. Investigate node startup, not the update path." + return 1 + fi + + # (-) Did something silence the updater? Checked FIRST: it explains a missing + # startup line, and reporting "check never ran" instead would send the + # reader hunting for a parsing bug that isn't there. + if log_has "$logdir" "$MARKER_DISABLED"; then + fail "auto-update is DISABLED on the canary node. The canary cannot test the updater while the updater is turned off -- this is the #5040 drop-in failure mode that hid #5221 for two releases." + log_lines "$logdir" "$MARKER_DISABLED" | head -2 >&2 + return 1 + fi + + # (+) POSITIVE side. Without this, every assertion below passes vacuously on + # a node that never checked for updates. + if ! log_has "$logdir" "$MARKER_CHECK_RAN"; then + # Hedged the same way the empty-log branch above is, and for the same + # reason. The update task is spawned well inside network-node startup, so + # anything that kills the node before it gets there lands HERE, not in that + # branch -- the tracer is already up, so the log dir is non-empty. The + # common one is a fresh config dir with no `gateways.toml`, which makes + # `NodeConfig::new` fetch the remote gateway index + # (`crates/core/src/config.rs`); if the runner cannot reach freenet.org the + # node dies before the updater exists. Naming only the update path sends the + # reader after a parsing bug that is not there, on a release someone is + # waiting for. + fail "the startup update check never ran: no '$MARKER_CHECK_RAN' line. Absence of a parse error here proves NOTHING -- the check did not happen. This is NOT by itself evidence that auto-update is broken: anything that stops the node reaching the update task lands here too (gateway-list fetch, config, port bind). Check the node output below for a startup failure BEFORE investigating the update path." + return 1 + fi + + # (-) NEGATIVE side: the #5221 signature. + if log_has "$logdir" "$MARKER_PARSE_FAIL"; then + fail "the node could not parse the version GitHub returned -- auto-update is BROKEN. This is the #5221 regression: the release tag reached the detection path without being normalised." + log_lines "$logdir" "$MARKER_PARSE_FAIL" | head -2 >&2 + return 1 + fi + + # Infrastructure, not a product bug: GitHub was unreachable or rate-limited, + # so the check ran but learned nothing. Distinct exit code so the caller can + # retry instead of failing a release on a transient network blip. + if log_has "$logdir" "$MARKER_FETCH_FAIL"; then + note "INDETERMINATE: could not reach GitHub to fetch the latest version." + log_lines "$logdir" "$MARKER_FETCH_FAIL" | head -2 >&2 + return 2 + fi + + # (+) The check STARTED (asserted above) but never reached an outcome: no + # completion line, no trigger, and none of the failure markers either. + # + # This is NOT success, and the whole point of the canary is that the two + # are told apart. Every negative check above is satisfied by a log that + # simply stops early, so without this branch a truncated run reports OK + # -- and a binary carrying the #5221 unparseable-tag bug passes Gate A + # and ships, as long as GitHub answered slower than the canary waited + # (#5236). Returning 2 rather than 1 because it is genuinely unknown: + # the caller retries, and a run that still cannot produce an answer + # fails the gate as UNVERIFIED instead of masquerading as a verdict. + if ! node_check_settled "$logdir"; then + note "INDETERMINATE: the startup update check started but never logged an outcome (no '$MARKER_CHECK_COMPLETE', no trigger, no failure). The check did not finish inside the canary's window, so this run proves NOTHING about the updater -- it is not evidence that parsing works." + return 2 + fi + + # (+) POSITIVE EQUALITY. Everything above is satisfied by a comparator that is + # silently WRONG rather than broken: nothing so far has looked at the + # value the node compared against, only at whether it complained. Assert + # the observed latest equals the tag GitHub actually published. + # + # `CANARY_EXPECTED_LATEST` is supplied by the CALLER, not fetched here, so + # this function stays pure and unit-testable against log fixtures. The + # caller (cmd_preflight) resolves it from the GitHub API and returns + # INDETERMINATE if it cannot -- so "unset" never reaches here on the + # release path, and the skip below cannot silently disarm the gate on a + # real run. `auto-update-canary_test.sh` pins that cmd_preflight resolves + # it, exports it, and refuses when it cannot -- without that pin this + # skip branch would be exactly the vacuous escape hatch the gate exists + # to remove. + if [ -n "${CANARY_EXPECTED_LATEST:-}" ]; then + local seen_line seen + seen_line="$(log_lines "$logdir" "$MARKER_LATEST_SEEN" | tail -1)" + if [ -z "$seen_line" ]; then + fail "the node never logged which release it compared against (no '$MARKER_LATEST_SEEN'). Without it a comparator that silently returns the wrong version -- a constant, or a truncated tag -- produces a log byte-identical to a healthy one, so 'no error' is not evidence that detection works." + return 1 + fi + # `latest=0.2.121` -- Display-formatted, so unquoted; take the last field + # and strip any trailing punctuation the formatter may add. + seen="${seen_line##*latest=}" + seen="${seen%% *}" + seen="$(printf '%s' "$seen" | tr -d '"'"'"'\r')" + if [ "$seen" != "$CANARY_EXPECTED_LATEST" ]; then + fail "the node compared against the WRONG release: it logged latest='$seen' but GitHub's latest published release is '$CANARY_EXPECTED_LATEST'. Detection is silently broken -- it did not fail to parse, it parsed the wrong thing, which is why every other check above passed. A constant-returning or truncating version_from_tag looks exactly like this." + printf '%s\n' "$seen_line" >&2 + return 1 + fi + log "OK: the node compared against '$seen', which matches GitHub's latest release." + else + # Deliberately loud. Reaching this on the release path would mean the + # caller stopped resolving the expected tag, and the gate would quietly + # drop from "compared against the right release" to "did not complain". + note "NOTE: CANARY_EXPECTED_LATEST is unset, so the positive-equality check was SKIPPED. This run does not prove the node compared against the right release." + fi + + log "OK: startup update check ran to completion and parsed GitHub's response." + log_lines "$logdir" "$MARKER_CHECK_RAN" | head -2 + return 0 +} + +# --------------------------------------------------------------------------- +# run_node_until_check +# +# Boot the node in an isolated tree and stop as soon as the startup check has +# produced a verdict (or the timeout expires). Sets NODE_EXIT. +# --------------------------------------------------------------------------- +NODE_EXIT="" +run_node_until_check() { + local binary="$1" work="$2" + mkdir -p "$work/home/.local/state/freenet" "$work/cfg" "$work/data" "$work/logs" + + # An isolated HOME matters for more than tidiness: the node keeps its GitHub + # poll token-bucket under $HOME/.local/state/freenet, so a shared HOME would + # let one gate's budget throttle the other's check. + # Job control, so this background job gets its own process group, AND the + # `exec` below, which is the half that actually makes the kill work. + # + # `kill $node_pid` alone reaps only the subshell and leaves the + # `timeout`/`freenet` grandchild alive (verified), still holding the UDP and + # WS ports and burning CPU while the next attempt tries to boot. But `set -m` + # by itself is NOT enough either: job control is inherited, so the `timeout` + # inside the subshell starts a process group of its OWN and a group kill on + # the subshell misses it (also verified -- the pgids differ). `exec` collapses + # the two: the subshell BECOMES timeout, so the job pid is timeout's pid and + # its child shares the group. The exports still apply, since they run before + # the exec replaces the shell. + set -m + ( + # shellcheck disable=SC2030 # scoping HOME to this subshell is the point: + # the node keeps its GitHub poll bucket under $HOME, and the caller's HOME + # must not be touched on a machine that is already running a node. + export HOME="$work/home" + # Tell the node a supervisor is present, exactly as the systemd unit does, + # so it takes the real exit-42 path rather than logging a "no supervisor" + # error and staying put. + export FREENET_SUPERVISED=1 + # The gate reads the node's log, and release builds rate-limit that log + # (1000 events/s aggregate plus a per-callsite cap, tracing/tracer.rs:557). + # A dropped line is indistinguishable from a line that was never emitted, + # and the directions are not symmetric: losing MARKER_CHECK_RAN or the + # completion line fails the gate LOUDLY (red / indeterminate), but losing + # the parse-failure WARN while the completion line survives leaves the + # negative check satisfied and the canary reporting OK on a binary carrying + # the #5221 bug -- a false GREEN, the exact class this canary exists to + # remove. The startup check emits a handful of lines and comes nowhere near + # either cap, so this is a latent risk rather than an observed one; the env + # var removes the class outright for the cost of one line. Only the + # canary's own throwaway node is affected. + export FREENET_DISABLE_LOG_RATE_LIMIT=1 + exec timeout "$CANARY_TIMEOUT_SECS" "$binary" network \ + --config-dir "$work/cfg" \ + --data-dir "$work/data" \ + --log-dir "$work/logs" \ + --network-port "$CANARY_NETWORK_PORT" \ + --ws-api-port "$CANARY_WS_PORT" \ + >"$work/node.out" 2>&1 + ) & + local node_pid=$! + set +m + + # Poll for a verdict rather than sleeping the full timeout: the check fires + # after a 0-60s jitter, so this normally returns in well under a minute and + # adds no meaningful time to a release. + # + # Measured against the CLOCK rather than by counting `sleep 3` iterations, + # so the budget means what it says regardless of how long a pass takes. + # + # Not a bug fix, and deliberately not described as one: the counting version + # charged 3s per pass while each pass cost slightly more, which makes the + # loop run marginally LONGER than nominal, not shorter. The false "the + # startup update check never ran" verdict that prompted this was caused by + # leaked nodes from earlier runs stealing CPU (see the `exec` note above), + # not by this loop. + local deadline=$(( $(date +%s) + CANARY_TIMEOUT_SECS )) + while [ "$(date +%s)" -lt "$deadline" ]; do + if ! kill -0 "$node_pid" 2>/dev/null; then + break # node exited on its own (exit 42 on the selfupdate path) + fi + if grep -aqF "$MARKER_CHECK_RAN" "$work/logs"/freenet.*.log 2>/dev/null; then + # The check has STARTED. Wait for it to FINISH. + # + # This was a flat `sleep 5`, which was shorter than the timeout the check + # itself runs under. The marker matched above is logged BEFORE the network + # request begins, and that request is bounded by PROBE_CHAIN_TIMEOUT (10s). + # So a GitHub that answered in 6s -- a loaded runner, a redirect hop, a + # mild rate-limit backoff -- had its node SIGTERMed before it could log + # success OR a parse failure OR a fetch failure, and + # `assert_detection_healthy` then read that silence as health. A binary + # carrying the exact #5221 bug this canary exists to catch would have + # passed Gate A and been published (#5236). + # + # Poll for the outcome instead, on a budget with real headroom over + # PROBE_CHAIN_TIMEOUT, and stop the moment it arrives -- so the common + # case is FASTER than the old fixed sleep, not slower. If the outcome + # never arrives the logs say so and `assert_detection_healthy` returns + # INDETERMINATE; the one thing that must not happen is reporting OK. + local outcome_deadline=$(( $(date +%s) + CANARY_OUTCOME_WAIT_SECS )) + while [ "$(date +%s)" -lt "$outcome_deadline" ] && [ "$(date +%s)" -lt "$deadline" ]; do + node_check_settled "$work/logs" && break + # A node that has exited has logged everything it is going to log. + kill -0 "$node_pid" 2>/dev/null || break + sleep 1 + done + # If the node decided to update, it exits 42 on its own. Killing it here + # would replace that with 143 and silently defeat Gate B's exit-42 + # assertion -- the canary would report "no update requested" for a node + # that requested one. Let it finish. + if node_decided_to_update "$work/logs"; then + # Clamped by `deadline` as well as by its own 60s budget. Every other + # wait in this loop honours the outer ceiling; this was the one arm that + # ignored it, so CANARY_TIMEOUT_SECS could be overrun by up to a minute. + # It was bounded in practice only because the node dies at its own + # `timeout $CANARY_TIMEOUT_SECS` -- an accident of a sibling mechanism, + # not a guarantee this loop makes. + local settle_deadline=$(( $(date +%s) + 60 )) + [ "$settle_deadline" -gt "$deadline" ] && settle_deadline="$deadline" + while kill -0 "$node_pid" 2>/dev/null && [ "$(date +%s)" -lt "$settle_deadline" ]; do + sleep 2 + done + fi + break + fi + sleep 3 + done + + # Stop the node if it is still up, then reap it for its exit code. Kill the + # whole process GROUP (see `set -m` above) so no node outlives this call. + kill -- "-$node_pid" 2>/dev/null || kill "$node_pid" 2>/dev/null + wait "$node_pid" + NODE_EXIT=$? + log "node exited with code $NODE_EXIT" +} + +# --------------------------------------------------------------------------- +# resolve_expected_latest +# +# The tag GitHub currently publishes as "latest", normalised the way +# `version_from_tag` normalises it (strip AT MOST one leading `v`). Echoes it +# on stdout; returns 1 if it cannot be determined. +# +# Deliberately the SAME source the node itself uses -- +# `github.com/{repo}/releases/latest`, read from the 302 `Location` -- and not +# `api.github.com`. Two reasons, both load-bearing: +# +# 1. Comparing the node's answer against a DIFFERENT endpoint would compare +# two things that are allowed to disagree, and the mismatch would fail a +# release for a reason that is not a bug. +# 2. The REST API allows 60 unauthenticated requests/hour per source IP, +# shared across everything on that runner. The redirect endpoint is served +# by the web front end and draws on no such budget -- which is exactly why +# #5102 moved the node off the API. Spending REST quota here would +# reintroduce that cost on the release critical path. +# +# During Gate A our own release is still a DRAFT, so this correctly resolves to +# the PREVIOUS release -- the same thing the node under test sees. +# --------------------------------------------------------------------------- + +# normalise_release_tag +# +# Split out from the fetch so it can be tested without a network: the whole +# check turns on this matching what the node does, and a normaliser nobody can +# test is how the mismatch it exists to catch would be introduced. +# +# `${tag#v}` strips AT MOST ONE leading `v`, mirroring version_from_tag's +# `strip_prefix` -- deliberately not the greedy `${tag##v*}`, because +# `trim_start_matches` semantics would turn `vv1.2.3` into `1.2.3` and lose what +# is needed to address the release. The rustdoc on version_from_tag documents +# the same hazard. +normalise_release_tag() { + printf '%s' "${1#v}" +} + +# version_at_least -- true when semver is >= . +# +# `sort -V` rather than a field split: it gets 0.2.9 < 0.2.10 right, which a +# lexical compare does not, and equal inputs land on the last line either way. +version_at_least() { + [ "$(printf '%s\n%s\n' "$1" "$2" | sort -V | tail -1)" = "$1" ] +} + +# prev_emits_latest_seen -- true when a binary at that version +# emits MARKER_LATEST_SEEN, so Gate B's positive-equality check can arm. +# +# A named function rather than the comparison inlined at its one call site, so +# the DECISION can be tested directly. Inlined, the only thing pinning it was a +# grep for the literal call text -- and `if ! version_at_least …` contains that +# text just as `if version_at_least …` does, so the pin stayed green under an +# inversion. Inverted, Gate B arms against pre-#5236 binaries (a spurious red) +# and SKIPS for post-#5236 ones, which is the silent direction: its only +# positive assertion goes permanently vacuous while every release looks fine. +prev_emits_latest_seen() { + version_at_least "$1" "$MARKER_LATEST_SEEN_SINCE" +} + +resolve_expected_latest() { + local url tag + # `--retry`: this call has no second chance anywhere else. Its failure returns + # 1 from cmd_preflight BEFORE the attempt loop is entered, so unlike every + # node-side indeterminate -- which gets CANARY_ATTEMPTS tries -- a single + # transient blip here blocks the release outright. The comment above justifies + # the no-retry stance with "not something a re-run fixes", which is true of the + # NODE's verdict and not of one curl. `--retry-all-errors` because the + # interesting failures (connection reset, DNS blip) are not HTTP statuses, + # which is all bare `--retry` covers. + url="$(curl -fsS --max-time 30 --retry 2 --retry-all-errors \ + -o /dev/null -w '%{redirect_url}' \ + 'https://github.com/freenet/freenet-core/releases/latest' 2>/dev/null)" || return 1 + case "$url" in + */releases/tag/*) tag="${url##*/releases/tag/}" ;; + *) return 1 ;; + esac + [ -n "$tag" ] || return 1 + normalise_release_tag "$tag" +} + +# --------------------------------------------------------------------------- +# Gate A: preflight -- BLOCKS publication. +# +# Runs the binary we are about to ship against the CURRENT latest release and +# asserts its detection path is healthy. Catches "the updater we are shipping +# cannot read GitHub's release tags" while the release is still a draft. +# --------------------------------------------------------------------------- +cmd_preflight() { + local binary="$1" + local work="$CANARY_WORKDIR/preflight" + mkdir -p "$work" + + log "=== Gate A: auto-update pre-flight on the binary about to ship ===" + "$binary" --version + + # Resolve what the node SHOULD see before booting it, so the log assertion can + # be a positive equality rather than an absence-of-error. Failing to resolve + # it is INDETERMINATE, never a pass: without it the gate silently weakens to + # "the node did not complain", which is what a silently-wrong comparator + # produces. Returning 1 here (not 2) because the retry loop below re-runs the + # whole attempt for rc=2, and a resolution failure is not something a node + # re-run fixes -- it is an infrastructure problem the operator must see. + # A caller may pin the expected release (the lifecycle test does, to stay off + # the network). What a pinned value cannot do is DISARM the check: skipping + # needs an EMPTY value, and empty is treated as unset here, so + # `CANARY_EXPECTED_LATEST=` falls through to resolving from GitHub or + # refusing. + # + # It CAN make the check PASS, though, and an earlier version of this comment + # claimed otherwise. Pin a value that happens to agree with a comparator that + # is silently wrong and the equality check confirms the wrong answer -- the + # asserted-instead-of-resolved shape this gate exists to replace. So the + # release path must never pin it; the workflow does not, and + # `release_canary_wiring_test.sh` pins that it stays that way. + if [ -n "${CANARY_EXPECTED_LATEST:-}" ]; then + log "using the caller-supplied expected release '$CANARY_EXPECTED_LATEST' (not resolving from GitHub)." + elif ! CANARY_EXPECTED_LATEST="$(resolve_expected_latest)"; then + fail "could not resolve GitHub's latest release tag, so the canary cannot check WHICH release the node compared against. This is an UNVERIFIED result, not a detected bug: re-run this job. Do NOT un-draft the release by hand -- an unverified gate is not a passed gate." + return 1 + fi + export CANARY_EXPECTED_LATEST + log "GitHub's latest published release is '$CANARY_EXPECTED_LATEST'; the node must compare against exactly that." + + # Retry only the INDETERMINATE case. A parse failure is deterministic and + # retrying it just burns release time; a GitHub blip is worth a second look + # before we stall a release on it. + local attempt rc + for attempt in $(seq 1 "$CANARY_ATTEMPTS"); do + log "--- attempt $attempt/$CANARY_ATTEMPTS ---" + # Wipe the WHOLE tree, not just the logs. The node persists its GitHub + # poll token-bucket and rate-limit cooldown under $work/home; reusing them + # means a retry after a 429 re-reads the same persisted cooldown and + # reports the identical INDETERMINATE without ever asking GitHub again. + # A retry that cannot produce a different answer is not a retry. + rm -rf "${work:?}" + mkdir -p "$work" + # Distinct ports per attempt. The process-group kill above should already + # guarantee the previous node is gone; this makes a retry survive even if + # some future refactor reintroduces a lingering child. + CANARY_NETWORK_PORT=$((CANARY_NETWORK_PORT + 1)) + CANARY_WS_PORT=$((CANARY_WS_PORT + 1)) + run_node_until_check "$binary" "$work" + # Classify the port collision BEFORE the log assertion, because the log + # assertion cannot see it: `assert_detection_healthy` never consults + # NODE_EXIT, so a node that died on exit 43 without an update-check line + # reads as "the startup update check never ran" -- an auto-update fault + # reported for another process holding the port. Reproduced with two + # `preflight` runs 2s apart. + # + # Returning 2 (environmental) rather than 1 is the load-bearing half: rc=1 + # skips the retry loop, and the ports are redrawn every attempt, so the very + # next attempt would have succeeded. This is precisely what rc=2 is for. + if [ "$NODE_EXIT" = "$EXIT_CODE_ALREADY_RUNNING" ]; then + note "INDETERMINATE: the node exited $EXIT_CODE_ALREADY_RUNNING (another instance already holds ports $CANARY_NETWORK_PORT/$CANARY_WS_PORT). This is a port collision on this host -- another canary run, or a local node -- not an auto-update fault. Retrying on a fresh port." + rc=2 + else + assert_detection_healthy "$work/logs" + rc=$? + fi + # Keep the evidence before the next attempt wipes the tree, or the EXIT trap + # deletes it. Only on a non-zero verdict, so a healthy release stays quiet. + [ "$rc" -eq 0 ] || dump_node_evidence "$work" + [ "$rc" -eq 2 ] || return "$rc" + if [ "$attempt" -lt "$CANARY_ATTEMPTS" ]; then + log "indeterminate (no verdict from the update check); retrying in ${CANARY_RETRY_SLEEP}s" + sleep "$CANARY_RETRY_SLEEP" + fi + done + + fail "the shipping binary's update check produced no verdict in $CANARY_ATTEMPTS attempts -- GitHub unreachable, or the check never logged an outcome. Cannot confirm its updater works. This is an UNVERIFIED result, not a detected bug: re-run this job. Do NOT un-draft the release by hand to work around it -- an unverified gate is not a passed gate." + return 1 +} + +# --------------------------------------------------------------------------- +# Gate B: selfupdate -- end-to-end, after publication. +# +# Takes the PREVIOUS release, points it at the real network, and requires it +# to detect this release, exit 42, and self-replace. This is the assertion +# that actually matters to the fleet: not "the log looks right" but "a node on +# the old version ends up on the new one". +# --------------------------------------------------------------------------- +cmd_selfupdate() { + local prev_version="$1" expected_version="$2" + local work="$CANARY_WORKDIR/selfupdate" + mkdir -p "$work" + + log "=== Gate B: does v$prev_version self-update to v$expected_version? ===" + mkdir -p "$work/bin" + if ! curl -fsSL --max-time 300 -o "$work/prev.tar.gz" \ + "$RELEASE_BASE/v${prev_version}/${MUSL_ASSET}"; then + fail "could not download the previous release (v$prev_version) -- cannot run the canary." + return 1 + fi + if ! tar xzf "$work/prev.tar.gz" -C "$work/bin" || [ ! -s "$work/bin/freenet" ]; then + fail "the previous release archive (v$prev_version) did not extract to a usable binary -- cannot run the canary. This is a download/packaging problem, not an updater problem." + return 1 + fi + chmod +x "$work/bin/freenet" + + local starting + starting="$("$work/bin/freenet" --version | head -1)" + log "starting from: $starting" + + # Arm the positive-equality check, as Gate A does. Gate B runs AFTER + # publication, so `releases/latest` IS this release: the previous release's + # binary must observe `expected_version`, and there is no need to re-resolve + # it from GitHub -- the caller already knows which release it just published, + # and asking again would only introduce a second source allowed to disagree. + # + # Without this the deliberately-loud "CANARY_EXPECTED_LATEST is unset" NOTE + # fired on EVERY healthy Gate B run (the command runs in its own process, so + # nothing Gate A exported reaches it). A warning that appears on every good + # release is one everybody learns to scroll past, which is worse than no + # warning: it is the same alarm-fatigue failure that let `--disable-auto-update` + # sit on `framework` for nine days. + # + # Version-gated for the one release where the previous binary predates the + # marker -- see MARKER_LATEST_SEEN_SINCE. + if prev_emits_latest_seen "$prev_version"; then + export CANARY_EXPECTED_LATEST="$expected_version" + else + unset CANARY_EXPECTED_LATEST + note "NOTE: v$prev_version predates the observed-latest log line (#5236, first emitted by v$MARKER_LATEST_SEEN_SINCE), so Gate B's positive-equality check is SKIPPED. It arms itself once the previous release is v$MARKER_LATEST_SEEN_SINCE or newer; no action needed." + fi + + run_node_until_check "$work/bin/freenet" "$work" + + # Same port-collision classification as Gate A, and for the same reason: the + # log assertion below never consults NODE_EXIT, so a 43 reads as an + # auto-update fault. Gate B has no retry loop, so this corrects only the + # DIAGNOSIS -- but that is the difference between "re-run this job" and + # someone hunting a fleet-wide updater break that does not exist. + if [ "$NODE_EXIT" = "$EXIT_CODE_ALREADY_RUNNING" ]; then + dump_node_evidence "$work" + fail "UNVERIFIED: the node exited $EXIT_CODE_ALREADY_RUNNING (another instance already holds ports $CANARY_NETWORK_PORT/$CANARY_WS_PORT), so Gate B never got to test the updater. This is a port collision on this host -- another canary run, or a local node -- NOT an auto-update fault. Re-run the job." + return 1 + fi + + # The two-sided log assertion first: it LOCALISES the failure. If detection + # is broken the version check below would also fail, but with a far less + # useful message. + assert_detection_healthy "$work/logs" + local rc=$? + # Keep the node's own output before the EXIT trap deletes the workdir. + [ "$rc" -eq 0 ] || dump_node_evidence "$work" + if [ "$rc" -eq 2 ]; then + # Infrastructure, not a stranded fleet. Still a failure -- reporting green + # on an unverified run is the vacuous-pass this canary exists to prevent -- + # but worded so nobody reads it as "the fleet is broken" and learns to + # ignore the alarm. + fail "UNVERIFIED: the update check produced no verdict (GitHub unreachable, or it never logged an outcome), so the canary could not determine whether v$prev_version reaches v$expected_version. This is NOT evidence that auto-update is broken, and NOT evidence that it works. Re-run the job." + return 1 + fi + [ "$rc" -eq 0 ] || return 1 + + if ! node_decided_to_update "$work/logs"; then + fail "v$prev_version parsed GitHub's response but did NOT decide to update to v$expected_version. The release is published and visible, so a node on the previous version is choosing to stay put -- the fleet will not converge." + return 1 + fi + + if [ "$NODE_EXIT" != "42" ]; then + fail "expected the node to exit 42 (update requested) but it exited $NODE_EXIT. The supervisor contract is what applies the update; without exit 42 the fleet never restarts onto the new binary." + return 1 + fi + + # The supervisor half of the contract, exactly as the systemd unit does it: + # exit 42 -> `freenet update` -> restart onto the new binary. + log "--- node requested an update (exit 42); running \`freenet update\` as the supervisor would ---" + if ! ( + # shellcheck disable=SC2031 # deliberate: `freenet update` must read the + # same isolated state dir the node wrote, and nothing outside it. + export HOME="$work/home" + "$work/bin/freenet" update --quiet + ); then + fail "\`freenet update\` failed -- the node asked for an update and the installer could not apply it." + return 1 + fi + + local final + final="$("$work/bin/freenet" --version | head -1)" + log "ended at: $final" + + # Field-exact, not a substring: `grep -F 0.2.12` also matches "0.2.121". + if [ "$(printf '%s' "$final" | awk '{print $3}')" != "$expected_version" ]; then + fail "self-update did NOT land on v$expected_version. Started at '$starting', ended at '$final'. A node on the previous release will not reach this one on its own." + return 1 + fi + + log "OK: v$prev_version -> v$expected_version end-to-end (detect, exit 42, install)." + return 0 +} + +usage() { + cat <<'EOF' +Usage: + auto-update-canary.sh preflight + Gate A (blocking, pre-publish): the binary about to ship can parse the + current latest release tag. + + auto-update-canary.sh selfupdate + Gate B (post-publish): the previous release self-updates to this one, + end to end. Versions are bare semver, no leading "v". + + auto-update-canary.sh assert-logs + Run just the two-sided log assertion over an existing log directory. +EOF +} + +main() { + case "${1:-}" in + preflight) [ $# -eq 2 ] || { usage; exit 64; }; cmd_preflight "$2" ;; + selfupdate) [ $# -eq 3 ] || { usage; exit 64; }; cmd_selfupdate "$2" "$3" ;; + assert-logs) [ $# -eq 2 ] || { usage; exit 64; }; assert_detection_healthy "$2" ;; + *) usage; exit 64 ;; + esac +} + +# Only run main when executed directly, so the test script can source this +# file and drive `assert_detection_healthy` without booting a node. +if [ "${BASH_SOURCE[0]}" = "${0}" ]; then + main "$@" +fi diff --git a/scripts/auto-update-canary_lifecycle_test.sh b/scripts/auto-update-canary_lifecycle_test.sh new file mode 100755 index 0000000000..c8f7f6bb20 --- /dev/null +++ b/scripts/auto-update-canary_lifecycle_test.sh @@ -0,0 +1,405 @@ +#!/usr/bin/env bash +# Lifecycle regression tests for auto-update-canary.sh (#5222). +# +# auto-update-canary_test.sh covers the PURE functions (the two-sided log +# assertion, the update-trigger detector, the source pins). This file covers +# the part that actually runs a process: `run_node_until_check` and the +# `cmd_preflight` workdir/trap lifecycle. Both had real bugs that the pure +# tests could not see, which is why this file exists: +# +# 1. An early draft used `trap 'rm -rf "$work"' RETURN` against a `local`, +# and under `set -u` EVERY gate returned 1 -- including a perfectly +# healthy binary. A canary that fails on success is worse than no canary: +# the first person to hit it learns to override the gate, and then it +# never catches anything real. That specific bug was caught before it +# reached a commit, so there is no commit to pin against and this file +# does NOT claim to reproduce it. Case 1 guards the broader class it +# belongs to -- a gate that can only ever go red -- which is checkable: +# forcing the gate to fail makes case 1 fail (verified). +# +# 2. The node was left running after the gate returned. `kill $node_pid` +# reaped only the subshell; `set -m` alone did not help because job +# control is inherited, so the `timeout` inside started a process group of +# its OWN. Every run leaked a node that held its ports and burned CPU, +# which is what made a later attempt's node boot too slowly to log its +# update check inside the window -- surfacing as a false "the startup +# update check never ran" on a HEALTHY binary. Case 4 pins this one +# directly: reintroducing the bug makes it fail (verified). +# +# 3. The gate could go green with no evidence (#5236). After the "check +# started" line it slept a flat 5s and killed the node -- but that line is +# logged BEFORE the network request, which production bounds at 10s +# (PROBE_CHAIN_TIMEOUT). Any GitHub answer in the 5-10s band was killed +# before it could log ANY outcome, and "no parse error in the log" was +# then read as "parsing works". A binary with the exact #5221 bug would +# have passed Gate A and shipped. Cases 5 and 6 pin it: 5 is the outcome +# that arrives late (verified to fail against the pre-fix script), 6 is +# the outcome that never arrives. +# +# Instead of booting a real Freenet node (slow, needs network, non-deterministic +# jitter), these drive the real functions against a FAKE node binary that emits +# the same log lines. The functions under test are the real ones, sourced. +# +# Run manually: bash scripts/auto-update-canary_lifecycle_test.sh +# Also wired into CI (the Fmt job in .github/workflows/ci.yml). + +set -uo pipefail + +SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" +CANARY_SH="$SCRIPT_DIR/auto-update-canary.sh" + +# Small budgets: the fake node logs within a second or two, so there is nothing +# to wait for. Must be exported BEFORE sourcing, since the script reads them at +# load time. +export CANARY_TIMEOUT_SECS=15 +export CANARY_ATTEMPTS=1 +export CANARY_RETRY_SLEEP=1 +export CANARY_NETWORK_PORT=39901 +export CANARY_WS_PORT=39902 + +# shellcheck source=scripts/auto-update-canary.sh +source "$CANARY_SH" + +FAILURES=0 +TMPROOT="$(mktemp -d)" +trap 'rm -rf "$TMPROOT"; cleanup' EXIT + +CHECK_LINE='INFO freenet: Startup update check against GitHub current="0.2.122" jitter_secs=1' +PARSE_FAIL_LINE="WARN freenet::commands::auto_update: Startup update check: failed to parse latest version 'v0.2.123': unexpected character 'v' while parsing major version number" +TRIGGER_LINE='INFO freenet: Startup check: newer version on GitHub, triggering auto-update new_version=0.2.123' +COMPLETE_LINE='INFO freenet: Startup update check complete: staying on the current version current="0.2.122"' +LATEST_SEEN_LINE='INFO freenet::commands::auto_update: Startup update check: GitHub reports latest release latest=0.2.121' + +# Pin what the node is expected to have compared against, so cmd_preflight does +# not reach GitHub from a test. +# +# Safe HERE, and only here: the node is a synthetic fixture and this file +# chooses BOTH sides of the comparison on purpose. It is not safe on the +# release path -- a pinned value that happens to agree with a silently-wrong +# comparator makes the equality check confirm the wrong answer rather than +# catch it. (An earlier version of this comment said a pinned value "can only +# make the check FAIL". That is true of skipping it, not of passing it.) +# `release_canary_wiring_test.sh` pins that the workflow leaves it unset. +# +# Skipping is what a pinned value cannot do: that needs an EMPTY value, which +# cmd_preflight treats as unset and then resolves or refuses. Cases that fail +# earlier (parse failure, no outcome) never reach the check at all. +export CANARY_EXPECTED_LATEST=0.2.121 + +# make_fake_node [linger-seconds] [extra-delay-seconds] +# +# Writes a stand-in for the freenet binary: it answers --version, parses just +# enough of the real flag set to find --log-dir, writes the log lines a real +# node would, then lingers before exiting with the requested code. +# +# `extra-delay-seconds` is the gap between the "check started" line and the +# outcome line. It models the only variable a real node has here: how long +# GitHub takes to answer. Production bounds that at PROBE_CHAIN_TIMEOUT (10s), +# and the whole of case 5 is a value inside that bound. +make_fake_node() { + local path="$1" exit_code="$2" extra="$3" linger="${4:-0}" delay="${5:-0}" + cat > "$path" <> "\$logdir/freenet.2026-08-08-02.log" +if [ -n "$extra" ]; then + sleep $delay + echo "2026-08-08T02:00:00.100000Z $extra" >> "\$logdir/freenet.2026-08-08-02.log" +fi +sleep $linger +exit $exit_code +FAKE + chmod +x "$path" +} + +ok() { echo "ok - $1"; } +bad() { echo "FAIL - $1" >&2; FAILURES=$((FAILURES + 1)); } + +# --------------------------------------------------------------------------- +# 1. A HEALTHY binary must make cmd_preflight exit 0. +# +# The "can this gate ever go green?" side. A gate that fails on every input +# would block the first release that ran it, and is indistinguishable from a +# working one until that happens. Paired with case 2 below, which is the +# "can it ever go red?" side -- neither is worth much alone. +# --------------------------------------------------------------------------- +FAKE_OK="$TMPROOT/fake-healthy" +# Emits the observed-latest line as well as the completion line: a real +# post-#5236 healthy node logs both, and Gate A now requires both. +make_fake_node "$FAKE_OK" 0 "$LATEST_SEEN_LINE +2026-08-08T02:00:00.200000Z $COMPLETE_LINE" 0 +if cmd_preflight "$FAKE_OK" >/dev/null 2>&1; then + ok "cmd_preflight returns 0 for a healthy binary" +else + bad "cmd_preflight returned non-zero for a HEALTHY binary -- the gate rejects everything" +fi + +# --------------------------------------------------------------------------- +# 2. A binary whose updater cannot parse the tag must FAIL the gate. +# Pairs with case 1: together they show the gate discriminates rather than +# always-passing or always-failing. +# --------------------------------------------------------------------------- +FAKE_BAD="$TMPROOT/fake-parsefail" +make_fake_node "$FAKE_BAD" 0 "$PARSE_FAIL_LINE" 0 +if cmd_preflight "$FAKE_BAD" >/dev/null 2>&1; then + bad "cmd_preflight returned 0 for a binary with a BROKEN updater" +else + ok "cmd_preflight fails a binary whose updater cannot parse the tag" +fi + +# --------------------------------------------------------------------------- +# 2b. A SILENTLY WRONG comparator must fail the gate too (#5236 finding 32). +# +# This node does everything right except the one thing that matters: it +# compares against the wrong release. It does not fail to parse, it does +# not fail to fetch, it runs to completion -- so every assertion the canary +# had before this change is satisfied and Gate A reported OK. Driven +# through cmd_preflight rather than assert_detection_healthy so the +# resolve/export wiring is exercised, not just the comparison. +# --------------------------------------------------------------------------- +FAKE_WRONG="$TMPROOT/fake-wrong-release" +make_fake_node "$FAKE_WRONG" 0 \ + 'INFO freenet::commands::auto_update: Startup update check: GitHub reports latest release latest=0.2.1 +2026-08-08T02:00:00.200000Z '"$COMPLETE_LINE" 0 +WRONG_OUT="$(cmd_preflight "$FAKE_WRONG" 2>&1)" +WRONG_RC=$? +if [ "$WRONG_RC" -eq 0 ]; then + bad "cmd_preflight returned OK for a node that compared against the WRONG release (0.2.1 vs 0.2.121) -- the silently-wrong-comparator hole is open" +# Glob match, not `printf … | grep -qF`: that pipeline's status is 141 under +# `pipefail` once the producer has more than a pipe buffer left to write when +# `grep -q` short-circuits, so a diagnosis that IS present reads as absent and +# this branch reports "the wrong diagnosis" for the right one. cmd_preflight's +# output is small today, so this is latent rather than live -- which is exactly +# how the same defect survived in assert_detection_healthy until a real 3.65 MB +# node log hit it. See .claude/rules/bug-prevention-patterns.md. +elif [[ "$WRONG_OUT" == *"compared against the WRONG release"* ]]; then + ok "cmd_preflight fails a node that compared against the wrong release, with the right diagnosis" +else + bad "cmd_preflight failed the wrong-release node but with the wrong diagnosis: $WRONG_OUT" +fi + +# --------------------------------------------------------------------------- +# 3. NODE_EXIT must carry the node's OWN exit code when it exits by itself. +# Gate B asserts exit 42; if the harness overwrites that with its own SIGTERM +# (143) the assertion silently stops meaning anything. +# --------------------------------------------------------------------------- +FAKE_42="$TMPROOT/fake-exit42" +make_fake_node "$FAKE_42" 42 "$TRIGGER_LINE" 0 +WORK42="$TMPROOT/work42" +mkdir -p "$WORK42" +run_node_until_check "$FAKE_42" "$WORK42" >/dev/null 2>&1 +if [ "$NODE_EXIT" = "42" ]; then + ok "NODE_EXIT preserves the node's own exit 42" +else + bad "NODE_EXIT was '$NODE_EXIT', expected 42 (the harness clobbered the real exit code)" +fi + +# --------------------------------------------------------------------------- +# 4. No node may outlive run_node_until_check. +# +# The process-group regression. A leaked node holds its ports and burns CPU, +# which is what made a later attempt's node boot too slowly to log its check +# in time -- reported as "the startup update check never ran" on a HEALTHY +# binary. Uses a marker in the fake's path so the search cannot match this +# test's own shell (the `pgrep -f` self-match trap). +# --------------------------------------------------------------------------- +MARKER="canaryleak$$" +FAKE_LONG="$TMPROOT/$MARKER" +make_fake_node "$FAKE_LONG" 0 "$COMPLETE_LINE" 30 # lingers well past the gate's return +WORKL="$TMPROOT/workleak" +mkdir -p "$WORKL" +LEAK_T0=$(date +%s) +run_node_until_check "$FAKE_LONG" "$WORKL" >/dev/null 2>&1 +sleep 2 +LEAK_ELAPSED=$(( $(date +%s) - LEAK_T0 )) +if pgrep -f "$MARKER" >/dev/null 2>&1; then + bad "a node survived run_node_until_check (process-group regression); leftovers:" + pgrep -af "$MARKER" >&2 + pkill -f "$MARKER" 2>/dev/null +elif [[ "$LEAK_ELAPSED" -ge "$CANARY_TIMEOUT_SECS" ]]; then + # The fake is launched under `timeout $CANARY_TIMEOUT_SECS` (canary + # script's run_node_until_check). Past that point it is dead whether or not + # the process-group cleanup works, so "no survivors" stops being evidence + # and this case silently proves nothing. Fail rather than report a pass we + # did not earn: on a loaded runner this is exactly how a re-introduced leak + # would go unnoticed. + bad "case 4 was VACUOUS: ${LEAK_ELAPSED}s elapsed >= CANARY_TIMEOUT_SECS (${CANARY_TIMEOUT_SECS}s), so the fake was reaped by its own timeout rather than by the cleanup under test" +else + ok "no node survives run_node_until_check (checked ${LEAK_ELAPSED}s in, well inside the ${CANARY_TIMEOUT_SECS}s timeout)" +fi + +# --------------------------------------------------------------------------- +# 5. THE VACUOUS PASS (#5236). A broken updater whose outcome lands more than +# five seconds after the "check started" line must still FAIL the gate. +# +# The gate used to `sleep 5` after that line and then kill the node. The +# line is logged BEFORE the network request, and the request is bounded by +# PROBE_CHAIN_TIMEOUT = 10s, so any GitHub answer between 5s and 10s -- +# loaded runner, redirect hop, mild rate-limit backoff -- was SIGTERMed +# before it could log success, a parse failure, or a fetch failure. The +# assertion then saw "check ran, no parse error" and returned OK. A binary +# carrying the exact #5221 bug this canary exists to catch would have +# passed Gate A and shipped. +# +# The fake below is that binary: it logs the parse failure 8s after the +# check line -- inside what production allows, outside what the gate used +# to watch. Verified to FAIL against the pre-fix script (which returned 0, +# reporting a broken updater as healthy) and to pass after. +# +# Asserting on the DIAGNOSIS, not just the exit code: the point is that the +# canary now SEES the parse failure, not merely that it stopped saying OK. +# --------------------------------------------------------------------------- +FAKE_SLOW="$TMPROOT/fake-slow-parsefail" +make_fake_node "$FAKE_SLOW" 0 "$PARSE_FAIL_LINE" 0 8 +WAS_TIMEOUT=$CANARY_TIMEOUT_SECS +WAS_WAIT=${CANARY_OUTCOME_WAIT_SECS:-20} +CANARY_TIMEOUT_SECS=40 +CANARY_OUTCOME_WAIT_SECS=25 +SLOW_OUT="$(cmd_preflight "$FAKE_SLOW" 2>&1)" +SLOW_RC=$? +CANARY_TIMEOUT_SECS=$WAS_TIMEOUT +CANARY_OUTCOME_WAIT_SECS=$WAS_WAIT +if [[ "$SLOW_RC" -eq 0 ]]; then + bad "cmd_preflight returned OK for a binary whose updater FAILED TO PARSE, because the failure was logged 8s after the check started (the #5236 vacuous pass)" +elif [[ "$SLOW_OUT" != *"could not parse the version GitHub returned"* ]]; then + bad "cmd_preflight failed the slow parse-failure binary but did not name the parse failure; got: $SLOW_OUT" +else + ok "a parse failure logged 8s after the check still fails the gate, with the right diagnosis" +fi + +# --------------------------------------------------------------------------- +# 6. NO OUTCOME AT ALL must not read as OK either. +# +# Case 5 covers the outcome that arrives late. This covers the one that +# never arrives -- a check wedged in its request, a node killed for any +# other reason. There is nothing to detect here and the gate must not +# pretend otherwise: it reports UNVERIFIED and refuses, rather than +# reporting a pass it has no evidence for. +# +# Short outcome budget on purpose: what is under test is the verdict for a +# log that never settles, not how long the canary is willing to wait. +# --------------------------------------------------------------------------- +FAKE_SILENT="$TMPROOT/fake-silent" +make_fake_node "$FAKE_SILENT" 0 "" 20 # logs the check line and nothing else +WAS_WAIT=${CANARY_OUTCOME_WAIT_SECS:-20} +CANARY_OUTCOME_WAIT_SECS=4 +if cmd_preflight "$FAKE_SILENT" >/dev/null 2>&1; then + bad "cmd_preflight returned OK for a node that logged NO outcome -- absence of an answer is being read as success (#5236)" +else + ok "a check that never logs an outcome is UNVERIFIED, not OK" +fi +CANARY_OUTCOME_WAIT_SECS=$WAS_WAIT + +# --------------------------------------------------------------------------- +# 7. A PORT COLLISION must be diagnosed as one, not as an auto-update fault. +# +# Reproduced before the fix: two `preflight` runs started 2s apart, the +# second reporting "the startup update check never ran". Exit 43 is +# EXIT_CODE_ALREADY_RUNNING -- the node found its WS port occupied and died +# before the update task existed. `assert_detection_healthy` never consults +# NODE_EXIT, so the log assertion is the only thing that spoke, and it named +# the wrong subsystem on a release someone was waiting for. +# +# Both halves are asserted, because the diagnosis is the point: the message +# must name the collision AND must no longer claim the update check never +# ran. Only the second of those was wrong before; a fix that added the new +# wording while leaving the old would still send the reader to the wrong +# place. +# --------------------------------------------------------------------------- +FAKE_43="$TMPROOT/fake-port-collision" +cat > "$FAKE_43" <<'FAKE43' +#!/usr/bin/env bash +if [ "${1:-}" = "--version" ]; then + echo "Freenet version: 0.2.122 (deadbeefcafe)" + exit 0 +fi +logdir="" +while [ $# -gt 0 ]; do + case "$1" in + --log-dir) logdir="$2"; shift 2 ;; + *) shift ;; + esac +done +mkdir -p "$logdir" +# A real node dies here BEFORE the update task is spawned, but the tracer is +# already up -- so the log dir is non-empty and the "no logs at all" branch is +# not the one that fires. That is what makes this land on the update-check +# branch and get misdiagnosed. +echo "2026-08-08T02:00:00.000000Z INFO freenet: another instance is already running" \ + >> "$logdir/freenet.2026-08-08-02.log" +exit 43 +FAKE43 +chmod +x "$FAKE_43" +COLLIDE_OUT="$(cmd_preflight "$FAKE_43" 2>&1)" +if [[ "$COLLIDE_OUT" != *"port collision"* ]]; then + bad "cmd_preflight did not diagnose exit 43 as a port collision; got: $COLLIDE_OUT" +elif [[ "$COLLIDE_OUT" == *"the startup update check never ran"* ]]; then + bad "cmd_preflight still reports a port collision as 'the startup update check never ran' -- the misdiagnosis is back" +else + ok "exit 43 is diagnosed as a port collision, not as an auto-update fault" +fi + +# --------------------------------------------------------------------------- +# 8. A BLOCKING gate must leave the node's own output behind. +# +# `cleanup` rm -rf's the workdir on EXIT, and the two branches likeliest to +# fire on a healthy release -- "the check never ran" and "started but never +# logged an outcome" -- printed nothing from the node, unlike the parse-fail +# and fetch-fail branches. So a real blocking run left no evidence at all, +# while docs/RELEASING.md told the operator to "read the job log; it names +# the offending line". +# +# Driven through the "check never ran" branch specifically, because that is +# one of the two that printed nothing: a fixture whose node logs something +# identifiable but never the check line. Asserting the node's OWN line comes +# back is what distinguishes a real dump from a header that says "evidence". +# --------------------------------------------------------------------------- +FAKE_NOCHECK="$TMPROOT/fake-no-check-line" +cat > "$FAKE_NOCHECK" <<'FAKENC' +#!/usr/bin/env bash +if [ "${1:-}" = "--version" ]; then + echo "Freenet version: 0.2.122 (deadbeefcafe)" + exit 0 +fi +logdir="" +while [ $# -gt 0 ]; do + case "$1" in + --log-dir) logdir="$2"; shift 2 ;; + *) shift ;; + esac +done +mkdir -p "$logdir" +echo "2026-08-08T02:00:00.000000Z INFO freenet: DISTINCTIVE_STARTUP_EVIDENCE_LINE" \ + >> "$logdir/freenet.2026-08-08-02.log" +sleep 1 +exit 0 +FAKENC +chmod +x "$FAKE_NOCHECK" +EVIDENCE_OUT="$(cmd_preflight "$FAKE_NOCHECK" 2>&1)" +if [[ "$EVIDENCE_OUT" != *"canary node evidence"* ]]; then + bad "a blocking gate produced no evidence block; got: $EVIDENCE_OUT" +elif [[ "$EVIDENCE_OUT" != *"DISTINCTIVE_STARTUP_EVIDENCE_LINE"* ]]; then + bad "the evidence block is present but does not contain the node's own log output; got: $EVIDENCE_OUT" +else + ok "a blocking gate dumps the node's own log before the workdir is deleted" +fi + +echo +if [[ "$FAILURES" -eq 0 ]]; then + echo "All auto-update-canary lifecycle assertions passed." +else + echo "$FAILURES lifecycle assertion(s) FAILED." >&2 + exit 1 +fi diff --git a/scripts/auto-update-canary_test.sh b/scripts/auto-update-canary_test.sh new file mode 100755 index 0000000000..56d9f091c2 --- /dev/null +++ b/scripts/auto-update-canary_test.sh @@ -0,0 +1,853 @@ +#!/usr/bin/env bash +# Regression test for auto-update-canary.sh -- the two-sided assertion that +# decides whether a release's auto-updater actually works (#5222). +# +# The fixtures below are VERBATIM log lines captured from real runs on +# 2026-08-08, not invented strings: +# - the BROKEN fixture is released v0.2.121 failing to parse the v0.2.122 +# tag: the live #5221 regression that broke auto-update fleet-wide; +# - the HEALTHY fixture is released v0.2.119 correctly detecting v0.2.122 +# and requesting the update. +# +# What this test is FOR: `assert_detection_healthy` is the load-bearing part +# of the canary, and its whole value is that it can go RED. A canary nobody +# has ever seen fail is indistinguishable from one that cannot fail. So the +# cases that matter most here are the negative ones -- especially +# `vacuous: clean log with no check` and `disabled`, which are precisely the +# inputs a one-sided "no error in the log" assertion would wave through. +# +# The real function is sourced (not copied) so the test cannot drift from the +# code CI runs -- mirroring release-agent/verify-version-decision_test.sh. +# +# Run manually: bash scripts/auto-update-canary_test.sh +# Also wired into CI (the Fmt job in .github/workflows/ci.yml). + +set -uo pipefail + +SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" +CANARY_SH="$SCRIPT_DIR/auto-update-canary.sh" + +if [[ ! -f "$CANARY_SH" ]]; then + echo "FAIL: $CANARY_SH not found" >&2 + exit 1 +fi + +# Source the real implementation. +# shellcheck source=scripts/auto-update-canary.sh +source "$CANARY_SH" + +FAILURES=0 +TMPROOT="$(mktemp -d)" +# Chain, do not replace: sourcing auto-update-canary.sh installed its own +# `trap cleanup EXIT`, and overwriting it leaks that script's workdir on every +# CI run. +trap 'rm -rf "$TMPROOT"; cleanup' EXIT + +# check [expected-message-substring] +# +# The optional message assertion is not decoration. Several branches of +# `assert_detection_healthy` return the SAME exit code for different reasons, +# so an exit-code-only test cannot tell them apart -- and mutation testing +# confirmed it: deleting the `Auto-update is DISABLED` branch entirely left an +# exit-code-only suite fully green, because a disabled node also has no +# "check ran" line and fails the next assertion anyway. What that branch +# actually contributes is the correct DIAGNOSIS, so that is what gets pinned. +check() { + local desc="$1" expected="$2" content="$3" want_msg="${4:-}" + local dir actual stderr + dir="$(mktemp -d "$TMPROOT/case.XXXXXX")" + if [[ -n "$content" ]]; then + printf '%s\n' "$content" > "$dir/freenet.2026-08-08-02.log" + fi + stderr="$(assert_detection_healthy "$dir" 2>&1 >/dev/null)" + actual=$? + if [[ "$actual" != "$expected" ]]; then + echo "FAIL - $desc (got exit $actual, expected $expected)" >&2 + FAILURES=$((FAILURES + 1)) + return + fi + if [[ -n "$want_msg" && "$stderr" != *"$want_msg"* ]]; then + echo "FAIL - $desc (exit $actual correct, but diagnosis wrong)" >&2 + echo " wanted message containing: $want_msg" >&2 + echo " got: $stderr" >&2 + FAILURES=$((FAILURES + 1)) + return + fi + echo "ok - $desc" +} + +# Verbatim from a real v0.2.119 run, 2026-08-08T02:02:59Z. +HEALTHY='2026-08-08T02:02:59.369148Z INFO freenet: Startup update check against GitHub current="0.2.119" jitter_secs=38 +2026-08-08T02:02:59.538127Z INFO freenet: Startup check: newer version on GitHub, triggering auto-update new_version=0.2.122' + +# The OTHER healthy shape, and the one Gate A actually sees: the binary about +# to ship is NEWER than the latest release, so the check finishes without +# triggering anything. Until #5236 that outcome was a `debug!` -- compiled out +# of release builds -- so a healthy Gate A run produced no ending at all and +# was byte-for-byte indistinguishable from a run cut short. +HEALTHY_UP_TO_DATE='2026-08-08T02:00:00.000000Z INFO freenet: Startup update check against GitHub current="0.2.123" jitter_secs=7 +2026-08-08T02:00:00.412000Z INFO freenet: Startup update check complete: staying on the current version current="0.2.123"' + +# The vacuous pass #5236 closed: the check STARTED and the log stops there, +# because the canary killed the node while GitHub was still answering. Every +# negative assertion is satisfied; none of them can see that nothing happened. +PENDING='2026-08-08T02:00:00.000000Z INFO freenet: Startup update check against GitHub current="0.2.123" jitter_secs=7' + +# Verbatim from a real v0.2.121 run, 2026-08-08T01:59:35Z -- the #5221 break. +BROKEN='2026-08-08T01:59:35.950835Z INFO freenet: Startup update check against GitHub current="0.2.121" jitter_secs=40 +2026-08-08T01:59:36.111073Z WARN freenet::commands::auto_update: Startup update check: failed to parse latest version '"'"'v0.2.122'"'"': unexpected character '"'"'v'"'"' while parsing major version number' + +# Verbatim from framework, 2026-08-07T15:36:35Z -- the stale #5040 drop-in. +DISABLED='2026-08-07T15:36:35.289311Z WARN freenet: Auto-update is DISABLED by configuration (--disable-auto-update): this node will NOT detect or apply updates and will stay on version 0.2.120 until you update it out-of-band.' + +DIRTY='2026-08-08T02:00:00.000000Z WARN freenet: Auto-update is DISABLED for this dirty (locally modified) build: this node will NOT detect or apply updates and will stay on version 0.2.122 until you act.' + +FETCH_FAIL='2026-08-08T02:00:00.000000Z INFO freenet: Startup update check against GitHub current="0.2.121" jitter_secs=12 +2026-08-08T02:00:00.500000Z WARN freenet::commands::auto_update: Startup update check: failed to fetch latest version: error sending request. Continuing with current binary.' + +# --- fixtures for the POSITIVE-EQUALITY check (#5236, review finding 32) ---- +# +# The shape Gate A sees on a healthy run, now carrying the observed latest. +SEEN_OK='2026-08-08T02:00:00.000000Z INFO freenet: Startup update check against GitHub current="0.2.123" jitter_secs=7 +2026-08-08T02:00:00.300000Z INFO freenet::commands::auto_update: Startup update check: GitHub reports latest release latest=0.2.122 +2026-08-08T02:00:00.412000Z INFO freenet: Startup update check complete: staying on the current version current="0.2.123"' + +# A SILENTLY WRONG comparator, which is the whole point of the check. This is +# what a `version_from_tag` that truncates `0.2.122` to `0.2.12` emits: it does +# not fail to parse, it parses the WRONG thing. Every other assertion in +# assert_detection_healthy passes on it -- the check ran, no parse error, no +# fetch error, it completed -- and before this check the canary called it OK. +SEEN_TRUNCATED='2026-08-08T02:00:00.000000Z INFO freenet: Startup update check against GitHub current="0.2.123" jitter_secs=7 +2026-08-08T02:00:00.300000Z INFO freenet::commands::auto_update: Startup update check: GitHub reports latest release latest=0.2.12 +2026-08-08T02:00:00.412000Z INFO freenet: Startup update check complete: staying on the current version current="0.2.123"' + +# The other silently-wrong shape: a comparator pinned to a constant. +SEEN_CONSTANT='2026-08-08T02:00:00.000000Z INFO freenet: Startup update check against GitHub current="0.2.123" jitter_secs=7 +2026-08-08T02:00:00.300000Z INFO freenet::commands::auto_update: Startup update check: GitHub reports latest release latest=0.0.0 +2026-08-08T02:00:00.412000Z INFO freenet: Startup update check complete: staying on the current version current="0.2.123"' + +# --- the positive cases ----------------------------------------------------- +check "healthy: check ran, parsed, triggered -> pass" 0 "$HEALTHY" +check "healthy: check ran and completed up-to-date -> pass" 0 "$HEALTHY_UP_TO_DATE" + +# --- the regression this canary exists to catch ----------------------------- +check "broken: #5221 unparseable tag -> fail" 1 "$BROKEN" \ + "could not parse the version GitHub returned" + +# --- THE VACUOUS-PASS CASES ------------------------------------------------- +# Each of these contains NO error line. A one-sided "grep -q 'failed to parse' +# && fail" assertion passes all of them, which is exactly how a dead updater +# comes to look identical to a working one. +check "vacuous: log with no update check at all -> fail" 1 \ + '2026-08-08T02:00:00.000000Z INFO freenet: Node started, listening on [::]:31337' \ + "the startup update check never ran" +check "vacuous: empty log directory -> fail" 1 "" \ + "no node logs at all" + +# Deliverable of #5222: "auto-update disabled on the canary" is a RED BUILD, +# not something a human has to remember. Both disable paths must be named as +# such -- the exit code alone would be satisfied by the missing-check branch, +# so the diagnosis is the assertion (see the note on `check` above). +check "disabled: --disable-auto-update (the #5040 drop-in) -> fail" 1 "$DISABLED" \ + "auto-update is DISABLED on the canary node" +check "disabled: dirty build silently skips the check -> fail" 1 "$DIRTY" \ + "auto-update is DISABLED on the canary node" + +# --- infrastructure vs product bug ------------------------------------------ +# GitHub unreachable is NOT a broken updater. It must be distinguishable, or +# a network blip either fails a good release or (worse) gets papered over with +# a retry that also swallows a real parse failure. +check "indeterminate: GitHub unreachable -> retry, not fail" 2 "$FETCH_FAIL" \ + "could not reach GitHub to fetch the latest version" + +# --- unknown must never read as OK (#5236) ---------------------------------- +# The check started and the log stops. Distinguishing this from success is the +# entire assertion: "no parse error" is evidence that parsing worked only if +# the check is known to have got as far as parsing. Exit 2, not 0 and not 1 -- +# nothing was detected, nothing was proved, and the caller retries. +check "unknown: check started but logged no outcome -> indeterminate, NOT ok" 2 "$PENDING" \ + "never logged an outcome" + +# --- the update-trigger detector -------------------------------------------- +# `node_decided_to_update` must fire for ALL FOUR "triggering auto-update" +# sites in freenet.rs and must NOT fire for the #4073 refusal, which shares the +# phrase ("...not triggering auto-update"). Two ways to get this wrong, both +# found in review: the bare substring counts the refusal as a trigger, and +# anchoring on one site's full phrase misses the other three -- reporting "did +# not decide to update" for a node that did. +trigger_case() { + # trigger_case + local desc="$1" expect="$2" line="$3" + local dir + dir="$(mktemp -d "$TMPROOT/trig.XXXXXX")" + printf '%s\n' "$line" > "$dir/freenet.2026-08-08-02.log" + if node_decided_to_update "$dir"; then local got=yes; else local got=no; fi + if [[ "$got" == "$expect" ]]; then + echo "ok - $desc" + else + echo "FAIL - $desc (detector said '$got', expected '$expect')" >&2 + FAILURES=$((FAILURES + 1)) + fi +} + +trigger_case "trigger: startup check" yes \ + '2026-08-08T02:02:59Z INFO freenet: Startup check: newer version on GitHub, triggering auto-update new_version=0.2.122' +trigger_case "trigger: post-stagger confirm" yes \ + '2026-08-08T02:02:59Z INFO freenet: Update confirmed on GitHub after stagger, triggering auto-update new_version=0.2.122' +trigger_case "trigger: peer-signal confirm" yes \ + '2026-08-08T02:02:59Z INFO freenet: Newer version confirmed on GitHub, triggering auto-update new_version=0.2.122' +trigger_case "trigger: periodic re-poll" yes \ + '2026-08-08T02:02:59Z INFO freenet: Periodic re-poll: newer version on GitHub, triggering auto-update new_version=0.2.122' +# The FIFTH site, and the one the fixed-string marker silently missed: it says +# "triggering IMMEDIATE auto-update", so `triggering auto-update` did not match +# and a node that took the urgent path was reported as never having decided to +# update. Fail-closed, so nothing broke loudly -- which is why it survived. +trigger_case "trigger: urgent path (the site the fixed-string marker missed)" yes \ + '2026-08-08T02:02:59Z INFO freenet: Urgent update confirmed on GitHub, triggering immediate auto-update new_version=0.2.122' +trigger_case "NOT a trigger: #4073 locally-blocked refusal" no \ + '2026-08-08T02:02:59Z WARN freenet: Startup check: newer version is locally blocked (crash-loop known-bad pin or repeated install failures); not triggering auto-update (#4073)' + +# --- the POSITIVE-EQUALITY check (#5236, review finding 32) ----------------- +# +# Everything above this point is satisfied by a comparator that is silently +# WRONG rather than broken. These drive assert_detection_healthy with +# CANARY_EXPECTED_LATEST set, which is how Gate A runs it. +check_vs_expected() { + # check_vs_expected [msg] + local desc="$1" expected_latest="$2" expected="$3" content="$4" want_msg="${5:-}" + CANARY_EXPECTED_LATEST="$expected_latest" check "$desc" "$expected" "$content" "$want_msg" +} + +check_vs_expected "equality: node compared against the right release -> pass" \ + "0.2.122" 0 "$SEEN_OK" +# The two silently-wrong comparators. Before this check both reported OK. +check_vs_expected "equality: TRUNCATED tag (0.2.122 -> 0.2.12) -> fail" \ + "0.2.122" 1 "$SEEN_TRUNCATED" "compared against the WRONG release" +check_vs_expected "equality: comparator pinned to a constant -> fail" \ + "0.2.122" 1 "$SEEN_CONSTANT" "compared against the WRONG release" +# A binary that never logs the observed value cannot be checked at all, and +# "cannot be checked" must not read as "checked and fine". +check_vs_expected "equality: no observed-latest line at all -> fail" \ + "0.2.122" 1 "$HEALTHY_UP_TO_DATE" "never logged which release it compared against" +# Unset is the pre-#5236 behaviour and must still work (the lifecycle test and +# `assert-logs` drive it that way), but it must SAY it proved less. +# +# The message assertion is the whole case, and it was missing: with only the +# exit code compared, replacing the entire `note "NOTE: CANARY_EXPECTED_LATEST +# is unset..."` in auto-update-canary.sh with `:` left this green. The skip +# branch could be silently emptied -- and a silent skip is precisely the +# vacuous pass this gate exists to remove, since a reader of a green log would +# have no way to tell the equality check ran from it having been skipped. +# +# Explicitly unset rather than relying on the variable happening to be unset. +# It is not leaking from `check_vs_expected` today -- bash restores a +# `VAR=x func` assignment when the function returns, verified -- but this is +# the one case whose meaning depends on ambient environment, and the way it +# would go wrong is silent: SEEN_OK carries latest=0.2.122, so an inherited +# CANARY_EXPECTED_LATEST=0.2.122 sends it down the EQUALITY branch, still +# exiting 0, testing the opposite of what its name says. The `unset` costs +# nothing and makes the case mean one thing. +unset CANARY_EXPECTED_LATEST +check "equality: unset expected-latest -> still passes, but says it skipped" \ + 0 "$SEEN_OK" "CANARY_EXPECTED_LATEST is unset, so the positive-equality check was SKIPPED" + +# --- the tag normaliser ----------------------------------------------------- +# It has to agree with version_from_tag exactly. If it strips differently, the +# equality check above compares two spellings of the same release and fails a +# release for a difference that is not a bug. +norm_case() { + # norm_case + local got + got="$(normalise_release_tag "$1")" + if [[ "$got" == "$2" ]]; then + echo "ok - normalise_release_tag '$1' -> '$2'" + else + echo "FAIL - normalise_release_tag '$1' gave '$got', expected '$2'" >&2 + FAILURES=$((FAILURES + 1)) + fi +} +norm_case "v0.2.122" "0.2.122" +norm_case "0.2.122" "0.2.122" +# At most ONE `v`, matching `strip_prefix` rather than the greedy +# `trim_start_matches` -- the hazard version_from_tag's rustdoc calls out. +norm_case "vv1.2.3" "v1.2.3" + +# --- the SIGPIPE regression (review finding 35) ----------------------------- +# `grep -q` at the end of a pipe exits at its first match and SIGPIPEs the +# upstream grep; under `pipefail` that 141 became the pipeline's status and the +# detector answered "no" for a node that plainly did decide to update. It only +# bites once output passes the 64 KB pipe buffer, so a small fixture cannot see +# it -- this one is deliberately large enough to. +sigpipe_dir="$(mktemp -d "$TMPROOT/sigpipe.XXXXXX")" +{ + for _ in $(seq 1 700); do + echo '2026-08-08T02:02:59Z INFO freenet: Startup check: newer version on GitHub, triggering auto-update new_version=0.2.122' + done +} > "$sigpipe_dir/freenet.2026-08-08-02.log" +if node_decided_to_update "$sigpipe_dir"; then + echo "ok - trigger detection survives >64KB of matching output (no SIGPIPE)" +else + echo "FAIL - trigger detection returned FALSE on a log full of triggers." >&2 + echo " This is the pipefail+SIGPIPE regression: a trailing 'grep -q' closes the" >&2 + echo " pipe at the first match, the upstream grep dies 141, and pipefail makes" >&2 + echo " that the pipeline's status -- so a node that decided to update reads as" >&2 + echo " one that did not." >&2 + FAILURES=$((FAILURES + 1)) +fi + +# The SAME defect, in `assert_detection_healthy` itself, which is the part the +# release gate calls. The two helpers above were fixed when the mechanism was +# first diagnosed; the four checks inside the function they serve were not, and +# unlike the helpers this one was not latent -- it hit 2 of 3 real preflight +# runs. Gate A's normal path is a binary NEWER than latest, so the node does +# not exit 42 and keeps logging (~33 KB/s) until the canary kills it seconds +# later, which puts the markers far behind the 64 KB pipe buffer. +# +# The fixtures elsewhere in this file are a few hundred bytes, so none of them +# can see it: the verdict was a function of log VOLUME, not of what the node +# did. These two are deliberately past the buffer, with the markers FIRST and +# the bulk after them -- the real geometry. +# +# Both directions are pinned, and both test the same property: that the verdict +# does not change with log VOLUME. The healthy one is what actually broke (a +# good release blocked by "the startup update check never ran", naming the wrong +# subsystem). The broken one covers the far worse direction -- a SIGPIPE'd +# negative check reading the #5221 signature as ABSENT, so the gate goes GREEN +# on the exact bug it exists to catch. +# +# What the broken case does NOT test, despite an earlier version of this comment +# saying so, is check ORDERING. `assert_detection_healthy` reaches the parse +# check via `log_has`, which greps the fixture FILES directly, so the marker is +# found whatever order the checks run in and a reordering leaves this green. +# Volume-resistance is what is pinned here; it is real, and it is the property +# that broke. +BULK="$(for _ in $(seq 1 1200); do + echo '2026-08-08T02:00:01.000000Z INFO freenet::node: connection established peer=abc123 remaining=7' +done)" +check "volume: healthy markers behind >64KB of later output -> still pass" \ + 0 "$SEEN_OK +$BULK" +check_vs_expected "volume: equality check still sees the observed-latest line behind >64KB" \ + "0.2.122" 0 "$SEEN_OK +$BULK" +check "volume: #5221 parse failure behind >64KB of later output -> still fail" \ + 1 "$BROKEN +$BULK" "could not parse the version GitHub returned" + +# --- numeric-override validation (review finding 36) ------------------------ +# A non-numeric CANARY_TIMEOUT_SECS reaches an arithmetic context and, under +# `set -u`, kills the canary with a shell error instead of a verdict -- a +# release-blocking failure whose message says nothing about the release. Its two +# neighbours were already guarded; this one was not. +timeout_guard_case() { + # timeout_guard_case + local got + got="$(CANARY_TIMEOUT_SECS="$1" bash -c ' + set -uo pipefail + # shellcheck source=/dev/null + source "$1" >/dev/null 2>&1 || true + printf "%s" "$CANARY_TIMEOUT_SECS"' _ "$CANARY_SH")" + if [[ "$got" == "$2" ]]; then + echo "ok - CANARY_TIMEOUT_SECS='$1' is sanitised to $2" + else + echo "FAIL - CANARY_TIMEOUT_SECS='$1' became '$got', expected '$2'" >&2 + FAILURES=$((FAILURES + 1)) + fi +} +timeout_guard_case "abc" "240" +timeout_guard_case "0" "240" +timeout_guard_case "" "240" +timeout_guard_case "90" "90" + +# --- Gate A must actually ARM the equality check ----------------------------- +# `assert_detection_healthy` skips the positive-equality check when +# CANARY_EXPECTED_LATEST is unset, which is right for the pure/unit-testable +# shape but means the check is only as real as the caller that sets it. Nothing +# else pins that, so a refactor dropping the assignment would leave every +# assertion here green while Gate A silently reverted to "the node did not +# complain" -- the exact vacuous shape this PR exists to remove. +# +# Scoped to cmd_preflight's body, not a whole-file grep: the variable is named +# in comments elsewhere in the file, and a file-wide match would be satisfied by +# the prose describing the mechanism rather than the code implementing it. +preflight_body="$(awk '/^cmd_preflight\(\) \{/{f=1} f{print} f&&/^\}/{exit}' "$CANARY_SH")" +# shellcheck disable=SC2016 # the needles below match LITERAL source text, so +# the `$(...)` inside them must not expand -- that is the point of the pin. +if [[ -z "$preflight_body" ]]; then + echo "FAIL - could not locate cmd_preflight() in $(basename "$CANARY_SH")" >&2 + FAILURES=$((FAILURES + 1)) +elif [[ "$preflight_body" != *'CANARY_EXPECTED_LATEST="$(resolve_expected_latest)"'* ]]; then + echo "FAIL - cmd_preflight no longer resolves CANARY_EXPECTED_LATEST." >&2 + echo " Gate A's only positive assertion is skipped when that is unset, so the gate" >&2 + echo " drops back to 'the node did not complain' -- which a silently-wrong" >&2 + echo " comparator satisfies (#5236, review finding 32)." >&2 + FAILURES=$((FAILURES + 1)) +elif [[ "$preflight_body" != *'export CANARY_EXPECTED_LATEST'* ]]; then + echo "FAIL - cmd_preflight resolves CANARY_EXPECTED_LATEST but does not export it." >&2 + FAILURES=$((FAILURES + 1)) +else + echo "ok - cmd_preflight resolves and exports CANARY_EXPECTED_LATEST (the equality check is armed)" +fi +# ...and refuses rather than passing when it cannot resolve it. A resolution +# failure that fell through would run the gate with the check skipped. +if [[ "$preflight_body" == *'if ! CANARY_EXPECTED_LATEST='*'return 1'* ]]; then + echo "ok - cmd_preflight refuses (returns non-zero) when the expected release cannot be resolved" +else + echo "FAIL - cmd_preflight does not refuse when resolve_expected_latest fails." >&2 + echo " Falling through would run Gate A with its positive check silently skipped." >&2 + FAILURES=$((FAILURES + 1)) +fi + +# --- Gate B must arm the equality check too --------------------------------- +# `cmd_selfupdate` runs in its own process, so nothing Gate A exported reaches +# it: before this, the deliberately-loud "CANARY_EXPECTED_LATEST is unset" NOTE +# fired on EVERY healthy Gate B run. A warning that appears on every good +# release is one everybody learns to scroll past. Same pin shape as +# cmd_preflight's above, and for the same reason -- the skip branch is only as +# harmless as the callers that do not take it. +selfupdate_body="$(awk '/^cmd_selfupdate\(\) \{/{f=1} f{print} f&&/^\}/{exit}' "$CANARY_SH")" +# shellcheck disable=SC2016 # literal source text; must not expand +if [[ -z "$selfupdate_body" ]]; then + echo "FAIL - could not locate cmd_selfupdate() in $(basename "$CANARY_SH")" >&2 + FAILURES=$((FAILURES + 1)) +elif [[ "$selfupdate_body" != *'export CANARY_EXPECTED_LATEST="$expected_version"'* ]]; then + echo "FAIL - cmd_selfupdate does not arm the positive-equality check." >&2 + echo " Gate B knows exactly which release it just published; without exporting it, the" >&2 + echo " gate drops to 'the node did not complain' and prints the unset NOTE on every" >&2 + echo " healthy release until nobody reads it (#5236)." >&2 + FAILURES=$((FAILURES + 1)) +# ...and it must arm it from the version it was told to expect, not from a +# second lookup. Re-resolving would introduce a source allowed to disagree with +# the caller -- the failure-that-is-not-a-bug this file already avoids in +# resolve_expected_latest. +elif [[ "$selfupdate_body" == *'resolve_expected_latest'* ]]; then + echo "FAIL - cmd_selfupdate re-resolves the expected release instead of using its argument." >&2 + echo " Two sources that may disagree produce a failed release that is not a bug." >&2 + FAILURES=$((FAILURES + 1)) +else + echo "ok - cmd_selfupdate arms the equality check from its expected-version argument" +fi + +# The version gate around it. The observed-latest marker is new in #5236 and +# Gate B drives the PREVIOUS release, so for one release there is no line to +# compare; the gate must skip rather than fail. Both halves are pinned, because +# either one alone is wrong: no gate blocks a release on its predecessor's age, +# and no arming leaves Gate B permanently vacuous. +# +# Pinned in two parts, because a single literal-text grep was not enough. The +# earlier form matched `version_at_least "$prev_version" "$MARKER_LATEST_SEEN_SINCE"` +# anywhere in the body -- and `if ! version_at_least …` CONTAINS that string, so +# inverting the gate left all assertions green. Demonstrated on this branch. +# So: the decision now lives in `prev_emits_latest_seen`, whose BEHAVIOUR is +# tested below, and the call site is matched INCLUDING its `if ` prefix so a +# `!` cannot slip between them. +# shellcheck disable=SC2016 # literal source text; must not expand +if [[ "$selfupdate_body" != *'if prev_emits_latest_seen "$prev_version"; then'* ]]; then + echo "FAIL - cmd_selfupdate no longer gates the equality check on prev_emits_latest_seen." >&2 + echo " Expected the call site verbatim, INCLUDING the 'if ' prefix:" >&2 + echo ' if prev_emits_latest_seen "$prev_version"; then' >&2 + echo " Matching the bare call would also match a NEGATED one. Un-gated, a previous" >&2 + echo " release built before #5236 emits no observed-latest line and Gate B fails for" >&2 + echo " a line that binary was never built to emit; negated, Gate B skips the check on" >&2 + echo " every modern release and goes permanently vacuous." >&2 + FAILURES=$((FAILURES + 1)) +else + echo "ok - cmd_selfupdate gates the equality check on prev_emits_latest_seen (un-negated)" +fi + +# ...and what that gate DECIDES, which the text match above cannot see. An +# inversion inside the function flips both of these. +gate_b_arm_case() { + # gate_b_arm_case + local got + if prev_emits_latest_seen "$1"; then got=yes; else got=no; fi + if [[ "$got" == "$2" ]]; then + echo "ok - prev_emits_latest_seen '$1' -> $2 (Gate B equality check ${2/yes/arms})" + else + echo "FAIL - prev_emits_latest_seen '$1' said '$got', expected '$2'." >&2 + echo " Inverted, Gate B skips its only positive assertion on every release from" >&2 + echo " v$MARKER_LATEST_SEEN_SINCE onward -- vacuous, and silent about it." >&2 + FAILURES=$((FAILURES + 1)) + fi +} +gate_b_arm_case "$MARKER_LATEST_SEEN_SINCE" yes # the release the marker lands in +gate_b_arm_case "0.2.125" yes # every release after it +gate_b_arm_case "0.3.0" yes +gate_b_arm_case "0.2.123" no # the one release that must skip +gate_b_arm_case "0.2.99" no # numeric, not lexical + +# `version_at_least` decides whether the gate above arms, so it gets its own +# cases: an off-by-one here silently disarms Gate B's only positive assertion. +version_ge_case() { + # version_ge_case + local got + if version_at_least "$1" "$2"; then got=yes; else got=no; fi + if [[ "$got" == "$3" ]]; then + echo "ok - version_at_least '$1' '$2' -> $3" + else + echo "FAIL - version_at_least '$1' '$2' said '$got', expected '$3'" >&2 + FAILURES=$((FAILURES + 1)) + fi +} +version_ge_case "0.2.124" "0.2.124" yes # the release the marker lands in +version_ge_case "0.2.125" "0.2.124" yes +version_ge_case "0.2.123" "0.2.124" no # the one release that must skip +version_ge_case "0.3.0" "0.2.124" yes +# Numeric, not lexical: a lexical compare puts 0.2.99 above 0.2.124 and would +# disarm the gate for every release in between. +version_ge_case "0.2.99" "0.2.124" no + +# --- no status-consuming pipe into a short-circuiting reader ---------------- +# The defect that produced this rule: `printf '%s' "$logs" | grep -aqF …` under +# `set -o pipefail`. `grep -q` exits at its first match, the producer dies with +# SIGPIPE (141), pipefail promotes 141 to the pipeline's status, and the `if` +# reads a marker that IS PRESENT as ABSENT. It is volume-dependent, so it does +# not fire below the 64 KB pipe buffer and no small fixture can see it -- it +# waits for a real log. On a 3.65 MB node log, `grep -acF` found the line while +# the piped `grep -q` exited 141 and Gate A blamed the wrong subsystem. +# +# The reason this is a pin and not just a fix: the commit that first diagnosed +# it fixed two helper functions and left four call sites inside the very +# function those helpers serve, plus two more elsewhere in these scripts. A fix +# applied where you happened to be reading is how this pattern survives. +# +# Scope is the release-gate scripts that set `pipefail`, where a wrong answer +# blocks or waves through a release. Alternatives, all used above: grep the +# FILE directly (`log_has`), match the variable with a bash glob +# (`[[ "$x" == *needle* ]]`), or take a count and test that. +# +# `head` is the same class but is NOT banned here: `$(… | head -1)` is used for +# its stdout, not its status, and banning it would be noise. Watch it manually +# when the pipeline's status is consumed. +# +# `release.sh` is in scope because it is the DRIVER: it sets `pipefail`, and its +# `verify_required_binaries` used `echo "$assets" | grep -xqF` -- the same shape, +# on the path that decides whether a release's binaries exist. Measured at 46 +# false "missing" verdicts in 20000 iterations under 24-way CPU load (0 in a +# quiet window), which is why it survived: it needs a contended runner. The +# consequence was the worst-placed one in the file, `wait_for_binaries` failing +# AFTER publish and BEFORE the gateway updates and announcements -- exactly what +# the comment above `verify_release_published` warns about. The file was never +# out of the regex's reach, only out of this list's. +SIGPIPE_SCRIPTS=( + "$CANARY_SH" + "$SCRIPT_DIR/auto-update-canary_test.sh" + "$SCRIPT_DIR/auto-update-canary_lifecycle_test.sh" + "$SCRIPT_DIR/release_wait_for_binaries_test.sh" + "$SCRIPT_DIR/release_canary_wiring_test.sh" + "$SCRIPT_DIR/release.sh" +) +# A renamed or moved entry must fail LOUDLY. Without this, `grep`'s complaint +# about a missing file goes to the `2>/dev/null` below and the entry simply +# stops being audited -- the pin keeps reporting "ok" over a file it no longer +# reads. Same reason `pin_marker` checks `[[ -f ]]` before scraping. +for _sigpipe_script in "${SIGPIPE_SCRIPTS[@]}"; do + if [[ ! -f "$_sigpipe_script" ]]; then + echo "FAIL - SIGPIPE_SCRIPTS names a file that does not exist: $_sigpipe_script" >&2 + echo " A renamed entry would otherwise drop out of the audit silently." >&2 + FAILURES=$((FAILURES + 1)) + fi +done +# Verified not to match its own defining line: after the `|` comes `[`, not +# whitespace-then-grep. A pin that finds its own needle is the self-satisfying +# shape this repo's rules file documents separately. +SIGPIPE_RE='\|[[:space:]]*grep[[:space:]]+-[a-zA-Z]*q' +sigpipe_hits="$(grep -nE "$SIGPIPE_RE" "${SIGPIPE_SCRIPTS[@]}" 2>/dev/null \ + | grep -vE ':[[:space:]]*#')" +if [[ -z "$sigpipe_hits" ]]; then + echo "ok - no 'pipe into grep -q' in the pipefail release-gate scripts (SIGPIPE/pipefail hazard)" +else + echo "FAIL - a pipeline ending in 'grep -q' has come back in a pipefail script." >&2 + echo " Under pipefail the producer's SIGPIPE (141) becomes the pipeline's status, so a" >&2 + echo " marker that IS present reads as ABSENT once the producer exceeds the 64 KB pipe" >&2 + echo " buffer. Small fixtures cannot see it; a real node log can. Grep the file directly," >&2 + echo " or match the variable with [[ \"\$x\" == *needle* ]]." >&2 + printf '%s\n' "$sigpipe_hits" >&2 + FAILURES=$((FAILURES + 1)) +fi + +# --- markers must still exist in the Rust source ---------------------------- +# Without this the fixtures above are a self-consistent copy of strings that +# may no longer be emitted: the canary would go quietly blind while its own +# test stayed green. Pin against the source of truth instead. +SRC="$SCRIPT_DIR/../crates/core/src/bin/freenet.rs" +AU_SRC="$SCRIPT_DIR/../crates/core/src/bin/commands/auto_update.rs" +pin_marker() { + # pin_marker + local desc="$1" file="$2" needle="$3" + if [[ ! -f "$file" ]]; then + echo "FAIL - $desc (source file not found: $file)" >&2 + FAILURES=$((FAILURES + 1)) + return + fi + # Rust wraps a long string literal two ways: a plain wrap, and a + # `\`-continuation, which also swallows the next line's indentation. + # Squeezing newlines into spaces handled only the first -- a continuation + # left a stray `\` mid-phrase, so the needle silently failed to match. + # `not triggering auto-update` is emitted at two sites in freenet.rs and + # only one has the phrase unbroken, so this pin was passing on the + # coincidence of which site rustfmt happened to leave intact; reflowing + # that one site would have reported the marker gone while it was still + # emitted. Drop the continuation backslash first, then strip whitespace + # from both sides (as the INFO-level pin below already does), so the pin + # tracks the marker rather than the formatting. + # + # A bash glob match on a command substitution rather than `... | grep -qF`, + # matching the shape the sibling pins below already use. The pipe version + # consumed the PIPELINE's status, which under `pipefail` is 141 whenever + # `grep -q` short-circuits and the producer still has more than a pipe + # buffer to write -- so a marker that IS present reads as absent. Measured + # on auto_update.rs (165 KB), matching a string on line 1: + # sed ... | grep -qF 'Auto-update' -> rc=141 + # sed ... | tr -d '[:space:]' | grep -qF ... -> rc=0 + # It passed only because `tr` deletes every newline, leaving one enormous + # line that grep must read to EOF before it can report a match. That is an + # accident of the whitespace stripping, not a property of the pin: anyone + # "simplifying" the `tr` away would silently arm the hazard on every source + # pin in this file at once. Take the status out of the pipeline instead. + if [[ "$(sed 's/\\$//' "$file" | tr -d '[:space:]')" == *"${needle//[[:space:]]/}"* ]]; then + echo "ok - $desc" + else + echo "FAIL - $desc: '$needle' no longer appears in $(basename "$file")" >&2 + FAILURES=$((FAILURES + 1)) + fi +} + +pin_marker "source pin: startup-check marker" "$SRC" "$MARKER_CHECK_RAN" +# The completion marker is load-bearing in a way the others are not: if it stops +# being emitted, every healthy run becomes INDETERMINATE and Gate A blocks every +# release. It must also stay at INFO -- a `debug!` is compiled out of release +# builds entirely (`release_max_level_info`), which is exactly how this outcome +# came to be invisible in the first place (#5236). +pin_marker "source pin: check-complete marker" "$SRC" "$MARKER_CHECK_COMPLETE" +# Whitespace stripped from BOTH sides, so this pins the macro rather than the +# formatting: a rustfmt reflow of the same call must not decide whether the +# canary is protected. +if [[ "$(tr -d '[:space:]' < "$SRC")" == *"tracing::info!(current=build_info::VERSION,\"${MARKER_CHECK_COMPLETE// /}"* ]]; then + echo "ok - source pin: check-complete marker is emitted at INFO" +else + echo "FAIL - source pin: the '$MARKER_CHECK_COMPLETE' line is no longer an INFO-level tracing::info! in freenet.rs -- release builds compile out anything below INFO, so the canary would go blind (#5236)" >&2 + FAILURES=$((FAILURES + 1)) +fi +# The trigger phrase gets the same NEGATIVE SUBTRACTION the runtime detector +# does, instead of a plain pin_marker. `MARKER_TRIGGERED` whitespace-stripped is +# `triggeringauto-update`, which is a SUBSTRING of the #4073 refusal line +# `not triggering auto-update`. So the refusal alone satisfied a plain +# containment check: the pin was tracking a line whose job is to say the +# OPPOSITE of the thing it claimed to pin. Demonstrated by rewording all four +# plain trigger sites in freenet.rs -- that assertion stayed green, and only the +# count pin below went red. +# +# `node_decided_to_update` has always subtracted the refusals; this brings the +# source pin into line with the detector it is supposed to protect. Counting +# OCCURRENCES rather than testing containment is what makes the subtraction +# possible at all. +TRIG_NEEDLE="${MARKER_TRIGGERED// /}" +SRC_SQUEEZED="$(sed 's/\\$//' "$SRC" | tr -d '[:space:]')" +# `grep -o | wc -l`: occurrences, not lines -- the squeezed source is ONE line, +# so `grep -c` would answer 1 no matter how many sites there are. Neither stage +# short-circuits, so this is not the `| grep -q` SIGPIPE shape banned below. +trig_all="$(printf '%s' "$SRC_SQUEEZED" | grep -oF -- "$TRIG_NEEDLE" | wc -l)" +trig_neg="$(printf '%s' "$SRC_SQUEEZED" | grep -oF -- "not$TRIG_NEEDLE" | wc -l)" +trig_pos=$(( trig_all - trig_neg )) +if [[ "$trig_pos" -gt 0 ]]; then + echo "ok - source pin: trigger phrase appears at $trig_pos site(s) that are NOT the #4073 refusal" +else + echo "FAIL - source pin: every '$MARKER_TRIGGERED' occurrence in freenet.rs is part of" >&2 + echo " '$MARKER_NOT_TRIGGERED' ($trig_all total, $trig_neg of them refusals)." >&2 + echo " No site actually announces a trigger with this wording, so the canary's" >&2 + echo " fixed-string half is dead. A containment check cannot see this: the" >&2 + echo " refusal CONTAINS the trigger phrase, which is how this pin passed while" >&2 + echo " all four plain trigger sites were reworded." >&2 + FAILURES=$((FAILURES + 1)) +fi +pin_marker "source pin: #4073 refusal phrase" "$SRC" "$MARKER_NOT_TRIGGERED" +pin_marker "source pin: disabled marker" "$SRC" "$MARKER_DISABLED" + +# --- the MARKER_LATEST_SEEN_SINCE constant itself --------------------------- +# Gate B's version gate is now pinned in both directions (the behavioural cases +# on `prev_emits_latest_seen`, and the un-negated call site), but neither looks +# at the CONSTANT they compare against. Raising it 0.2.124 -> 0.2.999 left the +# whole suite green while permanently disarming Gate B's only positive +# assertion -- the same silent direction as the `!` inversion, reached by +# editing a different line. +# +# Anchored against the crate version, which the constant cannot influence. The +# relationship is real rather than arbitrary: the constant names the first +# release whose binary emits MARKER_LATEST_SEEN, that marker is emitted by THIS +# source tree (pinned above), and this tree ships as the NEXT release. So the +# constant must be just ahead of the version in Cargo.toml -- not behind it (the +# marker is new here, so no already-published release emits it) and not far +# ahead of it (that is a typo, or a change that has sat unmerged for many +# releases and needs the value re-confirmed rather than assumed). +# +# The window is a guard against a wrong constant, not a proof of the right one. +# If a release genuinely slips further than this, update the constant on +# purpose -- which is the outcome this assertion exists to force. +CORE_TOML="$SCRIPT_DIR/../crates/core/Cargo.toml" +SINCE_SKEW_MAX=5 +if [[ ! -f "$CORE_TOML" ]]; then + echo "FAIL - cannot check MARKER_LATEST_SEEN_SINCE: $CORE_TOML not found" >&2 + FAILURES=$((FAILURES + 1)) +else + crate_version="$(sed -n 's/^version[[:space:]]*=[[:space:]]*"\([^"]*\)".*/\1/p' "$CORE_TOML" | head -1)" + IFS=. read -r c_maj c_min c_pat <<< "$crate_version" + IFS=. read -r s_maj s_min s_pat <<< "$MARKER_LATEST_SEEN_SINCE" + if [[ -z "$crate_version" ]]; then + echo "FAIL - could not read the crate version from $CORE_TOML" >&2 + FAILURES=$((FAILURES + 1)) + elif [[ "$s_maj" != "$c_maj" || "$s_min" != "$c_min" ]]; then + echo "FAIL - MARKER_LATEST_SEEN_SINCE ($MARKER_LATEST_SEEN_SINCE) is not on the same" >&2 + echo " major.minor as the crate ($crate_version). Gate B skips its positive" >&2 + echo " equality check for every release below the constant, so a constant set" >&2 + echo " too high leaves the gate permanently vacuous and silent about it." >&2 + FAILURES=$((FAILURES + 1)) + elif [[ "$s_pat" -lt "$c_pat" ]]; then + echo "FAIL - MARKER_LATEST_SEEN_SINCE ($MARKER_LATEST_SEEN_SINCE) is BELOW the crate" >&2 + echo " version ($crate_version). It names the first release that emits" >&2 + echo " '$MARKER_LATEST_SEEN', and that marker is new in this tree -- no" >&2 + echo " already-published release emits it, so Gate B would demand the line" >&2 + echo " from binaries never built to log it." >&2 + FAILURES=$((FAILURES + 1)) + elif [[ "$s_pat" -gt $(( c_pat + SINCE_SKEW_MAX )) ]]; then + echo "FAIL - MARKER_LATEST_SEEN_SINCE ($MARKER_LATEST_SEEN_SINCE) is more than" >&2 + echo " $SINCE_SKEW_MAX patch releases ahead of the crate version ($crate_version)." >&2 + echo " Gate B skips its only positive assertion for every release below the" >&2 + echo " constant, so an over-high value disarms the gate permanently and" >&2 + echo " silently. If the release really has slipped this far, re-confirm the" >&2 + echo " value and widen SINCE_SKEW_MAX deliberately." >&2 + FAILURES=$((FAILURES + 1)) + else + echo "ok - MARKER_LATEST_SEEN_SINCE ($MARKER_LATEST_SEEN_SINCE) is the next release after the crate version ($crate_version)" + fi +fi +# The parse-failure marker gets a STRONGER pin than pin_marker can give. +# `failed to parse latest version` appears twice in auto_update.rs: the +# production warn!, and a comment inside its own `#[cfg(test)] mod tests` +# block. A whole-file grep is satisfied by the COMMENT, so rewording the +# real warn! left every assertion green -- and a node carrying the #5221 bug +# then logs check-ran + reworded-warn + check-complete, which the canary +# reports as "OK: parsed GitHub's response". The gate this PR exists to +# install would have been removable by an ordinary log reword, with CI green +# throughout. Bound the pin to the emitting call instead, so what is pinned +# is the code that runs. Both arms are pinned: they fail the same way and +# neither may drift silently. +pin_warn_literal() { + # pin_warn_literal + local desc="$1" file="$2" literal="$3" + if [[ ! -f "$file" ]]; then + echo "FAIL - $desc (source file not found: $file)" >&2 + FAILURES=$((FAILURES + 1)) + return + fi + # Whitespace stripped from both sides, as the INFO-level pin above does, + # so a rustfmt reflow cannot decide whether the canary is protected. + if [[ "$(tr -d '[:space:]' < "$file")" == *"tracing::warn!(\"${literal//[[:space:]]/}"* ]]; then + echo "ok - $desc" + else + echo "FAIL - $desc: no 'tracing::warn!' in $(basename "$file") still emits" >&2 + echo " '$literal' -- the canary greps for that text, so rewording it here" >&2 + echo " makes a broken updater indistinguishable from a healthy one (#5236)." >&2 + FAILURES=$((FAILURES + 1)) + fi +} +pin_warn_literal "source pin: parse-failure marker (latest-version arm)" \ + "$AU_SRC" "$MARKER_PARSE_FAIL latest version" +pin_warn_literal "source pin: parse-failure marker (current-version arm)" \ + "$AU_SRC" "$MARKER_PARSE_FAIL current version" +pin_marker "source pin: fetch-failure marker" "$AU_SRC" "$MARKER_FETCH_FAIL" + +# The observed-latest marker, pinned to its emitting `tracing::info!` for the +# same reason the parse-failure arms are pinned to their `warn!`: a whole-file +# grep tracks prose, and this one carries the gate's only POSITIVE assertion. +# It must also stay at INFO -- `release_max_level_info` compiles out anything +# below, so a `debug!` here would delete the equality check from every shipped +# binary while leaving all 30 assertions green. +if [[ "$(tr -d '[:space:]' < "$AU_SRC")" == *"tracing::info!(latest=%latest,\"${MARKER_LATEST_SEEN//[[:space:]]/}"* ]]; then + echo "ok - source pin: observed-latest marker is emitted at INFO with a latest= field" +else + echo "FAIL - source pin: no 'tracing::info!(latest = %latest, \"$MARKER_LATEST_SEEN\")' in auto_update.rs." >&2 + echo " Gate A's only positive assertion reads that line and that field. Without it the" >&2 + echo " gate falls back to 'the node did not complain', which a silently-wrong comparator" >&2 + echo " satisfies (#5236, review finding 32). A 'debug!' here is equally fatal: release" >&2 + echo " builds compile it out." >&2 + FAILURES=$((FAILURES + 1)) +fi + +# --- the trigger-site ENUMERATION ------------------------------------------- +# `MARKER_TRIGGERED_RE` has to match every site that requests an update. It +# missed the urgent one at :609 for as long as that site has existed, because +# the marker was a fixed string and the site says "triggering IMMEDIATE +# auto-update". +# +# The expected count must NOT come from the regex being audited. The first +# version of this pin computed it as `grep -cE "$MARKER_TRIGGERED_RE"`, so a +# site the regex failed to match was invisible to the count as well -- the pin +# could not detect the one thing it exists to detect. Demonstrated: adding a +# sixth site worded "triggering a fresh auto-update" left this suite fully +# green, including this assertion. (Rewording an EXISTING site was caught, so +# the pin was not useless, just blind in the direction that matters most.) +# +# Derive the expectation from the CODE DECISION instead. Every real trigger +# ends in `update_tx.send(...)`, which is what makes the node exit 42; the log +# line is commentary on that send. Two anchors, neither of them the regex: +# +# total sends -- every path that requests an update, whatever it +# logs. Catches a site added with a send spelled +# some other way. +# versioned sends -- `update_tx.send(new_version)`, the sites that +# detected a specific newer release. These are +# exactly the sites that must carry a trigger log +# line, so this is the number the regex must find. +# +# The remaining sends are the two forced-exit paths that send a SENTINEL rather +# than a detected version (`"unknown (hard timeout)"`, `"unknown (gateway +# mismatch)"`). They deliberately carry no trigger phrase -- they are "leave +# for auto-update", not "this release detected". `node_decided_to_update` does +# not see them, which is correct for the gates: neither is reachable in a +# canary run (both need hours of isolation with a version mismatch). +EXPECTED_SEND_SITES=7 +EXPECTED_TRIGGER_SITES=5 +# shellcheck disable=SC2016 # literal source text, must not expand +total_sends="$(grep -cF 'update_tx.send(' "$SRC" 2>/dev/null || echo 0)" +# shellcheck disable=SC2016 +versioned_sends="$(grep -cF 'update_tx.send(new_version)' "$SRC" 2>/dev/null || echo 0)" +actual_sites="$(grep -cE "$MARKER_TRIGGERED_RE" "$SRC" 2>/dev/null || echo 0)" +actual_refusals="$(grep -cF "$MARKER_NOT_TRIGGERED" "$SRC" 2>/dev/null || echo 0)" +actual_triggers=$((actual_sites - actual_refusals)) + +if [[ "$total_sends" -eq "$EXPECTED_SEND_SITES" && "$versioned_sends" -eq "$EXPECTED_TRIGGER_SITES" ]]; then + echo "ok - source pin: freenet.rs has $EXPECTED_SEND_SITES update_tx.send sites, $EXPECTED_TRIGGER_SITES of them version-detecting" +else + echo "FAIL - source pin: freenet.rs has $total_sends 'update_tx.send(' sites ($versioned_sends versioned)," >&2 + echo " expected $EXPECTED_SEND_SITES ($EXPECTED_TRIGGER_SITES versioned). An auto-update trigger path was added or removed." >&2 + echo " Update the enumeration comment in auto-update-canary.sh, MARKER_TRIGGERED_RE if the new" >&2 + echo " site's wording needs it, and these two counts -- together." >&2 + grep -nF 'update_tx.send(' "$SRC" >&2 + FAILURES=$((FAILURES + 1)) +fi + +# ...and the regex must match every one of the version-detecting sites. This is +# the assertion the old count could not make, because both sides of it were the +# same grep. +if [[ "$actual_triggers" -eq "$versioned_sends" ]]; then + echo "ok - source pin: MARKER_TRIGGERED_RE matches all $versioned_sends version-detecting trigger sites" +else + echo "FAIL - source pin: MARKER_TRIGGERED_RE matches $actual_triggers trigger log lines, but freenet.rs has" >&2 + echo " $versioned_sends version-detecting trigger sites ('update_tx.send(new_version)')." >&2 + echo " ($actual_sites regex matches minus $actual_refusals refusals.) If the regex matches FEWER, a" >&2 + echo " trigger site is worded so the canary cannot see it -- a node that took that path reads as one" >&2 + echo " that never decided to update, which is how the urgent site at :609 went unseen. If it matches" >&2 + echo " MORE, the regex is picking up prose. Either way, reconcile MARKER_TRIGGERED_RE with the" >&2 + echo " enumeration comment in auto-update-canary.sh." >&2 + grep -nE "$MARKER_TRIGGERED_RE" "$SRC" >&2 + FAILURES=$((FAILURES + 1)) +fi + +echo +if [[ "$FAILURES" -eq 0 ]]; then + echo "All auto-update-canary assertions passed." +else + echo "$FAILURES assertion(s) FAILED." >&2 + exit 1 +fi diff --git a/scripts/release.sh b/scripts/release.sh index d61e22c042..ab67da8427 100755 --- a/scripts/release.sh +++ b/scripts/release.sh @@ -30,8 +30,9 @@ VERSION="" MIN_COMPATIBLE="" DRY_RUN=false SKIP_TESTS=false -DEPLOY_LOCAL=false -DEPLOY_REMOTE=false +# No DEPLOY_LOCAL / DEPLOY_REMOTE: `--deploy-local` and `--deploy-remote` are +# deprecated and their handler below only prints a note, so the two variables +# were written once and never read again. # Release steps for state tracking (in execution order) RELEASE_STEPS=( @@ -152,13 +153,19 @@ version_compare() { local v1="$1" local v2="$2" - local v1_major=$(echo "$v1" | cut -d. -f1) - local v1_minor=$(echo "$v1" | cut -d. -f2) - local v1_patch=$(echo "$v1" | cut -d. -f3) + local v1_major + v1_major=$(echo "$v1" | cut -d. -f1) || true + local v1_minor + v1_minor=$(echo "$v1" | cut -d. -f2) || true + local v1_patch + v1_patch=$(echo "$v1" | cut -d. -f3) || true - local v2_major=$(echo "$v2" | cut -d. -f1) - local v2_minor=$(echo "$v2" | cut -d. -f2) - local v2_patch=$(echo "$v2" | cut -d. -f3) + local v2_major + v2_major=$(echo "$v2" | cut -d. -f1) || true + local v2_minor + v2_minor=$(echo "$v2" | cut -d. -f2) || true + local v2_patch + v2_patch=$(echo "$v2" | cut -d. -f3) || true if [[ $v1_major -gt $v2_major ]]; then echo "1"; return; fi if [[ $v1_major -lt $v2_major ]]; then echo "-1"; return; fi @@ -177,7 +184,8 @@ download_release_binary() { local target_dir="${2:-/tmp}" # Detect architecture - local arch=$(uname -m) + local arch + arch=$(uname -m) || true local asset_name="" case "$arch" in @@ -227,7 +235,8 @@ download_release_binary() { echo " Binary: $binary_path" >&2 # Verify the binary - local dl_version=$("$binary_path" --version 2>/dev/null | head -1) + local dl_version + dl_version=$("$binary_path" --version 2>/dev/null | head -1) || true echo " Version: $dl_version" >&2 # Output only the path to stdout for capture @@ -345,15 +354,18 @@ detect_pr_state() { local branch_name="release/v$VERSION" # Check for existing PR - local pr_info=$(gh pr list --head "$branch_name" --state all --limit 1 \ + local pr_info + pr_info=$(gh pr list --head "$branch_name" --state all --limit 1 \ --json number,state 2>/dev/null | jq -r '.[0] | "\(.number)|\(.state)"' 2>/dev/null || echo "") if [[ -z "$pr_info" || "$pr_info" == "null|null" ]]; then return # No PR exists fi - local pr_number=$(echo "$pr_info" | cut -d'|' -f1) - local pr_state=$(echo "$pr_info" | cut -d'|' -f2) + local pr_number + pr_number=$(echo "$pr_info" | cut -d'|' -f1) || true + local pr_state + pr_state=$(echo "$pr_info" | cut -d'|' -f2) || true if [[ -n "$pr_number" && "$pr_number" != "null" ]]; then COMPLETED_STEPS["PR_CREATED"]=1 @@ -365,23 +377,34 @@ detect_pr_state() { } # Detect if tag exists +# +# No `... | grep -q` anywhere below: this script sets `pipefail`, and a +# short-circuiting reader makes the producer die with SIGPIPE (141), which +# pipefail then promotes to the pipeline's status -- so a tag that IS present +# reads as ABSENT. See the SIGPIPE section of .claude/rules/bug-prevention-patterns.md. +# Ask git for the one ref we care about and test whether the answer is empty. detect_tag_state() { # Check local tags - if git tag -l | grep -q "^v$VERSION$"; then + if [[ -n "$(git tag -l "v$VERSION")" ]]; then COMPLETED_STEPS["TAG_CREATED"]=1 return fi # Check remote tags - if git ls-remote --tags origin 2>/dev/null | grep -q "refs/tags/v$VERSION$"; then + if [[ -n "$(git ls-remote --tags origin "refs/tags/v$VERSION" 2>/dev/null)" ]]; then COMPLETED_STEPS["TAG_CREATED"]=1 fi } # Detect if crates are published detect_crates_state() { - # Check if freenet is published at this version - if cargo search freenet --limit 1 2>/dev/null | grep -q "freenet = \"$VERSION\""; then + # Check if freenet is published at this version. + # `|| true` because the old form ran inside an `if` condition, where errexit + # is disabled; a bare assignment is not, so a failing `cargo search` would + # otherwise abort the release. + local search_out + search_out="$(cargo search freenet --limit 1 2>/dev/null || true)" + if [[ "$search_out" == *"freenet = \"$VERSION\""* ]]; then COMPLETED_STEPS["CRATES_PUBLISHED"]=1 fi } @@ -717,11 +740,13 @@ create_release_pr() { # Check if a release PR for this version already exists or was merged echo -n " Checking for existing release PR... " - local existing_pr=$(gh pr list --head "$branch_name" --state all --limit 1 --json number,state,title --jq '.[] | "\(.number)|\(.state)|\(.title)"' 2>/dev/null || echo "") + local existing_pr + existing_pr=$(gh pr list --head "$branch_name" --state all --limit 1 --json number,state,title --jq '.[] | "\(.number)|\(.state)|\(.title)"' 2>/dev/null || echo "") if [[ -n "$existing_pr" ]]; then pr_number=$(echo "$existing_pr" | cut -d'|' -f1) - local pr_state=$(echo "$existing_pr" | cut -d'|' -f2) + local pr_state + pr_state=$(echo "$existing_pr" | cut -d'|' -f2) || true echo "found #$pr_number ($pr_state)" if [[ "$pr_state" == "MERGED" ]]; then @@ -886,7 +911,9 @@ Generated by: \`scripts/release.sh\`" \ failed_jobs=$(gh run view "$run_id" --json jobs --jq '.jobs[] | select(.conclusion == "failure") | .name' 2>/dev/null || echo "") if [[ -n "$failed_jobs" ]]; then echo " Failed jobs:" - echo "$failed_jobs" | sed 's/^/ - /' + while IFS= read -r _job; do + echo " - $_job" + done <<< "$failed_jobs" echo echo " To view logs: gh run view $run_id --log-failed" fi @@ -920,7 +947,8 @@ generate_release_notes() { local version="$1" # Find the previous release to determine what PRs to include - local prev_version=$(gh release list --limit 50 --json tagName,createdAt --jq 'sort_by(.createdAt) | reverse | .[].tagName' 2>/dev/null | grep -v "^v${version}$" | head -1 | sed 's/^v//') + local prev_version + prev_version=$(gh release list --limit 50 --json tagName,createdAt --jq 'sort_by(.createdAt) | reverse | .[].tagName' 2>/dev/null | grep -v "^v${version}$" | head -1 | sed 's/^v//') || true if [[ -z "$prev_version" ]]; then # Fallback to basic release notes if we can't find previous release @@ -936,10 +964,12 @@ See commit history for detailed changes. return fi - local prev_date=$(gh release view "v${prev_version}" --json createdAt --jq '.createdAt' 2>/dev/null) + local prev_date + prev_date=$(gh release view "v${prev_version}" --json createdAt --jq '.createdAt' 2>/dev/null) || true # Fetch merged PRs since the previous release - local prs=$(gh pr list --search "is:pr is:merged merged:>${prev_date}" --limit 100 --json number,title --jq '.[] | "#\(.number)|\(.title)"' 2>/dev/null || echo "") + local prs + prs=$(gh pr list --search "is:pr is:merged merged:>${prev_date}" --limit 100 --json number,title --jq '.[] | "#\(.number)|\(.title)"' 2>/dev/null || echo "") if [[ -z "$prs" ]]; then echo "Release $version @@ -958,8 +988,10 @@ See commit history for detailed changes. local maintenance="" while IFS= read -r pr; do - local number=$(echo "$pr" | cut -d'|' -f1) - local title=$(echo "$pr" | cut -d'|' -f2-) + local number + number=$(echo "$pr" | cut -d'|' -f1) || true + local title + title=$(echo "$pr" | cut -d'|' -f2-) || true # Skip the release PR itself if [[ "$title" =~ ^🚀\ Release || "$title" =~ ^Release\ v ]]; then @@ -1023,7 +1055,9 @@ publish_crates() { # Check if freenet is already published echo -n " Checking if freenet $VERSION is already published... " - if cargo search freenet --limit 1 2>/dev/null | grep -q "freenet = \"$VERSION\""; then + local freenet_search + freenet_search="$(cargo search freenet --limit 1 2>/dev/null || true)" + if [[ "$freenet_search" == *"freenet = \"$VERSION\""* ]]; then echo "yes" echo " ✓ freenet $VERSION already published to crates.io" freenet_published=true @@ -1040,7 +1074,9 @@ publish_crates() { # Check if fdev is already published echo -n " Checking if fdev $FDEV_VERSION is already published... " - if cargo search fdev --limit 1 2>/dev/null | grep -q "fdev = \"$FDEV_VERSION\""; then + local fdev_search + fdev_search="$(cargo search fdev --limit 1 2>/dev/null || true)" + if [[ "$fdev_search" == *"fdev = \"$FDEV_VERSION\""* ]]; then echo "yes" echo " ✓ fdev $FDEV_VERSION already published to crates.io" fdev_published=true @@ -1090,7 +1126,7 @@ create_github_release() { fi # Check if tag already exists - if git tag | grep -q "^v$VERSION$"; then + if [[ -n "$(git tag -l "v$VERSION")" ]]; then echo " ℹ️ Tag v$VERSION already exists locally" mark_completed "TAG_CREATED" else @@ -1098,7 +1134,7 @@ create_github_release() { fi # Check if tag exists on remote - if git ls-remote --tags origin | grep -q "refs/tags/v$VERSION$"; then + if [[ -n "$(git ls-remote --tags origin "refs/tags/v$VERSION" 2>/dev/null)" ]]; then echo " ℹ️ Tag v$VERSION already exists on remote" mark_completed "TAG_CREATED" else @@ -1107,7 +1143,8 @@ create_github_release() { fi echo -n " Generating release notes... " - local release_notes=$(generate_release_notes "$VERSION") + local release_notes + release_notes=$(generate_release_notes "$VERSION") || true echo "✓" echo -n " Creating GitHub release... " @@ -1200,17 +1237,102 @@ trigger_gateway_updates() { fi } +# The display name of the cross-compile job that uploads the assets, runs the +# BLOCKING pre-flight canary, and un-drafts the release. Must match `name:` on +# the `attach-to-release` job in .github/workflows/cross-compile.yml. +ATTACH_JOB_NAME='Attach binaries to GitHub release' + +# That job's own "status:conclusion", empty when it cannot be determined. +# +# Deliberately NOT the run's aggregate. The same run also contains the +# post-publish self-update canary (Gate B, #5222), which is by design +# NON-blocking: it starts only after `attach-to-release` has already published +# the release, and its job exists to report, not to gate. Reading the run's +# status therefore makes this script (a) keep waiting after the release is +# published and (b) treat a Gate B failure as a failed release -- and since +# `wait_for_binaries` is called bare under `set -e`, that aborts the driver +# before it updates the gateways or announces to Matrix and River. A release +# that published perfectly well would silently never be announced. +# +# Empty output means "we do not know" -- the job has not started, was renamed, +# or `gh` failed -- and every caller must treat it as such rather than as a +# pass. A rename shows up as a wait that times out loudly; it cannot fail open. +# +# CALLERS MUST WRITE `$(attach_job_state "$id" || echo "")`. This function ends +# in a bare `gh`, so a `gh` failure IS its exit status, and `var=$(cmd)` is a +# simple command whose status is `cmd`'s -- under `set -e` that aborts the whole +# driver rather than yielding the "we do not know" this comment promises. The +# same guard is needed on every bare `$(gh ...)` in this file, including +# `$(gh ... | head -1)`, which `set -o pipefail` makes fail too. Pinned by +# scripts/release_wait_for_binaries_test.sh. +attach_job_state() { + local run_id="$1" + gh run view "$run_id" --repo freenet/freenet-core --json jobs \ + --jq "[.jobs[] | select(.name == \"$ATTACH_JOB_NAME\")] | .[0] | select(. != null) | \"\(.status):\(.conclusion)\"" 2>/dev/null +} + publish_draft_release() { # Publish the draft release (idempotent -- no-op if already published). - # The cross-compile workflow also publishes via gh release edit --draft=false - # as a belt-and-suspenders measure (see cross-compile.yml). + # + # The cross-compile workflow publishes via `gh release edit --draft=false` + # as its final step, AFTER the blocking auto-update pre-flight canary + # (#5222). This belt-and-suspenders copy must therefore never fire while + # that workflow is still deciding: between asset upload and the canary's + # verdict there is now a multi-minute window in which every asset is + # present but the release has deliberately NOT been published. The caller + # below reaches this function on exactly that condition ("all required + # binaries already available"), so without this guard the local driver + # would race in and publish a release whose updater the gate was in the + # middle of rejecting -- silently turning a blocking gate into no gate. local is_draft - is_draft=$(gh release view "v$VERSION" --repo freenet/freenet-core --json isDraft --jq '.isDraft' 2>/dev/null || echo "false") - if [[ "$is_draft" == "true" ]]; then - echo -n " Publishing draft release... " - gh release edit "v$VERSION" --repo freenet/freenet-core --draft=false > /dev/null - echo "✓" + is_draft=$(gh release view "v$VERSION" --repo freenet/freenet-core --json isDraft --jq '.isDraft' 2>/dev/null || echo "unknown") + if [[ "$is_draft" == "false" ]]; then + return 0 # already published by the workflow -- nothing left to gate + fi + if [[ "$is_draft" != "true" ]]; then + # `gh` failed, so we do not know whether this is still a draft. Every + # other unknown in this function refuses, and this one must too: it + # coerced to "false" and returned 0, which never published an ungated + # release, but DID report success to the caller -- so the driver went on + # to update the gateways and announce a release that may still have been + # an unpublished draft. + echo " ⏸ Cannot tell whether v$VERSION is still a draft ('gh' failed)." >&2 + echo " Refusing to report success: on an unknown the driver would" >&2 + echo " otherwise update the gateways and announce to Matrix and River" >&2 + echo " a release that may still be an unpublished draft." >&2 + return 1 + fi + + # It IS still a draft, so the gate's verdict decides. Anything other than a + # successfully-concluded ATTACH job means "we do not know that the canary + # passed", and publishing on an unknown gate state is the fail-open this + # guard exists to prevent. A missing run, a missing job, or a `gh` failure + # all yield "" -- all of them are "we do not know", and all must refuse. + local run_id job_state + run_id=$(gh run list --repo freenet/freenet-core \ + --workflow=cross-compile.yml --branch "v$VERSION" \ + --json databaseId --jq '.[0].databaseId // empty' 2>/dev/null || echo "") + job_state="" + if [[ -n "$run_id" ]]; then + # `|| echo ""` per attach_job_state's contract: without it a `gh` blip + # aborts the driver here instead of printing the refusal below. + job_state=$(attach_job_state "$run_id" || echo "") + fi + if [[ "$job_state" != "completed:success" ]]; then + echo " ⏸ NOT publishing v$VERSION: '$ATTACH_JOB_NAME' is '${job_state:-unknown}'." >&2 + echo " Publication is gated on the auto-update pre-flight canary (#5222)," >&2 + echo " which runs between asset upload and un-draft. Let the workflow" >&2 + echo " publish, or fix the gate. Do NOT un-draft by hand -- a release" >&2 + echo " whose updater is broken cannot deliver its own fix." >&2 + # MUST be non-zero. Returning 0 here made the caller report success, so + # the driver went on to update the gateways and announce to Matrix and + # River a release that was still an unpublished draft. + return 1 fi + + echo -n " Publishing draft release... " + gh release edit "v$VERSION" --repo freenet/freenet-core --draft=false > /dev/null + echo "✓" } verify_required_binaries() { @@ -1221,8 +1343,18 @@ verify_required_binaries() { return 1 fi local missing=() + # Whole-line match against the asset list, done with a bash glob rather than + # `echo "$assets" | grep -xqF`. Under `pipefail` that form makes `echo` take + # SIGPIPE the moment `grep -q` short-circuits on a match, and 141 becomes the + # pipeline's status -- so a binary that IS present reads as MISSING. Measured + # here at 46 hits in 20000 iterations under 24-way CPU load (0 in a quiet + # window), i.e. it fires exactly on the contended runners this gate runs on. + # The consequence is the one the comment above warns about: wait_for_binaries + # returns 1 and the driver dies AFTER publishing but BEFORE the gateway + # updates and announcements. + local assets_nl=$'\n'"$assets"$'\n' for bin in "${required[@]}"; do - if ! echo "$assets" | grep -xqF "$bin"; then + if [[ "$assets_nl" != *$'\n'"$bin"$'\n'* ]]; then missing+=("$bin") fi done @@ -1274,7 +1406,10 @@ wait_for_binaries() { local find_elapsed=0 local find_max=120 # 2 minutes to find the run while [[ $find_elapsed -lt $find_max ]]; do - run_id=$(gh run list --workflow=cross-compile.yml --repo freenet/freenet-core --json databaseId,headBranch --jq ".[] | select(.headBranch == \"v$VERSION\") | .databaseId" 2>/dev/null | head -1) + # `|| echo ""` so a transient `gh` failure retries on the next tick + # instead of aborting the driver. `set -o pipefail` propagates `gh`'s + # status out of the pipeline, so `head -1` does NOT absorb it. + run_id=$(gh run list --workflow=cross-compile.yml --repo freenet/freenet-core --json databaseId,headBranch --jq ".[] | select(.headBranch == \"v$VERSION\") | .databaseId" 2>/dev/null | head -1 || echo "") if [[ -n "$run_id" ]]; then break fi @@ -1298,13 +1433,44 @@ wait_for_binaries() { local interval=30 while [[ $elapsed -lt $max_wait ]]; do - local status conclusion - status=$(gh run view "$run_id" --repo freenet/freenet-core --json status --jq '.status' 2>/dev/null) + # Watch the JOB that attaches and publishes, not the whole RUN. The run + # also carries the post-publish self-update canary (Gate B, #5222), + # which starts only after this job has published the release and is + # explicitly non-blocking -- see attach_job_state for what waiting on + # the run instead costs. An empty state means the job has not started + # yet (it waits on all six build jobs), so keep waiting. + # `|| echo ""` per attach_job_state's contract. A single rate-limit or + # 5xx anywhere in this multi-minute wait would otherwise abort the + # driver mid-release: the release publishes, but the gateways are never + # updated and it is never announced. Empty just means "poll again". + local job_state status conclusion + job_state=$(attach_job_state "$run_id" || echo "") + status="${job_state%%:*}" + conclusion="${job_state#*:}" + + # No job at all, and the RUN has finished: the job was cancelled before + # it was created, or renamed out from under ATTACH_JOB_NAME. Nothing is + # ever going to appear, so stop rather than burn the full timeout -- + # watching the job instead of the run must not cost us this fast exit. + # Reported as UNKNOWN, never as a pass. + if [[ -z "$job_state" ]]; then + # Same guard, and it matters most here: this branch is the whole + # build window (job_state is empty until the six build jobs finish), + # so it is the busiest `gh` call in the release. + local run_status + run_status=$(gh run view "$run_id" --repo freenet/freenet-core --json status --jq '.status' 2>/dev/null || echo "") + if [[ "$run_status" == "completed" ]]; then + echo " ✗ '$ATTACH_JOB_NAME' never reported a result, and the run has finished" + echo " (cancelled before the job started, or the job was renamed --" + echo " if renamed, update ATTACH_JOB_NAME in this script)." + echo " Check: https://github.com/freenet/freenet-core/actions/runs/$run_id" + return 1 + fi + fi if [[ "$status" == "completed" ]]; then - conclusion=$(gh run view "$run_id" --repo freenet/freenet-core --json conclusion --jq '.conclusion' 2>/dev/null) if [[ "$conclusion" == "success" ]]; then - echo " ✓ Cross-compile workflow completed successfully" + echo " ✓ Binaries attached and release published" # Verify all required platform binaries are uploaded sleep 5 # Brief delay for asset upload @@ -1313,19 +1479,21 @@ wait_for_binaries() { publish_draft_release return 0 else - echo " ✗ Cross-compile succeeded but some required binaries are missing" + echo " ✗ Attach job succeeded but some required binaries are missing" echo " Check: https://github.com/freenet/freenet-core/actions/runs/$run_id" return 1 fi else - echo " ✗ Cross-compile workflow failed (conclusion: $conclusion)" - echo " Binaries will NOT be available for auto-update." + echo " ✗ '$ATTACH_JOB_NAME' failed (conclusion: $conclusion)" + echo " Either a build is missing or the BLOCKING auto-update" + echo " pre-flight canary (#5222) rejected the binary. Binaries" + echo " will NOT be available for auto-update." echo " Check: https://github.com/freenet/freenet-core/actions/runs/$run_id" return 1 fi fi - printf " Waiting... (%ds elapsed, status: %s)\r" "$elapsed" "$status" + printf " Waiting... (%ds elapsed, status: %s)\r" "$elapsed" "${status:-pending}" sleep $interval elapsed=$((elapsed + interval)) done diff --git a/scripts/release_canary_wiring_test.sh b/scripts/release_canary_wiring_test.sh new file mode 100755 index 0000000000..fa3fc01f18 --- /dev/null +++ b/scripts/release_canary_wiring_test.sh @@ -0,0 +1,364 @@ +#!/usr/bin/env bash +# Regression test for the WIRING of the blocking auto-update pre-flight canary +# (#5222/#5236) -- as distinct from the canary's own logic, which +# auto-update-canary_test.sh covers. +# +# THE GAP THIS CLOSES. The canary only gates anything because of where it sits +# in .github/workflows/cross-compile.yml: inside the `attach-to-release` job, +# AFTER the assets are uploaded and BEFORE `gh release edit --draft=false`. +# That position is the entire mechanism. Delete the step, move the publish +# above it, or mark it `continue-on-error`, and the gate becomes a no-op while +# every other test in this repo stays green -- which is precisely the +# silently-removable-gate shape the canary was introduced to eliminate. A gate +# whose removal is invisible is not a gate. +# +# It also pins the two ends of a string that must agree across files: +# release.sh's ATTACH_JOB_NAME is how the release driver finds this job's +# status, and nothing else checks that the name still matches. Rename the job +# in the workflow and the driver waits for a job that will never appear, then +# times out ~20 minutes later reporting UNKNOWN -- on a release that in fact +# published fine. +# +# Same shape as release_mergequeue_test.sh, which greps release.yml for the +# `gh pr merge` invocation it must keep. +# +# Run manually: bash scripts/release_canary_wiring_test.sh +# Also wired into CI (the Fmt job in .github/workflows/ci.yml). + +set -uo pipefail + +SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" +WF="$SCRIPT_DIR/../.github/workflows/cross-compile.yml" +RELEASE_SH="$SCRIPT_DIR/release.sh" + +FAILURES=0 + +fail() { + echo "FAIL - $1" >&2 + shift + for line in "$@"; do echo " $line" >&2; done + FAILURES=$((FAILURES + 1)) +} +pass() { echo "ok - $1"; } + +for f in "$WF" "$RELEASE_SH"; do + if [[ ! -f "$f" ]]; then + echo "FAIL: $f not found" >&2 + exit 1 + fi +done + +# The `attach-to-release:` job block: from its own key to the next top-level +# job key. Job keys sit at exactly two spaces; everything inside the job is +# indented further, so this needs no YAML parser and cannot be fooled by a +# matching string in a comment elsewhere in the file. +# Comment-only lines are dropped, but the original line NUMBERS are kept, so +# ordering comparisons stay meaningful. This is load-bearing: the job's own +# comments discuss `--draft=false` (explaining the RELEASE_PAT coalesce) well +# above the step that runs it, so matching raw text would compare the canary +# against a sentence and report the gate inverted. A pin that fails on prose is +# no better than one that passes on prose. +JOB_BLOCK="$(awk ' + /^ attach-to-release:[[:space:]]*$/ { inblock = 1; print NR ":" $0; next } + inblock && /^ [A-Za-z_.-]+:/ { inblock = 0 } + inblock && $0 !~ /^[[:space:]]*#/ { print NR ":" $0 } +' "$WF")" + +if [[ -z "$JOB_BLOCK" ]]; then + fail "the 'attach-to-release' job no longer exists in cross-compile.yml" \ + "That job is where the canary gates publication; release.sh watches it by name." + echo + echo "$FAILURES assertion(s) FAILED." >&2 + exit 1 +fi +pass "cross-compile.yml still has an 'attach-to-release' job" + +# line_of -- first matching line number INSIDE the job block. +line_of() { + printf '%s\n' "$JOB_BLOCK" | grep -E "$1" | head -1 | cut -d: -f1 +} + +# step_block -- the whole STEP containing , as `NNN:text` lines. +# +# Bounded by the `- name:` at or above and the next one below it (or the +# end of the job). Step keys such as `if:` and `continue-on-error:` sit ABOVE +# the `run:` that holds the invocation, so anything anchored on the invocation +# line alone cannot see them -- which is exactly how the publish step's own +# `if:` went unpinned while the canary step's was covered. +step_block() { + local at="$1" start end + start="$(printf '%s\n' "$JOB_BLOCK" \ + | awk -F: -v a="$at" '$1 <= a && /^[0-9]+: - name:/ { n = $1 } END { print n }')" + end="$(printf '%s\n' "$JOB_BLOCK" \ + | awk -F: -v a="$at" '$1 > a && /^[0-9]+: - name:/ { print $1; exit }')" + [[ -z "$end" ]] && end=999999 + printf '%s\n' "$JOB_BLOCK" | awk -F: -v a="$start" -v b="$end" '$1 >= a && $1 < b' +} + +# --- 1. the canary step still runs ------------------------------------------ +CANARY_LINE="$(line_of 'auto-update-canary\.sh preflight')" +if [[ -n "$CANARY_LINE" ]]; then + pass "the pre-flight canary still runs in attach-to-release (line $CANARY_LINE)" +else + fail "the pre-flight canary is GONE from the attach-to-release job" \ + "Nothing now blocks publication on the shipping binary's updater working." \ + "This is the #5222 regression the canary exists to prevent: v0.2.120 and" \ + "v0.2.121 both shipped with a dead updater and every signal stayed green." +fi + +# --- 2. it runs BEFORE the release is un-drafted ---------------------------- +# Presence alone does not gate anything: a canary that runs after the publish +# is a report, not a gate, and the release has already reached users by then. +PUBLISH_LINE="$(line_of '\-\-draft=false')" +if [[ -z "$PUBLISH_LINE" ]]; then + fail "no 'gh release edit --draft=false' in the attach-to-release job" \ + "If publication moved elsewhere, the canary no longer gates it." +elif [[ -n "$CANARY_LINE" ]]; then + if [[ "$CANARY_LINE" -lt "$PUBLISH_LINE" ]]; then + pass "the canary runs BEFORE '--draft=false' (canary $CANARY_LINE < publish $PUBLISH_LINE)" + else + fail "the canary runs AFTER the release is published (canary $CANARY_LINE > publish $PUBLISH_LINE)" \ + "Steps in a job run in file order, so this is no longer a gate: the" \ + "release is public before the updater is ever exercised. The whole" \ + "point of Gate A is that a failure costs a stuck DRAFT, not a" \ + "stranded fleet." + fi +fi + +# --- 3. it is not neutered in place ----------------------------------------- +# `continue-on-error: true` leaves the step present, running, and visibly +# green-ish in the UI while the job proceeds to publish regardless -- the +# cheapest way to disable this gate without appearing to remove it. +# +# The scan must cover the whole STEP, not the run: line onwards. Step keys +# (`continue-on-error`, `if`, `timeout-minutes`) sit ABOVE the `run:` that +# contains the invocation, so a scan anchored on the invocation line misses +# them entirely -- verified by mutation: this assertion did not fire until the +# bounds were widened to the step. +if [[ -n "$CANARY_LINE" ]]; then + CANARY_STEP="$(step_block "$CANARY_LINE")" + NEUTERED="$(printf '%s\n' "$CANARY_STEP" \ + | grep -cE 'continue-on-error:[[:space:]]*true|^[0-9]+: if:[[:space:]]*false')" + if [[ "$NEUTERED" -eq 0 ]]; then + pass "the canary step is not disabled in place" + else + fail "the canary step is disabled in place ('continue-on-error: true' or 'if: false')" \ + "It still runs and still reports, but the job publishes the release" \ + "whatever it finds. That is a gate in appearance only." + fi + + # --- 3a. ...and its shell does not swallow the canary's exit status ------ + # The step-key checks above are blind to the SHELL. Appending `|| true` to + # the invocation leaves the step present, before the publish, and without + # `continue-on-error` -- every assertion here passed under exactly that + # mutation, because assertion 1 matches the invocation as a SUBSTRING and + # anything appended to the line is invisible to it. + # + # This is the likelier of the two neutering routes, and the worse one. + # `|| true` is the reflex fix when a gate false-positives at 2am, and it + # does not read as disabling a gate -- which is exactly why it has to fail + # loudly here. The value of this gate is that removing it cannot be quiet. + # + # Scanning the whole step rather than just the canary line: `set +e` + # anywhere in the run block has the same effect, and the step is three + # lines, so there is no legitimate use of these to trip over. Comment-only + # lines were dropped when JOB_BLOCK was built, so a `# || true` in prose + # cannot fire this. + SWALLOWED="$(printf '%s\n' "$CANARY_STEP" \ + | grep -cE '\|\|[[:space:]]*(true|:)[[:space:]]*$|set[[:space:]]+\+e')" + if [[ "$SWALLOWED" -eq 0 ]]; then + pass "the canary step's shell does not swallow its own exit status" + else + fail "the canary step swallows its own exit status ('|| true', '|| :' or 'set +e')" \ + "$(printf '%s\n' "$CANARY_STEP" | grep -E '\|\|[[:space:]]*(true|:)[[:space:]]*$|set[[:space:]]+\+e')" \ + "The step still runs, still reports, and still sits before the publish," \ + "but it can no longer fail -- so nothing blocks publication. This is the" \ + "cheapest possible way to disable the gate and the least visible: it looks" \ + "like error handling, not like removing a release gate." + fi +fi + +# --- 3b. ...and the PUBLISH step is not made unconditional ------------------ +# The mirror image of the check above, and the hole it left. Assertion 3 asks +# whether the CANARY is disabled; nothing asked whether the PUBLISH step was +# made to run regardless of it. Both produce the same outcome -- a red canary +# that no longer blocks publication -- and only one was pinned. +# +# Demonstrated on this branch: adding `if: always()` to the `Publish release` +# step neutered Gate A completely and all six assertions here stayed GREEN. +# release.sh's belt-and-suspenders check gives no cover either, because the +# workflow really did publish, so `isDraft` reads false. +# +# Steps default to running only if every earlier step in the job succeeded, and +# that default IS the gate. The publish step has no `if:` today, and this pins +# that state rather than trying to judge which conditionals are safe. +# +# Deliberately stricter than "no always()/failure()/cancelled()". Whether an +# expression can evaluate true after a failed step is not something a grep +# should be deciding -- `success() || github.actor == 'x'` overrides the default +# without naming any of those functions. An `if:` on the one step whose +# conditional execution IS the release gate deserves a human look, so any `if:` +# at all fails here. If a legitimate one is ever needed, the person adding it +# updates this assertion on purpose, which is the point. +if [[ -n "$PUBLISH_LINE" ]]; then + PUBLISH_STEP="$(step_block "$PUBLISH_LINE")" + PUBLISH_IF="$(printf '%s\n' "$PUBLISH_STEP" | grep -E '^[0-9]+: if:')" + if [[ -z "$PUBLISH_IF" ]]; then + pass "the publish step has no 'if:', so it still runs only when the canary passed" + else + fail "the publish step has acquired an 'if:'" \ + "$(printf '%s\n' "$PUBLISH_IF")" \ + "Steps run only after every earlier step succeeded, and that default is" \ + "the ENTIRE mechanism by which the canary blocks publication. An 'if:'" \ + "here can override it -- 'if: always()' publishes the release even when" \ + "the canary failed, and the gate is gone without the canary step being" \ + "touched at all. If this conditional is genuinely wanted, confirm it" \ + "cannot evaluate true after a failed step, then update this assertion." + fi +fi + +# --- 4. CI must not pre-set CANARY_EXPECTED_LATEST -------------------------- +# Gate A resolves the expected release itself, from the same `releases/latest` +# redirect the node uses, and refuses if it cannot. A value supplied by the +# workflow would displace that resolution with a hand-maintained string. +# +# Note what this does and does not protect against, because the commit that +# introduced the skip branch overstated it. A pinned value can only make the +# check FAIL -- it cannot make it PASS vacuously -- provided the pinned value +# is WRONG. Pin it CORRECTLY (say to the tag being released, which during +# Gate A is not yet what `releases/latest` returns) and you have replaced a +# resolved fact with an asserted one: the gate then compares the node's answer +# against a constant somebody typed, which is precisely the class of check this +# canary exists to replace. Either way it should not be here, so pin its +# absence rather than reasoning about which failure mode it would cause. +# +# Nothing sets it today; that is the state being pinned. +ARMED="$(printf '%s\n' "$JOB_BLOCK" | grep -cE 'CANARY_EXPECTED_LATEST')" +if [[ "$ARMED" -eq 0 ]]; then + pass "the workflow does not pre-set CANARY_EXPECTED_LATEST (Gate A resolves it)" +else + fail "the attach-to-release job sets CANARY_EXPECTED_LATEST" \ + "Gate A resolves the expected release from the same redirect the node reads," \ + "and refuses if it cannot. A workflow-supplied value replaces that resolved" \ + "fact with a hand-maintained constant -- and if it is wrong, it fails a" \ + "healthy release for a difference that is not a bug." \ + "$(printf '%s\n' "$JOB_BLOCK" | grep -E 'CANARY_EXPECTED_LATEST')" +fi + +# --- 5. release.sh and the workflow agree on the job name ------------------- +# release.sh reads this job's status by DISPLAY NAME. Nothing else pins the +# pair, and a rename on either side is silent: the driver simply never sees the +# job, waits out its 20-minute timeout, and reports UNKNOWN for a release that +# published normally. +WF_JOB_NAME="$(printf '%s\n' "$JOB_BLOCK" \ + | sed -n 's/^[0-9]*: name:[[:space:]]*//p' | head -1 \ + | sed "s/^['\"]//;s/['\"]$//")" +SH_JOB_NAME="$(sed -n "s/^ATTACH_JOB_NAME=//p" "$RELEASE_SH" | head -1 \ + | sed "s/^['\"]//;s/['\"]$//")" + +if [[ -z "$WF_JOB_NAME" ]]; then + fail "the attach-to-release job has no 'name:' in cross-compile.yml" \ + "release.sh matches on the display name, which defaults to the job KEY" \ + "when 'name:' is absent -- so removing it silently breaks the driver." +elif [[ -z "$SH_JOB_NAME" ]]; then + fail "ATTACH_JOB_NAME not found in release.sh" +elif [[ "$WF_JOB_NAME" == "$SH_JOB_NAME" ]]; then + pass "release.sh ATTACH_JOB_NAME matches the workflow job name ('$WF_JOB_NAME')" +else + fail "release.sh and cross-compile.yml disagree on the attach job's name" \ + "cross-compile.yml: '$WF_JOB_NAME'" \ + "release.sh: '$SH_JOB_NAME'" \ + "The driver polls for the workflow's name, so it would wait for a job" \ + "that never appears and time out reporting UNKNOWN." +fi + +# --- 6. the failure notification still covers BOTH gates -------------------- +# Gate A blocks publication by failing, which leaves the release stuck as a +# DRAFT -- a silent state. Nobody is watching the Actions tab during a release; +# the Matrix message is how anyone finds out. Gate B runs after publication and +# cannot block anything, so the notification is its ONLY output. +# +# Neither the notify job nor Gate B's job was referenced by any test in this +# repo before this. Demonstrated on this branch: deleting the two +# `needs.attach-to-release.result` clauses from the notify job's `if:` -- +# reinstating exactly the silent-Gate-A regression the workflow comment +# describes -- left all four suites GREEN. +# +# Whole-file scan, not the attach-to-release block: these are separate +# top-level jobs. +notify_block="$(awk ' + /^ notify-auto-update-canary-failure:[[:space:]]*$/ { inblock = 1; print; next } + inblock && /^ [A-Za-z_.-]+:/ { inblock = 0 } + inblock { print } +' "$WF")" + +if [[ -z "$notify_block" ]]; then + fail "the 'notify-auto-update-canary-failure' job is gone from cross-compile.yml" \ + "A failed Gate A leaves the release stuck as a draft and says nothing;" \ + "a failed Gate B has no other output at all. This job is how either" \ + "one reaches a human." +else + pass "cross-compile.yml still has the pre-flight failure notification job" + + # Each gate contributes two result states. `failure` alone is not enough: + # a cancelled job is not a passed one, and treating it as passed is how a + # timed-out gate goes unreported. + missing=() + for clause in \ + "needs.attach-to-release.result == 'failure'" \ + "needs.attach-to-release.result == 'cancelled'" \ + "needs.auto-update-selfupdate-canary.result == 'failure'" \ + "needs.auto-update-selfupdate-canary.result == 'cancelled'" + do + [[ "$notify_block" == *"$clause"* ]] || missing+=("$clause") + done + + if [[ ${#missing[@]} -eq 0 ]]; then + pass "the notification fires for failure AND cancellation of both gates" + else + fail "the notification no longer covers every gate outcome" \ + "Missing from the notify job's 'if:':" \ + "${missing[@]}" \ + "A gate whose failure notifies nobody is a gate nobody acts on. Gate A" \ + "failing leaves the release a silent DRAFT; Gate B has no other output." + fi + + # `always()` is what lets the job run at all after a needed job failed. + # Without it the notification is skipped in exactly the case it exists for. + if [[ "$notify_block" == *'always()'* ]]; then + pass "the notify job runs under always() (so a failed gate does not skip it)" + else + fail "the notify job's 'if:' no longer calls always()" \ + "A job whose dependency failed is SKIPPED unless its condition calls" \ + "always(). Without it this job never runs on the one path it exists for." + fi + + # It must also still DEPEND on both, or the results it tests are always ''. + for needed in attach-to-release auto-update-selfupdate-canary; do + if [[ "$notify_block" == *"needs:"*"$needed"* ]]; then + pass "the notify job still needs '$needed'" + else + fail "the notify job no longer lists '$needed' in 'needs:'" \ + "A result expression for a job that is not needed evaluates to the" \ + "empty string, so every clause above silently stops matching." + fi + done +fi + +# --- 7. Gate B's job still exists ------------------------------------------- +# The notify job's clauses are only meaningful if the job they name is real. +if grep -qE '^ auto-update-selfupdate-canary:[[:space:]]*$' "$WF"; then + pass "cross-compile.yml still has the 'auto-update-selfupdate-canary' job (Gate B)" +else + fail "the 'auto-update-selfupdate-canary' job (Gate B) is gone from cross-compile.yml" \ + "Gate B is what proves a node on the PREVIOUS release can actually reach" \ + "this one -- the #5221 failure mode. Nothing else covers it." +fi + +echo +if [[ "$FAILURES" -eq 0 ]]; then + echo "All release canary wiring assertions passed." +else + echo "$FAILURES assertion(s) FAILED." >&2 + exit 1 +fi diff --git a/scripts/release_wait_for_binaries_test.sh b/scripts/release_wait_for_binaries_test.sh new file mode 100755 index 0000000000..ab60229a35 --- /dev/null +++ b/scripts/release_wait_for_binaries_test.sh @@ -0,0 +1,419 @@ +#!/usr/bin/env bash +# Regression test for the release driver's `gh` calls during the cross-compile +# wait -- the window in which a single transient GitHub blip could abandon a +# release that had already published. +# +# THE BUG. `scripts/release.sh` runs under `set -euo pipefail`, and a bare +# `var=$(cmd)` is a simple command whose exit status IS `cmd`'s. So every +# unguarded `$(gh ...)` in `wait_for_binaries` was a live abort: +# +# $ bash -c 'set -e; x=$(false); echo reached' # "reached" never prints +# +# `set -o pipefail` extends this to `$(gh ... | head -1)` -- `head` does not +# absorb `gh`'s failure. `wait_for_binaries` is called BARE at release.sh:1598, +# so errexit is genuinely armed inside it, and it polls for up to 20 minutes. +# One rate-limit or 5xx in that window killed the driver AFTER the release had +# published but BEFORE `trigger_gateway_updates`, `announce_to_matrix` and +# `announce_to_river` -- release.sh:1216 describes the consequence in its own +# words: "A release that published perfectly well would silently never be +# announced." Silent, and indistinguishable from a release nobody cut. +# +# WHAT IS ASSERTED. `attach_job_state` documents that empty output means "we do +# not know", explicitly including the case where "`gh` failed". These cases pin +# that the code actually delivers that contract: a failing `gh` must make the +# loop poll again, not tear the driver down. The negative cases (4, 5, 6) exist +# because "survive a `gh` failure" is one `|| true` away from "survive +# everything" -- a driver that never aborts is as broken as one that always +# does, just in the other direction. +# +# The real functions are extracted verbatim from release.sh (the technique +# release_state_restore_test.sh already uses) so this test cannot drift from +# the code the release actually runs. +# +# Run manually: bash scripts/release_wait_for_binaries_test.sh +# Also wired into CI (the Fmt job in .github/workflows/ci.yml). + +set -uo pipefail + +SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" +RELEASE_SH="$SCRIPT_DIR/release.sh" + +if [[ ! -f "$RELEASE_SH" ]]; then + echo "FAIL: $RELEASE_SH not found" >&2 + exit 1 +fi + +FAILURES=0 +TMP="$(mktemp -d)" +trap 'rm -rf "$TMP"' EXIT + +# --- the `gh` stub ---------------------------------------------------------- +# A real executable on PATH, not a shell function, so it exercises the same +# invocation path as production and cannot be bypassed by `command gh`. +# +# Each scripted response is a file named . whose first line +# is the exit code and whose remaining lines are stdout. An invocation with no +# scripted response is a hard error (exit 98) rather than a silent empty +# result, because several callers swallow `gh`'s stderr and would otherwise +# read a stub gap as a legitimate "not ready yet". +mkdir -p "$TMP/bin" +cat > "$TMP/bin/gh" <<'STUB' +#!/usr/bin/env bash +args="$*" +case "$args" in + *"--json isDraft"*) kind=isdraft ;; + *"--json assets"*) kind=assets ;; + *"--json jobs"*) kind=jobs ;; + *"--json status"*) kind=runstatus ;; + *"--json databaseId"*) kind=runlist ;; + *"--draft=false"*) kind=releaseedit ;; + *) + echo "gh stub: unhandled invocation: $args" >&2 + exit 99 + ;; +esac + +n=$(( $(cat "$GH_STUB_DIR/count.$kind" 2>/dev/null || echo 0) + 1 )) +echo "$n" > "$GH_STUB_DIR/count.$kind" +echo "$kind #$n" >> "$GH_STUB_DIR/calls.log" + +resp="$GH_STUB_DIR/$kind.$n" +if [[ ! -f "$resp" ]]; then + echo "gh stub: no scripted response for $kind call #$n" >&2 + exit 98 +fi +code="$(head -1 "$resp")" +tail -n +2 "$resp" +exit "$code" +STUB +chmod +x "$TMP/bin/gh" + +# --- the code under test ---------------------------------------------------- +# Pulled verbatim from release.sh so a future edit to the real functions is +# what this test runs. `sleep` is neutralised so the 20-minute poll and the +# 2-minute run-discovery loop run instantly; nothing else is substituted. +DEFS="$TMP/defs.sh" +{ + grep -E "^ATTACH_JOB_NAME=" "$RELEASE_SH" + awk '/^attach_job_state\(\) \{/,/^}/' "$RELEASE_SH" + awk '/^publish_draft_release\(\) \{/,/^}/' "$RELEASE_SH" + awk '/^verify_required_binaries\(\) \{/,/^}/' "$RELEASE_SH" + awk '/^wait_for_binaries\(\) \{/,/^}/' "$RELEASE_SH" + echo 'sleep() { :; }' + echo 'VERSION="0.0.0-test"' + echo 'DRY_RUN=false' +} > "$DEFS" + +for fn in attach_job_state publish_draft_release verify_required_binaries wait_for_binaries; do + if ! grep -q "^$fn() {" "$DEFS"; then + echo "FAIL: could not extract $fn from release.sh -- has it been renamed or reindented?" >&2 + exit 1 + fi +done + +# The 10 assets verify_required_binaries insists on, mirroring REQUIRED_BINARIES. +ALL_BINARIES=( + "freenet-x86_64-unknown-linux-musl.tar.gz" + "freenet-aarch64-unknown-linux-musl.tar.gz" + "freenet-aarch64-apple-darwin.tar.gz" + "freenet-x86_64-apple-darwin.tar.gz" + "freenet-x86_64-pc-windows-msvc.zip" + "fdev-x86_64-unknown-linux-musl.tar.gz" + "fdev-aarch64-unknown-linux-musl.tar.gz" + "fdev-aarch64-apple-darwin.tar.gz" + "fdev-x86_64-apple-darwin.tar.gz" + "fdev-x86_64-pc-windows-msvc.zip" +) + +STUB_DIR="" + +new_scenario() { + STUB_DIR="$(mktemp -d "$TMP/scenario.XXXXXX")" +} + +# respond [stdout-line ...] +respond() { + local kind="$1" n="$2" code="$3" + shift 3 + { + echo "$code" + if [[ $# -gt 0 ]]; then + printf '%s\n' "$@" + fi + } > "$STUB_DIR/$kind.$n" +} + +# Runs wait_for_binaries EXACTLY as release.sh:1598 does -- bare, under +# `set -euo pipefail`. DRIVER_CONTINUED prints only if the driver would have +# gone on to update the gateways and announce the release; an errexit abort or +# a non-zero return both swallow it, which is the production consequence. +run_driver() { + ( + set -euo pipefail + export GH_STUB_DIR="$STUB_DIR" + export PATH="$TMP/bin:$PATH" + # shellcheck source=/dev/null + source "$DEFS" + wait_for_binaries + echo "DRIVER_CONTINUED" + ) 2>&1 +} + +# Dumps the exact `gh` call sequence the driver made. A failure here is +# otherwise reported only through the driver's own output, where a stub or +# environment problem is indistinguishable from a real product failure -- +# a missed response reads as a plausible "Missing: ". +dump_calls() { + echo " gh calls made: $(tr '\n' ',' < "$STUB_DIR/calls.log" 2>/dev/null || echo 'none recorded')" >&2 +} + +# check [expected-substring] +check() { + local desc="$1" expect_cont="$2" expect_rc="$3" want_msg="${4:-}" + local out rc got_cont + out="$(run_driver)" + rc=$? + if [[ "$out" == *DRIVER_CONTINUED* ]]; then got_cont=yes; else got_cont=no; fi + + if [[ "$got_cont" != "$expect_cont" ]]; then + echo "FAIL - $desc" >&2 + if [[ "$expect_cont" == "yes" ]]; then + echo " the driver ABORTED during the cross-compile wait (rc=$rc)." >&2 + echo " In production that is a published release that never reaches the" >&2 + echo " gateways and is never announced -- see release.sh:1216." >&2 + else + echo " the driver CONTINUED past a condition that must stop it (rc=$rc)." >&2 + fi + echo " output: $out" >&2 + dump_calls + FAILURES=$((FAILURES + 1)) + return + fi + if [[ "$rc" != "$expect_rc" ]]; then + echo "FAIL - $desc (got rc=$rc, expected $expect_rc)" >&2 + echo " output: $out" >&2 + dump_calls + FAILURES=$((FAILURES + 1)) + return + fi + if [[ -n "$want_msg" && "$out" != *"$want_msg"* ]]; then + echo "FAIL - $desc (rc=$rc correct, but the diagnosis is missing)" >&2 + echo " wanted output containing: $want_msg" >&2 + echo " got: $out" >&2 + dump_calls + FAILURES=$((FAILURES + 1)) + return + fi + echo "ok - $desc" +} + +# check_call_count +check_call_count() { + local desc="$1" kind="$2" expected="$3" actual + actual="$(cat "$STUB_DIR/count.$kind" 2>/dev/null || echo 0)" + if [[ "$actual" == "$expected" ]]; then + echo "ok - $desc" + else + echo "FAIL - $desc (gh '$kind' called $actual times, expected $expected)" >&2 + dump_calls + FAILURES=$((FAILURES + 1)) + fi +} + +# =========================================================================== +# 1. A transient `gh` failure while reading the attach job's state. +# +# This is the busiest call in the release: `job_state` stays empty for the +# whole multi-minute build window, so BOTH the `attach_job_state` read and the +# run-status read under it are hit on every 30s tick. One 5xx here used to end +# the release. It must simply poll again. +# =========================================================================== +new_scenario +respond assets 1 0 # workflow still building +respond runlist 1 0 "9001" +respond jobs 1 1 # <-- transient gh failure +respond runstatus 1 1 # <-- and on the follow-up read +respond jobs 2 0 "completed:success" # recovered +respond assets 2 0 "${ALL_BINARIES[@]}" +respond isdraft 1 0 "false" # already published by the workflow +check "transient gh failure reading attach-job state -> keeps polling, release completes" \ + yes 0 "All required platform binaries attached" +check_call_count " and it really did re-poll after the failure" jobs 2 + +# =========================================================================== +# 2. A transient `gh` failure while discovering the workflow run. +# +# `run_id=$(gh run list ... | head -1)` looks protected because `head` exits 0, +# but `set -o pipefail` propagates `gh`'s status out of the pipeline. This loop +# exists specifically to retry ("it takes a few seconds for GitHub to start the +# workflow"), so aborting on the first blip defeats its only purpose. +# =========================================================================== +new_scenario +respond assets 1 0 +respond runlist 1 1 # <-- transient gh failure +respond runlist 2 0 "9001" # recovered on the next tick +respond jobs 1 0 "completed:success" +respond assets 2 0 "${ALL_BINARIES[@]}" +respond isdraft 1 0 "false" +check "transient gh failure finding the workflow run -> retries, release completes" \ + yes 0 "Workflow run ID: 9001" + +# =========================================================================== +# 3. `gh` SUCCEEDS but returns nothing -- the job has not started yet. +# +# The guard must not change this path: empty-with-exit-0 already meant "keep +# waiting", and it must still mean that rather than being read as a pass. +# =========================================================================== +new_scenario +respond assets 1 0 +respond runlist 1 0 "9001" +respond jobs 1 0 # job not created yet (exit 0, empty) +respond runstatus 1 0 "in_progress" +respond jobs 2 0 # still not created +respond runstatus 2 0 "in_progress" +respond jobs 3 0 "completed:success" +respond assets 2 0 "${ALL_BINARIES[@]}" +respond isdraft 1 0 "false" +check "gh returns empty while the job is pending -> keeps waiting, then succeeds" \ + yes 0 "Binaries attached and release published" +check_call_count " and it waited through both pending ticks" jobs 3 + +# =========================================================================== +# 4. Empty job state, but the RUN has finished: the fast, loud exit. +# +# The job was cancelled before creation or renamed out from under +# ATTACH_JOB_NAME. Reported as UNKNOWN, never as a pass -- and the guard must +# not soften it into "poll until timeout". +# =========================================================================== +new_scenario +respond assets 1 0 +respond runlist 1 0 "9001" +respond jobs 1 0 +respond runstatus 1 0 "completed" +check "job never reported and the run finished -> stops loudly, driver does NOT continue" \ + no 1 "never reported a result" + +# =========================================================================== +# 5. A genuinely failed attach job is still fatal. +# +# The blocking pre-flight canary (#5222) rejecting the binary lands here. If +# the errexit guard were over-applied, this is where it would show up as a +# release that announces a broken updater. +# =========================================================================== +new_scenario +respond assets 1 0 +respond runlist 1 0 "9001" +respond jobs 1 0 "completed:failure" +check "attach job failed -> stops loudly, driver does NOT continue" \ + no 1 "failed (conclusion: failure)" + +# =========================================================================== +# 6. A `gh` failure at the publish gate must REFUSE, with its diagnosis. +# +# publish_draft_release already treats an unknown gate state as "do not +# publish". Without the guard the `gh` failure aborted the driver one line +# before it could say so, turning a documented refusal into a silent death. +# The refusal is still fatal here -- what regressed was the operator's only +# clue about why. +# =========================================================================== +new_scenario +respond assets 1 0 "${ALL_BINARIES[@]}" # all assets up; gate decides +respond isdraft 1 0 "true" # still a draft -> gate applies +respond runlist 1 0 "9001" +respond jobs 1 1 # <-- transient gh failure at the gate +check "gh failure at the publish gate -> refuses to publish AND says why" \ + no 1 "NOT publishing v0.0.0-test" + +# =========================================================================== +# 7. `gh` fails while reading isDraft -> refuse, do not report success. +# +# This one never published an ungated release, so it looked harmless. What it +# did was coerce the failure to "false" ("not a draft, nothing to gate") and +# return 0, so the driver went on to update the gateways and announce a release +# that may still have been an unpublished draft. Every other unknown in +# publish_draft_release refuses; this is the one that did not. +# =========================================================================== +new_scenario +respond assets 1 0 "${ALL_BINARIES[@]}" +respond isdraft 1 1 # <-- gh failure, draft state unknown +check "gh failure reading isDraft -> refuses instead of announcing a maybe-draft" \ + no 1 "Cannot tell whether v0.0.0-test is still a draft" + +# =========================================================================== +# 8. isDraft=false -> the workflow already published; nothing left to gate. +# +# Distinguishing this from case 7 is the whole point of the change: a real +# "false" must still short-circuit to success, or every release would refuse. +# =========================================================================== +new_scenario +respond assets 1 0 "${ALL_BINARIES[@]}" +respond isdraft 1 0 "false" +check "isDraft=false -> already published, driver continues" yes 0 \ + "All required platform binaries already available" + +# =========================================================================== +# 9-12. One case per `job_state` value, pinning the DECISION each produces. +# +# release.sh:1206-1288 added ~100 lines of decision logic to the release +# critical path, in a function whose own comment records a prior fail-open +# ("Returning 0 here made the caller report success, so the driver went on to +# update the gateways and announce..."). The four values are the whole state +# space of that switch, and each maps to a different, load-bearing outcome. +# +# `in_progress:` is the one with no other coverage: it is neither empty (so the +# run-finished fast-exit does not apply) nor completed (so the terminal switch +# does not fire), and the only correct behaviour is to keep polling. If it ever +# fell through to "not completed, therefore fine", the driver would announce +# mid-build. +# =========================================================================== +new_scenario +respond assets 1 0 +respond runlist 1 0 "9001" +respond jobs 1 0 "in_progress:" # queued/running, no conclusion yet +respond jobs 2 0 "in_progress:" +respond jobs 3 0 "completed:success" +respond assets 2 0 "${ALL_BINARIES[@]}" +respond isdraft 1 0 "false" +check "job_state 'in_progress:' -> keeps polling, never treated as terminal" \ + yes 0 "Binaries attached and release published" +check_call_count " and it polled through both in_progress ticks" jobs 3 +# `in_progress:` must NOT reach the run-status branch: that branch is gated on +# an EMPTY job_state, and firing it here would mean the switch had lost track of +# a job that is plainly still running. +check_call_count " and it never consulted run status for a running job" runstatus 0 + +new_scenario +respond assets 1 0 +respond runlist 1 0 "9001" +respond jobs 1 0 "completed:cancelled" # any non-success conclusion +check "job_state 'completed:cancelled' -> fails the release loudly" \ + no 1 "failed (conclusion: cancelled)" + +# `completed:success` but the assets are NOT all there: the job lied, or an +# upload was lost. Publishing on this would ship a release that cannot be +# installed on the missing platform. +new_scenario +respond assets 1 0 +respond runlist 1 0 "9001" +respond jobs 1 0 "completed:success" +respond assets 2 0 "${ALL_BINARIES[@]:0:9}" # windows fdev zip missing +check "job_state 'completed:success' but an asset is missing -> fails" \ + no 1 "some required binaries are missing" + +# The publish gate itself: still a draft, and the attach job did NOT succeed. +# Publishing here would turn the blocking pre-flight canary into no gate at all. +new_scenario +respond assets 1 0 "${ALL_BINARIES[@]}" +respond isdraft 1 0 "true" +respond runlist 1 0 "9001" +respond jobs 1 0 "completed:failure" +check "publish gate: still a draft and attach job failed -> refuses to publish" \ + no 1 "NOT publishing v0.0.0-test" + +echo +if [[ "$FAILURES" -eq 0 ]]; then + echo "All release wait_for_binaries assertions passed." +else + echo "$FAILURES assertion(s) FAILED." >&2 + exit 1 +fi