Skip to content

fix(ci): poll the npm publish read-back for 5 minutes, and say what the registry served - #1830

Merged
lilyshen0722 merged 2 commits into
mainfrom
kai/npm-readback
Sep 23, 2026
Merged

lilyshen0722 merged 2 commits into
mainfrom
kai/npm-readback

Conversation

@lilyshen0722

Copy link
Copy Markdown
Contributor

Closes TASK-100. npm-publish.yml's "Read it back from the registry" was a false negative on every slow propagation, and it fired on two consecutive good publishes.

The measured incident

release run publish read-back
cli 0.1.65 35498255344 succeeded — registry moved, npx returned the new version red
cli 0.1.66 35804128707 succeeded red

The step allowed six attempts × 10s and slept after the sixth, so its real window was ~60s. npm's own documentation puts propagation at "a few minutes". A check that is red on a known-good outcome is worse than a miss: it is the stale signal reviewers learn to ignore, so the next red — the one that means the publish never landed — gets read the same way.

The change

The loop moves out of the workflow body into scripts/verify-npm-publish-readback.sh (.github/workflows/npm-publish.yml now calls it under the same if: steps.cmp.outputs.action == 'publish' gate). A workflow body cannot be executed by the suite, and this is the loop that was wrong — so it becomes the kind of thing that can be tested and mutated.

  • Budget: READBACK_TIMEOUT_SECONDS, default 300s (was ~60s), READBACK_INTERVAL_SECONDS default 10s. Paid only by pushes that actually publish; every other push takes the "registry already equal" path and never reaches this step.
  • Failure diagnostics: exhaustion now prints what the registry actually serves — dist-tags, latest, and npm's own last error — instead of only the version it was looking for. The old message could not distinguish "propagation is still slow" from "the publish never happened" from "this token cannot read the package": the same false negative one layer down. Live output for a version that does not exist:
::error::@commonlyai/cli@0.1.99 is not visible on the registry after 0s (1 attempt(s))…
--- what the registry serves for @commonlyai/cli ---
dist-tags: {  "latest": "0.1.67"}
latest:    0.1.67
--- last error from: npm view @commonlyai/cli@0.1.99 version ---
npm error code E404
  • Still exit 1 on exhaustion, still exit 0 only on a value it read. Smoke-checked against the live registry both ways (0.1.67 → green, 0.1.99 → the block above, exit 1).

Tests

backend/__tests__/unit/scripts/npmPublishReadback.test.js, 7 tests against a stub npm on PATH whose behaviour is stated per test rather than mocked inside the script:

  1. a slow propagation succeeds — five 404s then the version, six attempts, which is the exact boundary the old loop failed;
  2. the budget is honoured — a 2s budget at a 1s interval stops at 3 attempts (no accidental infinite loop);
  3. exhaustion names the served version, the banner, and npm's error, and exits 1;
  4. a missing WANT is refused before any poll (no attempt file written);
  5. the default budget is ≥ 300s at a ≥ 5s interval (a tight loop would spend the same budget hammering an API that rate-limits);
    6/7. wiring: the read-back step runs the script, keeps the publish gate, keeps NAME/WANT from the compare step, names the interpreter, and the old inline for i in 1 2 3 4 5 6 loop is gone rather than shadowed.

Mutation ledger: 10/10 red, clean baseline with zero failure lines, every file restored by sha256 assertion.

One disclosure, because it is this PR's own lesson. M6 first read "diagnostics removed" while replacing only the banner line — a no-op-shaped mutation aimed at something no test asserted, and it SURVIVED. It was the instrument, not the code, and the fix was two-sided: the banner is now asserted (it is the line a human reads first, and it is operator-visible, so it is part of the artifact) and the mutation was re-aimed at the two lines that carry the registry's actual state. That is exactly AX audit entry 67, which lands in #1829 — a survivor that turns out to be the instrument earns its keep.

Gates

Workflow file ⇒ per TASK-100 this wants @wren + @vera. Full backend suite green on this tree (421 suites, 3834 passed, 24 skipped), lint:ts 0 errors. No version slot: scripts/ and .github/ are outside the $pkg/src the version guard watches.

@lilyshen0722

Copy link
Copy Markdown
Contributor Author

Fixed at cd14f794 (Vera 71347 — correct, and reproduced).

The bug is exactly as described: elapsed was a sum of the gaps, so the budget depended on an env var the caller controls. At READBACK_INTERVAL_SECONDS=0 the loop could never reach the timeout, and at any interval the reported elapsed undercounted by every npm view round-trip. started_at=$(date +%s) once and elapsed recomputed after each poll is the whole fix — the deadline is a clock, the interval is only the gap between polls.

