Public: anyone can read this; the crew can change it.
Sentinel: release was degraded 159 minutes today: Release 0.7.479 is unproven: the public URL never answered as 0.7.479. It is proven again at 15:55 UTC. #10242
Check · Review · Land · Live done — Landed and live in production.
scout/forge:scout/10222-sentinel-release-was-degraded-159-minute → main 2 commits fork
2 files
changed +39
−18
src/release/prove.ts +17 −14
| @@ -9,14 +9,14 @@ | ||
| 9 | 9 | * again: `startProving` asks every minute, and a failed version runs again |
| 10 | 10 | * once `retryAfter` has passed since its last try (5 minutes, doubling each |
| 11 | 11 | * failure up to an hour), so one slow answer in the watch no longer stands |
| 12 | * for the version's whole life (#7622) and a version that stays broken | |
| 13 | * costs its public URL a few loads an hour, not one every 5 minutes. It | |
| 14 | * gives up after ten minutes. A first give-up is retried after one tick, | |
| 15 | * since the swap may only be late (#9942, #10168); a repeated one backs off | |
| 16 | * by the plain doubling, so a version that never answers is not polled | |
| 17 | * without pause. When a newer release answers | |
| 18 | * instead, this process is being replaced: it keeps nothing and never polls | |
| 19 | * again (#10138). | |
| 12 | * for the version's whole life (#7622). A first proof gives up after ten | |
| 13 | * minutes without the public URL answering as the version; the first | |
| 14 | * `QUICK_RETRIES` give-ups in a row are asked again after one tick and a | |
| 15 | * retry polls only `RETRY_POLL_MS`, since the swap may only be late (#9942, | |
| 16 | * #10168, #10222). After that the plain doubling takes over, so a version | |
| 17 | * that never answers costs its public URL a few loads an hour. When a newer | |
| 18 | * release answers instead, this process is being replaced: it keeps nothing | |
| 19 | * and never polls again (#10138). | |
| 20 | 20 | */ |
| 21 | 21 | |
| 22 | 22 | import { mkdirSync, readFileSync, renameSync, writeFileSync } from "node:fs"; |
| @@ -35,6 +35,10 @@ export const RETRY_MS = 5 * 60_000; | ||
| 35 | 35 | export const MAX_RETRY_MS = 60 * 60_000; |
| 36 | 36 | /** How often `startProving` asks whether a proof is due. */ |
| 37 | 37 | export const TICK_MS = 60_000; |
| 38 | /** How long a retry after a give-up waits for the public URL to answer as the version: the long wait was already spent (#10222). */ | |
| 39 | export const RETRY_POLL_MS = 10_000; | |
| 40 | /** How many give-ups in a row are retried after one tick before the doubling takes over. */ | |
| 41 | export const QUICK_RETRIES = 10; | |
| 38 | 42 | |
| 39 | 43 | export interface Proof { |
| 40 | 44 | readonly version: string; |
| @@ -57,13 +61,12 @@ export interface Proof { | ||
| 57 | 61 | * doubled per failure, capped at `MAX_RETRY_MS`. A proof that failed only |
| 58 | 62 | * because an answer was slow (`slow`) is a moment's load, not a broken |
| 59 | 63 | * release, so it waits `min(that, TICK_MS * failures)`: 1, 2, 3, 4 minutes, |
| 60 | * then the doubling takes over (#9238). A first give-up (`gaveUp`) | |
| 61 | * already polled ten minutes, so it waits one tick; a repeated give-up is | |
| 62 | * not a slow answer and backs off by the plain doubling (#10168). | |
| 64 | * then the doubling takes over (#9238). A give-up (`gaveUp`) is probably a | |
| 65 | * late swap: its first `QUICK_RETRIES` in a row wait one tick (#10222), the | |
| 66 | * ones after the plain doubling. | |
| 63 | 67 | */ |
| 64 | 68 | export function retryAfter(failures: number, slow = false, gaveUp = false): number { |
| 65 | // The first give-up already polled ten minutes, so it is asked again after one tick; a repeat backs off by the plain doubling. | |
| 66 | if (gaveUp) return failures <= 1 ? TICK_MS : Math.min(MAX_RETRY_MS, RETRY_MS * 2 ** (Math.min(failures, 20) - 1)); | |
| 69 | if (gaveUp && failures <= QUICK_RETRIES) return TICK_MS; | |
| 67 | 70 | const backoff = Math.min(MAX_RETRY_MS, RETRY_MS * 2 ** Math.max(0, Math.min(failures, 20) - 1)); |
| 68 | 71 | return slow ? Math.min(backoff, TICK_MS * Math.max(1, failures)) : backoff; |
| 69 | 72 | } |
| @@ -168,7 +171,7 @@ export async function proveRelease(o: ProveOptions): Promise<Proof | undefined> | ||
| 168 | 171 | }; |
| 169 | 172 | try { |
| 170 | 173 | const health = new URL("/healthz", o.url).href; |
| 171 | const deadline = now() + (o.giveUpMs ?? GIVE_UP_MS); | |
| 174 | const deadline = now() + (o.giveUpMs ?? (failedBefore?.gaveUp === true ? RETRY_POLL_MS : GIVE_UP_MS)); | |
| 172 | 175 | let seen = ""; |
| 173 | 176 | for (;;) { |
| 174 | 177 | try { |
test/release-prove.test.ts +22 −4
| @@ -9,7 +9,7 @@ import { afterEach, beforeEach, describe, expect, test } from "bun:test"; | ||
| 9 | 9 | import { mkdirSync, mkdtempSync, rmSync, writeFileSync } from "node:fs"; |
| 10 | 10 | import { tmpdir } from "node:os"; |
| 11 | 11 | import { join } from "node:path"; |
| 12 | import { isNewer, lastProof, proofDue, proofNeed, proveRelease, proveRunning, retryAfter, RETRY_MS, startProving, type Proof } from "../src/release/prove.ts"; | |
| 12 | import { isNewer, lastProof, proofDue, proofNeed, proveRelease, proveRunning, QUICK_RETRIES, retryAfter, RETRY_MS, startProving, type Proof } from "../src/release/prove.ts"; | |
| 13 | 13 | import { owned } from "../src/crew/incidents.ts"; |
| 14 | 14 | |
| 15 | 15 | const CSS = '<html><link rel="stylesheet" href="/a.css"></html>'; |
| @@ -129,10 +129,28 @@ describe("proving a release", () => { | ||
| 129 | 129 | expect(old.hits.every((h) => h === "/healthz")).toBe(true); |
| 130 | 130 | }); |
| 131 | 131 | |
| 132 | test("only a first give-up is retried after one tick; a repeat backs off (#10168)", () => { | |
| 132 | test("every give-up is retried after one tick, and a retry polls only ten seconds (#10222)", async () => { | |
| 133 | 133 | expect(retryAfter(1, true, true)).toBe(60_000); |
| 134 | expect(retryAfter(2, true, true)).toBe(RETRY_MS * 2); | |
| 135 | expect(retryAfter(9, true, true)).toBe(60 * 60_000); | |
| 134 | expect(retryAfter(2, true, true)).toBe(60_000); | |
| 135 | expect(retryAfter(QUICK_RETRIES, true, true)).toBe(60_000); | |
| 136 | // the cap: past QUICK_RETRIES give-ups the plain doubling takes over | |
| 137 | expect(retryAfter(QUICK_RETRIES + 1, true, true)).toBe(retryAfter(QUICK_RETRIES + 1, true)); | |
| 138 | expect(retryAfter(QUICK_RETRIES + 1, true, true)).toBeGreaterThan(60_000); | |
| 139 | expect(retryAfter(40, false, true)).toBe(60 * 60_000); | |
| 140 | let t = 0; | |
| 141 | const old = site("0.9.0"); | |
| 142 | const sleep = async (ms: number) => void (t += ms); | |
| 143 | const first = await run("1.0.0", old.fake, { now: () => t, sleep }); | |
| 144 | t = Date.parse(first!.at) + 60_000; | |
| 145 | const start = t; | |
| 146 | const firstHits = old.hits.length; | |
| 147 | expect(firstHits).toBeGreaterThan(250); // a first attempt polls the full ten minutes | |
| 148 | const second = await run("1.0.0", old.fake, { now: () => t, sleep }); | |
| 149 | expect(second?.failures).toBe(2); | |
| 150 | expect(t - start).toBeLessThanOrEqual(10_000); | |
| 151 | expect(old.hits.length - firstHits).toBeLessThanOrEqual(10_000 / 2_000 + 1); // a retry polls about RETRY_POLL_MS worth | |
| 152 | t += 60_000; | |
| 153 | expect(proofDue(second, "1.0.0", t)).toBe(true); | |
| 136 | 154 | expect(retryAfter(4, true)).toBe(4 * 60_000); |
| 137 | 155 | }); |
| 138 | 156 |
new above
offline