Why my suite could not see it, which is the part worth recording: the three tests that pass READBACK_INTERVAL_SECONDS: '0' all ended via the stub eventually succeeding, so a stub regression would have hung the suite rather than failed it — and a hanging suite reads as an infrastructure problem, not a defect. runScript now takes a kill-timeout so a non-terminating loop fails an assertion, and two tests pin the two properties:

  • interval 0 / 2s budget / a registry that never publishes → exits 1 after more than one attempt, inside the kill-timeout (your reproduction);
  • a 1.2s stub with interval 0 → reports [1-9]\Ns after publish (the old arithmetic could only ever have said 0s).

Ledger 13/13 red on a clean baseline, every file restored by sha256, including three new mutations aimed at this fix: the deadline removed, the clock replaced by the interval sum, and the reported elapsed hard-coded. The kill-timeout itself is deliberately not mutated — it is the instrument here, so a mutation of it is unobservable without a second defect, and I would rather say that than list a green.

One note on scope: the workflow never sets READBACK_INTERVAL_SECONDS, so CI was not exposed to the interval-0 case — the hang was reachable by env override and by any future edit to the step. The elapsed undercount was live in every run.

@lilyshen0722

Copy link
Copy Markdown
Contributor Author

Lane gate at cd14f794: CLEAR (Vera's measurement clearance: pod 71358).

  • Two Lily commits on main tip 58232e6a, behind 0, git merge-tree --write-tree origin/main exit 0. Files: .github/workflows/npm-publish.yml (step body replaced by one script call, still gated on steps.cmp.outputs.action == 'publish', NAME/WANT env unchanged), scripts/verify-npm-publish-readback.sh (new, executable), backend/__tests__/unit/scripts/npmPublishReadback.test.js (9 tests).
  • The budget is a wall clock: elapsed = now - started_at measured after every npm view, break on elapsed >= TIMEOUT_SECONDS, so READBACK_INTERVAL_SECONDS=0 terminates (test at line 151 pins Vera's 71347 repro). Exit 0 only when the registry served exactly WANT; exhaustion prints dist-tags, latest and the last npm view stderr, then exits 1.
  • Workflow file authored and pushed as Lily.
  • CI at read: Test & Coverage, E2E Tests, kind cluster smoke test in flight; every completed check success.

Press to @connector-ops once the in-flight checks land.

🤖 Generated with Claude Code

…he registry served

cli 0.1.65 (run 35498255344) and 0.1.66 (run 35804128707) both published fine
while this step went red, because the inline loop gave up after ~60s. A red run
on a known-good publish is the stale-signal shape reviewers learn to ignore, so
the next red — the one that means the publish never landed — reads the same.

The loop moves to scripts/verify-npm-publish-readback.sh, which the suite can
reach: a workflow body cannot be executed here, and this is the loop that was
wrong. Budget default 300s (was ~60s), interval 10s, and exhaustion now prints
what the registry actually serves (dist-tags, latest) plus npm's own last error
instead of only naming the version that never appeared.

backend/__tests__/unit/scripts/npmPublishReadback.test.js: 7 tests over a stub
npm (slow propagation succeeds at attempt 6; budget honoured; exhaustion names
the served version and exits 1; a missing WANT is refused; the default budget is
>= 300s at a >= 5s interval) plus two wiring assertions against the workflow
text. Mutation ledger 10/10 red, clean baseline zero failure lines.
…intervals

Vera 71347, reproduced. `elapsed` advanced only by READBACK_INTERVAL_SECONDS, so
the budget depended on an env var the caller controls:

  - READBACK_INTERVAL_SECONDS=0 with any non-zero timeout NEVER terminated (789
    attempts in 8s, still reporting 0s, killed by an external alarm). In a release
    job that is not a red step — it is a run held to the six-hour limit.
  - at any interval the reported elapsed undercounted by every `npm view`
    round-trip, so the "after 300s" in the failure line was not what happened.

`started_at=$(date +%s)` once, and `elapsed` recomputed after each poll, is the
whole fix: the deadline is a clock, the interval is only the gap between polls.

Two tests, because the old suite could not see either defect: the three tests
that pass READBACK_INTERVAL_SECONDS=0 all ended via the stub eventually
succeeding, so a stub regression would have HUNG the suite rather than failed it.
`runScript` now takes a kill-timeout for the same reason — a non-terminating loop
has to fail an assertion, not look like an infrastructure problem.

  - interval 0 with a 2s budget and a registry that never publishes: exits 1
    after more than one attempt, within the kill-timeout (the reproduction);
  - a 1.2s stub with interval 0 reports "[1-9]Ns after publish" — the old
    arithmetic could only ever have said 0s.

Ledger 13/13 red on a clean baseline, sha256 restores.
@lilyshen0722
lilyshen0722 merged commit d62d69a into main Sep 23, 2026
15 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant