Merge status detection: first-byte speed probe, deploy windows, 4 of 5 with a re-check, check history, reminders
28 files+1434−2180/28 viewed
| 22 | 22 | # deploy.yml in production (Settings, Guardrails), and | |
| 23 | 23 | # registry.cloudflare.com there too, to find, pull and push the runner's | |
| 24 | 24 | # image. A job that must build that image (the `runner-image` group) does | |
| 25 | − | # so with its own Docker Engine, on a larger machine. See docs/DEPLOYING.md. | |
| 25 | + | # so with its own Docker Engine, on a larger machine. Optionally, the | |
| 26 | + | # secret STATUS_DEPLOY_TOKEN (the status Worker's secret of the same name) | |
| 27 | + | # and status.g1t.sh among the same workflow-only domains, so status.g1t.sh | |
| 28 | + | # hears each deploy start and finish. See docs/DEPLOYING.md. | |
| 26 | 29 | name: Deploy | |
| 27 | 30 | ||
| 28 | 31 | on: | |
| ⋯ | |||
| 215 | 218 | - name: Deploy ${{ matrix.units }} | |
| 216 | 219 | env: | |
| 217 | 220 | CLOUDFLARE_API_TOKEN: ${{ secrets.CLOUDFLARE_API_TOKEN }} | |
| 221 | + | # status.g1t.sh hears the deploy start and finish, so its restarts | |
| 222 | + | # are not drafted as incidents. Optional: without it, nothing is sent. | |
| 223 | + | STATUS_DEPLOY_TOKEN: ${{ secrets.STATUS_DEPLOY_TOKEN }} | |
| 218 | 224 | run: node scripts/deploy.mjs deploy --only "${{ matrix.units }}" --force --no-migrations --concurrency 2 | |
| 219 | 225 | ||
| 220 | 226 | edge: | |
| 116 | 116 | ||
| 117 | 117 | ### Noticed before anyone reports it | |
| 118 | 118 | ||
| 119 | − | When a part fails, or is slow, three checks in a row, g1t staff are | |
| 120 | − | alerted and an incident is drafted for them. It appears on the status | |
| 121 | − | page once someone confirms it, usually within minutes. The part's own | |
| 122 | − | state on the page changes at once either way, because it comes from the | |
| 123 | − | checks. | |
| 119 | + | When a part fails, or is slow, on four of five checks in a row, g1t | |
| 120 | + | staff are alerted and an incident is drafted for them. It appears on the | |
| 121 | + | status page once someone confirms it, usually within minutes. The part's | |
| 122 | + | own state on the page changes at once either way, because it comes from | |
| 123 | + | the checks. | |
| 124 | 124 | ||
| 125 | − | A brief blip does not become an incident: if the part recovers and stays | |
| 126 | − | healthy for 10 minutes before anyone confirms the draft, the draft is | |
| 127 | − | dismissed and never appears on the page. While g1t is deploying, and for | |
| 128 | − | 3 minutes after, a slow restart is not drafted unless it outlasts the | |
| 129 | − | deploy. | |
| 125 | + | A brief blip does not become an incident. A slow answer is checked again | |
| 126 | + | straight away, and counts as slow only if the second answer is slow too. | |
| 127 | + | If the part recovers and stays healthy for 10 minutes before anyone | |
| 128 | + | confirms the draft, the draft is dismissed and never appears on the page. | |
| 129 | + | While g1t is deploying, and for 3 minutes after, a slow restart is not | |
| 130 | + | drafted unless it outlasts the deploy. | |
| 131 | + | ||
| 132 | + | **Page speed** is timed to the first byte of each page, loaded as a | |
| 133 | + | browser loads it. The checks identify themselves as `g1t-status/1.0` at | |
| 134 | + | the end of a browser's user agent. | |
| 130 | 135 | ||
| 131 | 136 | If something is broken and the page does not show it, write to | |
| 132 | 137 | [hey@flagon.io](mailto:hey@flagon.io) or see |
| 1 | + | -- Every check, kept for 7 days, and detection by N of M. | |
| 2 | + | -- | |
| 3 | + | -- check_history: one row per part per round of checks: how long it took, | |
| 4 | + | -- what it meant, and the Cloudflare data centre it ran from (the answer's | |
| 5 | + | -- cf-ray). sudo's incident page draws an incident's parts from it. Rows | |
| 6 | + | -- older than 7 days are deleted as checks run (store.ts `record`). | |
| 7 | + | -- | |
| 8 | + | -- streak gains `checks` (every check in the run, good ones between | |
| 9 | + | -- included) and `recent` (its last five, "." good, "s" slow, "x" not | |
| 10 | + | -- answering): a draft is made at four bad of the last five, and a run ends | |
| 11 | + | -- after three good checks in a row. Runs kept before this have neither; | |
| 12 | + | -- the worker fills them in as all bad, in a row (detect.ts `upgradeStreak`). | |
| 13 | + | ||
| 14 | + | CREATE TABLE IF NOT EXISTS check_history ( | |
| 15 | + | component TEXT NOT NULL, | |
| 16 | + | at TEXT NOT NULL, | |
| 17 | + | ms INTEGER, | |
| 18 | + | outcome TEXT NOT NULL CHECK (outcome IN ('up', 'degraded', 'down')), | |
| 19 | + | colo TEXT, | |
| 20 | + | -- A slow answer asked again at once: the first try's time. | |
| 21 | + | first_ms INTEGER, | |
| 22 | + | PRIMARY KEY (component, at) | |
| 23 | + | ); | |
| 24 | + | CREATE INDEX IF NOT EXISTS check_history_at ON check_history (at); | |
| 25 | + | ||
| 26 | + | ALTER TABLE streak ADD COLUMN checks INTEGER NOT NULL DEFAULT 0; | |
| 27 | + | ALTER TABLE streak ADD COLUMN recent TEXT NOT NULL DEFAULT ''; |
| 13 | 13 | "dependencies": { | |
| 14 | 14 | "@g1t/contracts": "*", | |
| 15 | 15 | "@g1t/theme": "*" | |
| 16 | + | }, | |
| 17 | + | "devDependencies": { | |
| 18 | + | "isbot": "^5.1.36" | |
| 16 | 19 | } | |
| 17 | 20 | } |
| 32 | 32 | headers?: Record<string, string>; | |
| 33 | 33 | /** The status that means it works; any 2xx when absent. */ | |
| 34 | 34 | expect?: number; | |
| 35 | + | /** | |
| 36 | + | * A page people open in a browser: asked for with a browser's user agent | |
| 37 | + | * (probe.ts `BROWSER_USER_AGENT`), so the site streams it as it does for | |
| 38 | + | * people, and the time is to the first byte, not to a crawler's full render. | |
| 39 | + | */ | |
| 40 | + | browser?: boolean; | |
| 35 | 41 | }; | |
| 36 | 42 | ||
| 37 | 43 | export type Check = | |
| ⋯ | |||
| 102 | 108 | check: { | |
| 103 | 109 | kind: "http", | |
| 104 | 110 | steps: [ | |
| 105 | − | { url: `${site}/login` }, | |
| 111 | + | { url: `${site}/login`, browser: true }, | |
| 106 | 112 | ...(api ? [{ url: `${api}/v1/user`, headers: { authorization: `Bearer ${NO_TOKEN}` }, expect: 401 }] : []), | |
| 107 | 113 | ], | |
| 108 | 114 | }, | |
| ⋯ | |||
| 146 | 152 | address: `${shown}/${repo}`, | |
| 147 | 153 | checks: `A public project page and Explore each answering within ${SPEED_BUDGET_MS} ms. Slower counts as degraded.`, | |
| 148 | 154 | core: false, | |
| 149 | − | check: { kind: "http", steps: [{ url: `${site}/${repo}` }, { url: `${site}/explore` }] }, | |
| 155 | + | check: { kind: "http", steps: [{ url: `${site}/${repo}`, browser: true }, { url: `${site}/explore`, browser: true }] }, | |
| 150 | 156 | slowMs: SPEED_BUDGET_MS, | |
| 151 | 157 | } | |
| 152 | 158 | : null, | |
| 4 | 4 | import { | |
| 5 | 5 | DEPLOY_GRACE_MS, | |
| 6 | 6 | DEPLOY_MAX_MS, | |
| 7 | − | DETECT_AFTER, | |
| 7 | + | DETECT_BAD, | |
| 8 | + | DETECT_WINDOW, | |
| 9 | + | RECOVER_AFTER, | |
| 8 | 10 | RECOVERED_FOR_MS, | |
| 11 | + | STALE_AFTER_MS, | |
| 12 | + | STALE_EVERY_MS, | |
| 9 | 13 | type DeployWindow, | |
| 10 | 14 | type Streak, | |
| 11 | 15 | autoDismissText, | |
| ⋯ | |||
| 16 | 20 | draftTitle, | |
| 17 | 21 | limitWords, | |
| 18 | 22 | minutesWords, | |
| 23 | + | quietUntil, | |
| 19 | 24 | recoverySentence, | |
| 20 | 25 | settleDrafts, | |
| 26 | + | staleDrafts, | |
| 27 | + | staleText, | |
| 21 | 28 | troubleSentence, | |
| 29 | + | troubledNow, | |
| 30 | + | upgradeStreak, | |
| 22 | 31 | } from "./detect.ts"; | |
| 23 | 32 | ||
| 24 | 33 | const at = (minute: number) => new Date(Date.UTC(2026, 9, 5, 12, minute)); | |
| 25 | 34 | ||
| 35 | + | type State = "up" | "degraded" | "down"; | |
| 36 | + | ||
| 26 | 37 | /** Runs rounds of checks through detection, carrying the streaks along. */ | |
| 27 | 38 | function run( | |
| 28 | − | rounds: Record<string, "up" | "degraded" | "down">[], | |
| 39 | + | rounds: Record<string, State>[], | |
| 29 | 40 | open: { id: string; components: string[] }[] = [], | |
| 30 | 41 | maintenance = new Set<string>(), | |
| 31 | 42 | quiet: (minute: number) => boolean = () => false, | |
| 43 | + | start = new Map<string, Streak>(), | |
| 32 | 44 | ) { | |
| 33 | − | let streaks = new Map<string, Streak>(); | |
| 45 | + | let streaks = start; | |
| 34 | 46 | const results = rounds.map((round, minute) => { | |
| 35 | 47 | const found = detect(streaks, Object.entries(round).map(([component, state]) => ({ component, state })), open, maintenance, at(minute), { quiet: quiet(minute) }); | |
| 36 | 48 | streaks = new Map(found.streaks.map((s) => [s.component, s])); | |
| ⋯ | |||
| 39 | 51 | return results; | |
| 40 | 52 | } | |
| 41 | 53 | ||
| 42 | − | test(`a draft after ${DETECT_AFTER} failed checks in a row, once`, () => { | |
| 43 | − | assert.equal(DETECT_AFTER, 3); | |
| 44 | − | const rounds = run([{ api: "down" }, { api: "down" }, { api: "down" }, { api: "down" }]); | |
| 45 | − | assert.deepEqual(rounds.map((r) => r.draft.length), [0, 0, 1, 0]); | |
| 46 | − | assert.deepEqual(rounds[2]!.draft[0], { key: "api", state: "down", since: at(0).toISOString(), checks: 3 }); | |
| 54 | + | /** One part's states as rounds: "x" down, "s" slow, "." up. */ | |
| 55 | + | const rounds = (key: string, pattern: string): Record<string, State>[] => | |
| 56 | + | [...pattern].map((c) => ({ [key]: c === "x" ? "down" : c === "s" ? "degraded" : "up" })); | |
| 57 | + | ||
| 58 | + | test(`a draft at ${DETECT_BAD} bad of the last ${DETECT_WINDOW} checks, once`, () => { | |
| 59 | + | assert.deepEqual([DETECT_BAD, DETECT_WINDOW, RECOVER_AFTER], [4, 5, 3]); | |
| 60 | + | const found = run(rounds("api", "xxxxx")); | |
| 61 | + | assert.deepEqual(found.map((r) => r.draft.length), [0, 0, 0, 1, 0]); | |
| 62 | + | assert.deepEqual(found[3]!.draft[0], { key: "api", state: "down", since: at(0).toISOString(), checks: 4, of: 4 }); | |
| 63 | + | }); | |
| 64 | + | ||
| 65 | + | test("N of M: a good check between does not hide trouble that keeps coming", () => { | |
| 66 | + | // Three in a row used to be the line, and one good check reset it: down, down, up, down, down was never drafted. | |
| 67 | + | const found = run(rounds("api", "xx.xx")); | |
| 68 | + | assert.deepEqual(found.map((r) => r.draft.length), [0, 0, 0, 0, 1]); | |
| 69 | + | assert.deepEqual(found[4]!.draft[0], { key: "api", state: "down", since: at(0).toISOString(), checks: 4, of: 5 }); | |
| 47 | 70 | }); | |
| 48 | 71 | ||
| 49 | − | test("a blip is not an incident: a good check resets the run", () => { | |
| 50 | − | const rounds = run([{ api: "down" }, { api: "down" }, { api: "up" }, { api: "down" }, { api: "down" }]); | |
| 51 | − | assert.ok(rounds.every((r) => r.draft.length === 0)); | |
| 52 | − | assert.equal(rounds[4]!.streaks[0]!.count, 2); | |
| 72 | + | test("a blip is not an incident: three bad of five is under the line, and three good checks end the run", () => { | |
| 73 | + | const flapping = run(rounds("api", "x.x.x.x")); | |
| 74 | + | assert.ok(flapping.every((r) => r.draft.length === 0), "half the checks failing, alternately, is not four of five"); | |
| 75 | + | const blip = run(rounds("api", "xx...xx")); | |
| 76 | + | assert.ok(blip.every((r) => r.draft.length === 0)); | |
| 77 | + | assert.equal(blip[4]!.streaks.length, 0, "three good checks in a row end the run"); | |
| 78 | + | assert.deepEqual(blip[6]!.streaks[0], { component: "api", state: "down", count: 2, checks: 2, recent: "xx", since: at(5).toISOString(), alerted: false }); | |
| 53 | 79 | }); | |
| 54 | 80 | ||
| 55 | 81 | test("slow then failing is one run, at its worst", () => { | |
| 56 | − | const rounds = run([{ docs: "degraded" }, { docs: "down" }, { docs: "degraded" }]); | |
| 57 | − | assert.deepEqual(rounds[2]!.draft, [{ key: "docs", state: "down", since: at(0).toISOString(), checks: 3 }]); | |
| 82 | + | const found = run(rounds("docs", "sxss")); | |
| 83 | + | assert.deepEqual(found[3]!.draft, [{ key: "docs", state: "down", since: at(0).toISOString(), checks: 4, of: 4 }]); | |
| 58 | 84 | }); | |
| 59 | 85 | ||
| 60 | 86 | test("parts failing together share one draft", () => { | |
| 61 | − | const rounds = run([{ api: "down", git: "down" }, { api: "down", git: "down" }, { api: "down", git: "down" }]); | |
| 62 | − | assert.deepEqual(rounds[2]!.draft.map((d) => d.key), ["api", "git"]); | |
| 87 | + | const found = run(Array.from({ length: 4 }, () => ({ api: "down" as const, git: "down" as const }))); | |
| 88 | + | assert.deepEqual(found[3]!.draft.map((d) => d.key), ["api", "git"]); | |
| 63 | 89 | }); | |
| 64 | 90 | ||
| 65 | − | test("with an incident already open on the part: a line on it, no draft; recovery is noted", () => { | |
| 91 | + | test("with an incident already open on the part: a line on it, no draft; recovery is noted once the run ends", () => { | |
| 66 | 92 | const open = [{ id: "inc1", components: ["api"] }]; | |
| 67 | − | const rounds = run([{ api: "down" }, { api: "down" }, { api: "down" }, { api: "up" }], open); | |
| 68 | − | assert.equal(rounds[2]!.draft.length, 0); | |
| 69 | − | assert.deepEqual(rounds[2]!.failing, [{ incident: "inc1", key: "api", state: "down", since: at(0).toISOString(), checks: 3 }]); | |
| 70 | − | assert.deepEqual(rounds[3]!.recovered, [{ incident: "inc1", key: "api", state: "down", since: at(0).toISOString(), checks: 3 }]); | |
| 71 | − | assert.equal(rounds[3]!.streaks.length, 0); | |
| 93 | + | const found = run(rounds("api", "xxxx..."), open); | |
| 94 | + | assert.equal(found[3]!.draft.length, 0); | |
| 95 | + | assert.deepEqual(found[3]!.failing, [{ incident: "inc1", key: "api", state: "down", since: at(0).toISOString(), checks: 4, of: 4 }]); | |
| 96 | + | assert.deepEqual(found.map((r) => r.recovered.length), [0, 0, 0, 0, 0, 0, 1], "answering again is noted after three good checks, not the first"); | |
| 97 | + | assert.deepEqual(found[6]!.recovered, [{ incident: "inc1", key: "api", state: "down", since: at(0).toISOString(), checks: 4, of: 4 }]); | |
| 98 | + | assert.equal(found[6]!.streaks.length, 0); | |
| 72 | 99 | }); | |
| 73 | 100 | ||
| 74 | − | test("a short blip that never crossed the line is not noted as a recovery", () => { | |
| 75 | − | const rounds = run([{ api: "down" }, { api: "up" }], [{ id: "inc1", components: ["api"] }]); | |
| 76 | − | assert.equal(rounds[1]!.recovered.length, 0); | |
| 101 | + | test("a run that never crossed the line is not noted as a recovery", () => { | |
| 102 | + | const found = run(rounds("api", "xx..."), [{ id: "inc1", components: ["api"] }]); | |
| 103 | + | assert.ok(found.every((r) => r.recovered.length === 0)); | |
| 77 | 104 | }); | |
| 78 | 105 | ||
| 79 | 106 | test("parts under maintenance and unmonitored parts are left alone", () => { | |
| 80 | − | const rounds = run([{ api: "down" }, { api: "down" }, { api: "down" }], [], new Set(["api"])); | |
| 81 | − | assert.ok(rounds.every((r) => r.draft.length === 0 && r.streaks.length === 0)); | |
| 107 | + | const found = run(rounds("api", "xxxxx"), [], new Set(["api"])); | |
| 108 | + | assert.ok(found.every((r) => r.draft.length === 0 && r.streaks.length === 0)); | |
| 82 | 109 | const none = detect(new Map(), [{ component: "sandboxes", state: "unmonitored" }], [], new Set(), at(0)); | |
| 83 | 110 | assert.equal(none.streaks.length, 0); | |
| 84 | 111 | }); | |
| ⋯ | |||
| 94 | 121 | }); | |
| 95 | 122 | ||
| 96 | 123 | test("a run that recovered is over: the next one starts fresh, with its own start", () => { | |
| 97 | − | // 12:00 and 12:01 slow, 12:02 fine; then slow again from 12:10. | |
| 98 | − | const rounds = run([ | |
| 99 | − | { git: "degraded" }, | |
| 100 | − | { git: "degraded" }, | |
| 101 | − | { git: "up" }, | |
| 102 | − | ...Array.from({ length: 7 }, () => ({ git: "up" as const })), | |
| 103 | − | { git: "degraded" }, | |
| 104 | − | { git: "degraded" }, | |
| 105 | − | { git: "degraded" }, | |
| 106 | − | ]); | |
| 107 | − | assert.equal(rounds[2]!.streaks.length, 0); | |
| 108 | − | assert.equal(rounds[10]!.streaks[0]!.count, 1); | |
| 109 | − | assert.equal(rounds[10]!.streaks[0]!.since, at(10).toISOString()); | |
| 110 | − | assert.equal(rounds[11]!.draft.length, 0, "two slow checks after a recovery are not three"); | |
| 111 | − | assert.deepEqual(rounds[12]!.draft, [{ key: "git", state: "degraded", since: at(10).toISOString(), checks: 3 }]); | |
| 124 | + | // 12:00 and 12:01 slow, then fine; slow again from 12:10. | |
| 125 | + | const found = run(rounds("git", "ss........ssss")); | |
| 126 | + | assert.equal(found[4]!.streaks.length, 0); | |
| 127 | + | assert.equal(found[10]!.streaks[0]!.count, 1); | |
| 128 | + | assert.equal(found[10]!.streaks[0]!.since, at(10).toISOString()); | |
| 129 | + | assert.equal(found[12]!.draft.length, 0, "three slow checks after a recovery are not four"); | |
| 130 | + | assert.deepEqual(found[13]!.draft, [{ key: "git", state: "degraded", since: at(10).toISOString(), checks: 4, of: 4 }]); | |
| 112 | 131 | }); | |
| 113 | 132 | ||
| 133 | + | test("a run slow for hours, raised long ago, still ends when the checks go healthy", () => { | |
| 134 | + | // As kept before N of M: 300 slow checks in a row, raised. | |
| 135 | + | const old = upgradeStreak({ component: "speed", state: "degraded", count: 300, since: at(0).toISOString(), alerted: true }); | |
| 136 | + | assert.deepEqual([old.checks, old.recent], [300, "sssss"]); | |
| 137 | + | const open = [{ id: "d1", components: ["speed"] }]; | |
| 138 | + | const found = run(rounds("speed", "s.s...."), open, new Set(), () => false, new Map([["speed", old]])); | |
| 139 | + | assert.ok(found.every((r) => r.draft.length === 0 && r.failing.length === 0), "already raised: nothing new"); | |
| 140 | + | assert.deepEqual(found.map((r) => r.recovered.length), [0, 0, 0, 0, 0, 1, 0]); | |
| 141 | + | assert.deepEqual(found[5]!.recovered[0], { incident: "d1", key: "speed", state: "degraded", since: at(0).toISOString(), checks: 302, of: 303 }); | |
| 142 | + | assert.equal(found[5]!.streaks.length, 0); | |
| 143 | + | // While the run lasts, only a bad latest check holds a draft up (settleDrafts). | |
| 144 | + | assert.deepEqual(found.slice(0, 5).map((r) => r.streaks.filter(troubledNow).length), [1, 0, 1, 0, 0]); | |
| 145 | + | }); | |
| 146 | + | ||
| 114 | 147 | test("during a deploy, trouble is counted but not drafted; it is drafted once it outlasts the window", () => { | |
| 115 | − | // Quiet for minutes 0-3 (a deploy and its grace). | |
| 116 | − | const quiet = (m: number) => m <= 3; | |
| 117 | − | const blip = run([{ api: "down" }, { api: "down" }, { api: "down" }, { api: "down" }, { api: "up" }, { api: "up" }], [], new Set(), quiet); | |
| 148 | + | // Quiet for minutes 0-4 (a deploy and its grace). | |
| 149 | + | const quiet = (m: number) => m <= 4; | |
| 150 | + | const blip = run(rounds("api", "xxxxx..."), [], new Set(), quiet); | |
| 118 | 151 | assert.ok(blip.every((r) => r.draft.length === 0), "a restart that recovers inside the window is never drafted"); | |
| 119 | − | assert.deepEqual(blip[2]!.held, ["api"]); | |
| 120 | − | const lasting = run([{ api: "down" }, { api: "down" }, { api: "down" }, { api: "down" }, { api: "down" }], [], new Set(), quiet); | |
| 121 | − | assert.deepEqual(lasting.map((r) => r.draft.length), [0, 0, 0, 0, 1]); | |
| 122 | − | assert.deepEqual(lasting[4]!.draft[0], { key: "api", state: "down", since: at(0).toISOString(), checks: 5 }, "the draft keeps the run's true start"); | |
| 152 | + | assert.deepEqual(blip[3]!.held, ["api"]); | |
| 153 | + | const lasting = run(rounds("api", "xxxxxx"), [], new Set(), quiet); | |
| 154 | + | assert.deepEqual(lasting.map((r) => r.draft.length), [0, 0, 0, 0, 0, 1]); | |
| 155 | + | assert.deepEqual(lasting[5]!.draft[0], { key: "api", state: "down", since: at(0).toISOString(), checks: 6, of: 6 }, "the draft keeps the run's true start"); | |
| 123 | 156 | }); | |
| 124 | 157 | ||
| 125 | 158 | test("during a deploy, an incident already open still hears about its parts", () => { | |
| 126 | − | const rounds = run([{ api: "down" }, { api: "down" }, { api: "down" }], [{ id: "inc1", components: ["api"] }], new Set(), () => true); | |
| 127 | − | assert.equal(rounds[2]!.failing.length, 1); | |
| 159 | + | const found = run(rounds("api", "xxxx"), [{ id: "inc1", components: ["api"] }], new Set(), () => true); | |
| 160 | + | assert.equal(found[3]!.failing.length, 1); | |
| 128 | 161 | }); | |
| 129 | 162 | ||
| 130 | 163 | test("the deploy window: running, finished plus grace, and a start that never finished", () => { | |
| 131 | 164 | const t = (minute: number) => new Date(Date.UTC(2026, 9, 6, 7, minute)); | |
| 132 | 165 | assert.equal(deployQuiet(null, t(0)), false); | |
| 133 | 166 | const running: DeployWindow = deployChange(null, "started", "abc", t(20)); | |
| 134 | − | assert.deepEqual(running, { id: "abc", started_at: t(20).toISOString(), finished_at: null }); | |
| 167 | + | assert.deepEqual(running, { id: "abc", started_at: t(20).toISOString(), finished_at: null, running: 1, last_started_at: t(20).toISOString() }); | |
| 135 | 168 | assert.equal(deployQuiet(running, t(25)), true); | |
| 136 | 169 | assert.equal(deployQuiet(running, t(10)), false, "trouble before the deploy is not forgiven"); | |
| 137 | 170 | assert.equal(deployQuiet(running, new Date(t(20).getTime() + DEPLOY_MAX_MS)), false, "a deploy that never said it finished stops counting"); | |
| 138 | 171 | const finished = deployChange(running, "finished", null, t(26)); | |
| 139 | − | assert.deepEqual(finished, { id: "abc", started_at: t(20).toISOString(), finished_at: t(26).toISOString() }); | |
| 172 | + | assert.deepEqual(finished, { id: "abc", started_at: t(20).toISOString(), finished_at: t(26).toISOString(), running: 0, last_started_at: t(20).toISOString() }); | |
| 140 | 173 | assert.equal(deployQuiet(finished, new Date(t(26).getTime() + DEPLOY_GRACE_MS - 1)), true); | |
| 141 | 174 | assert.equal(deployQuiet(finished, new Date(t(26).getTime() + DEPLOY_GRACE_MS)), false); | |
| 142 | − | // A second start while one runs keeps the first start. | |
| 143 | − | assert.equal(deployChange(running, "started", "def", t(22)).started_at, t(20).toISOString()); | |
| 144 | − | // A new start after one finished begins a new window. | |
| 175 | + | assert.equal(quietUntil(finished), new Date(t(26).getTime() + DEPLOY_GRACE_MS).toISOString()); | |
| 176 | + | // A new start after the window closed begins a new window. | |
| 145 | 177 | assert.equal(deployChange(finished, "started", "def", t(40)).started_at, t(40).toISOString()); | |
| 146 | 178 | }); | |
| 147 | 179 | ||
| 180 | + | test("deploys that overlap are one window, finished when the last one is", () => { | |
| 181 | + | const t = (minute: number) => new Date(Date.UTC(2026, 9, 6, 7, minute)); | |
| 182 | + | // Two jobs of a stage start; the first finishes early. | |
| 183 | + | let w = deployChange(null, "started", "abc", t(0)); | |
| 184 | + | w = deployChange(w, "started", "abc", t(1)); | |
| 185 | + | assert.equal(w.running, 2); | |
| 186 | + | w = deployChange(w, "finished", "abc", t(4)); | |
| 187 | + | assert.deepEqual([w.finished_at, w.running], [null, 1], "one still running: not finished"); | |
| 188 | + | assert.equal(deployQuiet(w, t(12)), true, "the other job's restarts at 12 minutes are still forgiven"); | |
| 189 | + | w = deployChange(w, "finished", "abc", t(14)); | |
| 190 | + | assert.deepEqual([w.started_at, w.finished_at, w.running], [t(0).toISOString(), t(14).toISOString(), 0]); | |
| 191 | + | // The next stage starts inside the grace period: the same window, from its first start. | |
| 192 | + | w = deployChange(w, "started", "abc", t(15)); | |
| 193 | + | assert.deepEqual([w.started_at, w.finished_at, w.running], [t(0).toISOString(), null, 1]); | |
| 194 | + | // The 30-minute cap counts from the latest start, not the first. | |
| 195 | + | assert.equal(deployQuiet(w, t(40)), true); | |
| 196 | + | assert.equal(deployQuiet(w, new Date(t(15).getTime() + DEPLOY_MAX_MS)), false); | |
| 197 | + | }); | |
| 198 | + | ||
| 148 | 199 | test("a detected draft that recovers and stays healthy is dismissed; trouble in between starts the wait again", () => { | |
| 149 | − | const draft = { id: "d1", title: "Detected: Git slow", components: ["git"], started_at: at(0).toISOString(), healthy_since: null as string | null }; | |
| 200 | + | const draft = { | |
| 201 | + | id: "d1", | |
| 202 | + | title: "Detected: Git slow", | |
| 203 | + | components: ["git"], | |
| 204 | + | started_at: at(0).toISOString(), | |
| 205 | + | declared_at: at(3).toISOString(), | |
| 206 | + | healthy_since: null as string | null, | |
| 207 | + | reminded_at: null, | |
| 208 | + | }; | |
| 150 | 209 | const minute = 60_000; | |
| 151 | 210 | // Still slow: not healthy. | |
| 152 | 211 | assert.deepEqual(settleDrafts([draft], new Set(["git"]), at(3)), { healthy: [{ id: "d1", since: null }], dismiss: [] }); | |
| ⋯ | |||
| 165 | 224 | assert.equal(settleDrafts([waiting], new Set(["api"]), new Date(at(4).getTime() + RECOVERED_FOR_MS)).dismiss.length, 1); | |
| 166 | 225 | }); | |
| 167 | 226 | ||
| 227 | + | test("a draft nobody acknowledges is raised again after 45 minutes, once, then every 6 hours", () => { | |
| 228 | + | assert.deepEqual([STALE_AFTER_MS, STALE_EVERY_MS], [45 * 60_000, 6 * 3_600_000]); | |
| 229 | + | const made = at(0); | |
| 230 | + | const later = (ms: number) => new Date(made.getTime() + ms); | |
| 231 | + | const draft = { id: "d1", title: "Detected: Page speed slow", declared_at: made.toISOString(), reminded_at: null as string | null }; | |
| 232 | + | assert.deepEqual(staleDrafts([draft], later(STALE_AFTER_MS - 1)), []); | |
| 233 | + | assert.deepEqual(staleDrafts([draft], later(STALE_AFTER_MS)), [{ id: "d1", title: draft.title, waiting_ms: STALE_AFTER_MS }]); | |
| 234 | + | // Raised at 45 minutes: not again the minute after, nor at 90 minutes. | |
| 235 | + | const reminded = { ...draft, reminded_at: later(STALE_AFTER_MS).toISOString() }; | |
| 236 | + | assert.deepEqual(staleDrafts([reminded], later(STALE_AFTER_MS + 60_000)), []); | |
| 237 | + | assert.deepEqual(staleDrafts([reminded], later(2 * STALE_AFTER_MS)), []); | |
| 238 | + | assert.deepEqual(staleDrafts([reminded], later(STALE_AFTER_MS + STALE_EVERY_MS - 1)), []); | |
| 239 | + | assert.equal(staleDrafts([reminded], later(STALE_AFTER_MS + STALE_EVERY_MS)).length, 1); | |
| 240 | + | assert.equal(staleText(STALE_AFTER_MS, true), "Unacknowledged for 45 minutes. The alert address was emailed again."); | |
| 241 | + | assert.equal(staleText(STALE_AFTER_MS + STALE_EVERY_MS, false), "Unacknowledged for 6h 45m."); | |
| 242 | + | }); | |
| 243 | + | ||
| 168 | 244 | test("slow and down are said apart, with the run's own start", () => { | |
| 169 | 245 | assert.equal(limitWords(1500), "1.5 s"); | |
| 170 | 246 | assert.equal(limitWords(800), "800 ms"); | |
| 171 | 247 | assert.equal( | |
| 172 | − | troubleSentence("Git and repositories", { state: "degraded", checks: 3 }, "6 Oct 07:25 UTC", 1500), | |
| 173 | − | "Git and repositories has been slow — over 1.5 s — on 3 checks in a row since 6 Oct 07:25 UTC.", | |
| 248 | + | troubleSentence("Git and repositories", { state: "degraded", checks: 4, of: 4 }, "6 Oct 07:25 UTC", 1500), | |
| 249 | + | "Git and repositories has been slow — over 1.5 s — on 4 checks in a row since 6 Oct 07:25 UTC.", | |
| 174 | 250 | ); | |
| 251 | + | assert.equal(troubleSentence("API", { state: "down", checks: 4, of: 5 }, "6 Oct 07:25 UTC", 1500), "API has not answered on 4 of 5 checks since 6 Oct 07:25 UTC."); | |
| 175 | 252 | assert.equal(troubleSentence("API", { state: "down", checks: 3 }, "6 Oct 07:25 UTC", 1500), "API has not answered on 3 checks in a row since 6 Oct 07:25 UTC."); | |
| 176 | − | assert.match(recoverySentence("Git", { state: "degraded", checks: 4 }, "6 Oct 07:25 UTC"), /^Git is back to normal speed, after being slow on 4 checks/); | |
| 177 | − | assert.match(recoverySentence("API", { state: "down", checks: 4 }, "6 Oct 07:25 UTC"), /^API is answering again, after not answering on 4 checks/); | |
| 253 | + | assert.match(recoverySentence("Git", { state: "degraded", checks: 4, of: 4 }, "6 Oct 07:25 UTC"), /^Git is back to normal speed, after being slow on 4 checks in a row/); | |
| 254 | + | assert.match(recoverySentence("API", { state: "down", checks: 40, of: 42 }, "6 Oct 07:25 UTC"), /^API is answering again, after not answering on 40 of 42 checks/); | |
| 178 | 255 | assert.equal(minutesWords(30_000), "1 minute"); | |
| 179 | 256 | assert.equal(minutesWords(4 * 60_000), "4 minutes"); | |
| 180 | 257 | assert.equal(minutesWords(125 * 60_000), "2h 05m"); | |
| 1 | 1 | /** | |
| 2 | 2 | * Noticing trouble before anyone reports it: when a part fails (or is | |
| 3 | − | * slow) for DETECT_AFTER checks in a row, a draft incident is made for | |
| 4 | − | * staff in sudo, not shown on the status page until someone publishes it. | |
| 5 | − | * When a part that had crossed that line answers again, open incidents on | |
| 6 | − | * it get a note. A detected draft nobody has picked up is dismissed on its | |
| 7 | − | * own once its parts have stayed healthy for RECOVERED_FOR_MS, and while a | |
| 8 | − | * deploy is running (and for DEPLOY_GRACE_MS after) no new draft is made | |
| 9 | − | * unless the trouble outlasts it. No Workers imports, so it is tested | |
| 10 | − | * under Node. | |
| 3 | + | * slow) on DETECT_BAD of its last DETECT_WINDOW checks, a draft incident | |
| 4 | + | * is made for staff in sudo, not shown on the status page until someone | |
| 5 | + | * publishes it. A run of trouble ends after RECOVER_AFTER good checks in a | |
| 6 | + | * row, however long it lasted; when a run that had crossed the line ends, | |
| 7 | + | * open incidents on its part get a note. A detected draft nobody has | |
| 8 | + | * picked up is dismissed on its own once its parts have stayed healthy for | |
| 9 | + | * RECOVERED_FOR_MS, and one left unacknowledged is raised again after | |
| 10 | + | * STALE_AFTER_MS, then every STALE_EVERY_MS. While a deploy is running | |
| 11 | + | * (and for DEPLOY_GRACE_MS after) no new draft is made unless the trouble | |
| 12 | + | * outlasts it. No Workers imports, so it is tested under Node. | |
| 13 | + | * | |
| 14 | + | * A slow answer only counts once the check, asked again at once, is slow | |
| 15 | + | * too (probe.ts `probe`), so one cold start is not a slow check. | |
| 11 | 16 | */ | |
| 12 | 17 | import type { ComponentImpact, StatusComponentState } from "@g1t/contracts"; | |
| 13 | 18 | ||
| 14 | − | /** Checks in a row, a minute apart, before a draft is made. */ | |
| 15 | − | export const DETECT_AFTER = 3; | |
| 19 | + | /** Failed or slow checks, of the last DETECT_WINDOW, before a draft is made. */ | |
| 20 | + | export const DETECT_BAD = 4; | |
| 21 | + | /** How many of a part's latest checks DETECT_BAD counts over (a minute apart). */ | |
| 22 | + | export const DETECT_WINDOW = 5; | |
| 23 | + | /** Good checks in a row that end a run of trouble, whether or not it was raised. */ | |
| 24 | + | export const RECOVER_AFTER = 3; | |
| 16 | 25 | /** How long a detected draft's parts stay healthy before it is dismissed on its own. */ | |
| 17 | 26 | export const RECOVERED_FOR_MS = 10 * 60_000; | |
| 27 | + | /** How long a detected draft waits, unacknowledged, before the alert goes out again. */ | |
| 28 | + | export const STALE_AFTER_MS = 45 * 60_000; | |
| 29 | + | /** After that, how often it goes out again while the draft still waits. */ | |
| 30 | + | export const STALE_EVERY_MS = 6 * 60 * 60_000; | |
| 18 | 31 | /** How long after a deploy finishes its restarts are still forgiven. */ | |
| 19 | 32 | export const DEPLOY_GRACE_MS = 3 * 60_000; | |
| 20 | 33 | /** A deploy that said it started and never said it finished stops counting after this. */ | |
| 21 | 34 | export const DEPLOY_MAX_MS = 30 * 60_000; | |
| 22 | 35 | ||
| 36 | + | /** One check in a run's `recent`: good, slow, or not answering. */ | |
| 37 | + | export type Mark = "." | "s" | "x"; | |
| 38 | + | ||
| 23 | 39 | /** | |
| 24 | − | * One part's current run of failed or slow checks. Only parts that were | |
| 25 | − | * failing or slow on the latest check have one: any good check ends it, | |
| 26 | − | * and the next trouble starts a new run, with its own start. | |
| 40 | + | * One part's current run of trouble: from its first failed or slow check | |
| 41 | + | * until RECOVER_AFTER good checks in a row. Good checks inside the run | |
| 42 | + | * (flapping) do not end it; they are counted in `checks` and `recent`. | |
| 27 | 43 | */ | |
| 28 | 44 | export type Streak = { | |
| 29 | 45 | component: string; | |
| 30 | − | /** The worst seen in this run of failures. */ | |
| 46 | + | /** The worst seen in this run. */ | |
| 31 | 47 | state: "degraded" | "down"; | |
| 48 | + | /** Failed or slow checks in this run. */ | |
| 32 | 49 | count: number; | |
| 50 | + | /** Every check in this run, from its first failed or slow one. */ | |
| 51 | + | checks: number; | |
| 52 | + | /** The run's latest checks, oldest first, at most DETECT_WINDOW: "." good, "s" slow, "x" not answering. */ | |
| 53 | + | recent: string; | |
| 33 | 54 | /** The first failed or slow check of this run. */ | |
| 34 | 55 | since: string; | |
| 35 | 56 | /** Whether it has crossed the line, and been raised. */ | |
| ⋯ | |||
| 39 | 60 | /** An open incident (draft or public), with the parts it affects. */ | |
| 40 | 61 | export type OpenRef = { id: string; components: string[] }; | |
| 41 | 62 | ||
| 42 | − | export type Trouble = { key: string; state: "degraded" | "down"; since: string; checks: number }; | |
| 63 | + | /** A run that crossed the line: `checks` failed or slow of the `of` checks since `since`. */ | |
| 64 | + | export type Trouble = { key: string; state: "degraded" | "down"; since: string; checks: number; of: number }; | |
| 43 | 65 | ||
| 44 | 66 | export type Detection = { | |
| 45 | − | /** Every failing part's run after this round; parts not here have none. */ | |
| 67 | + | /** Every part's run still going after this round; parts not here have none. */ | |
| 46 | 68 | streaks: Streak[]; | |
| 47 | 69 | /** Parts that crossed the line with no open incident on them: one draft for all. */ | |
| 48 | 70 | draft: Trouble[]; | |
| 49 | 71 | /** Parts that crossed the line while an incident on them was open. */ | |
| 50 | 72 | failing: (Trouble & { incident: string })[]; | |
| 51 | − | /** Parts answering again after crossing the line. */ | |
| 52 | − | recovered: { incident: string; key: string; state: "degraded" | "down"; since: string; checks: number }[]; | |
| 73 | + | /** Parts whose raised run ended: answering again, in time. */ | |
| 74 | + | recovered: (Trouble & { incident: string })[]; | |
| 53 | 75 | /** Parts that crossed the line during a deploy: kept counting, not raised yet. */ | |
| 54 | 76 | held: string[]; | |
| 55 | 77 | }; | |
| 56 | 78 | ||
| 57 | 79 | export type DetectOptions = { | |
| 58 | − | threshold?: number; | |
| 80 | + | /** Failed or slow checks of the last `window` that cross the line. */ | |
| 81 | + | bad?: number; | |
| 82 | + | window?: number; | |
| 83 | + | /** Good checks in a row that end a run. */ | |
| 84 | + | recoverAfter?: number; | |
| 59 | 85 | /** A deploy is running, or just finished: no new drafts, only counting. */ | |
| 60 | 86 | quiet?: boolean; | |
| 61 | 87 | }; | |
| 62 | 88 | ||
| 89 | + | const isBad = (m: string) => m === "s" || m === "x"; | |
| 90 | + | ||
| 91 | + | function mark(state: StatusComponentState): Mark { | |
| 92 | + | return state === "down" ? "x" : state === "degraded" ? "s" : "."; | |
| 93 | + | } | |
| 94 | + | ||
| 95 | + | /** How many of `recent` were failed or slow. */ | |
| 96 | + | export function badIn(recent: string): number { | |
| 97 | + | return [...recent].filter(isBad).length; | |
| 98 | + | } | |
| 99 | + | ||
| 100 | + | /** Good checks at the end of `recent`. */ | |
| 101 | + | function goodTail(recent: string): number { | |
| 102 | + | let n = 0; | |
| 103 | + | for (let i = recent.length - 1; i >= 0 && recent[i] === "."; i--) n++; | |
| 104 | + | return n; | |
| 105 | + | } | |
| 106 | + | ||
| 107 | + | /** Whether a run's latest check was failed or slow: what keeps a draft from counting as healthy. */ | |
| 108 | + | export function troubledNow(streak: Streak): boolean { | |
| 109 | + | return isBad(streak.recent.at(-1) ?? "x"); | |
| 110 | + | } | |
| 111 | + | ||
| 112 | + | /** | |
| 113 | + | * A run as kept before `checks` and `recent` (migration 0003): every one | |
| 114 | + | * of its checks failed, in a row. | |
| 115 | + | */ | |
| 116 | + | export function upgradeStreak(s: Omit<Streak, "checks" | "recent"> & { checks?: number | null; recent?: string | null }, window = DETECT_WINDOW): Streak { | |
| 117 | + | const count = Math.max(1, Number(s.count) || 1); | |
| 118 | + | const recent = s.recent || (s.state === "down" ? "x" : "s").repeat(Math.min(count, window)); | |
| 119 | + | return { ...s, count, checks: Math.max(Number(s.checks) || 0, count), recent }; | |
| 120 | + | } | |
| 121 | + | ||
| 63 | 122 | export function detect( | |
| 64 | 123 | previous: Map<string, Streak>, | |
| 65 | 124 | observations: { component: string; state: StatusComponentState }[], | |
| 66 | 125 | open: OpenRef[], | |
| 67 | 126 | maintenance: Set<string>, | |
| 68 | 127 | at: Date, | |
| 69 | − | { threshold = DETECT_AFTER, quiet = false }: DetectOptions = {}, | |
| 128 | + | { bad: need = DETECT_BAD, window = DETECT_WINDOW, recoverAfter = RECOVER_AFTER, quiet = false }: DetectOptions = {}, | |
| 70 | 129 | ): Detection { | |
| 71 | 130 | const out: Detection = { streaks: [], draft: [], failing: [], recovered: [], held: [] }; | |
| 72 | 131 | const covering = (key: string) => open.filter((i) => i.components.includes(key)); | |
| 73 | 132 | for (const { component: key, state } of observations) { | |
| 74 | 133 | const prev = previous.get(key); | |
| 75 | 134 | if (state === "unmonitored" || maintenance.has(key)) continue; | |
| 76 | − | if (state !== "degraded" && state !== "down") { | |
| 77 | − | // A good check: the run, if any, is over. Leaving it out of `streaks` ends it. | |
| 78 | − | if (prev?.alerted) for (const i of covering(key)) out.recovered.push({ incident: i.id, key, state: prev.state, since: prev.since, checks: prev.count }); | |
| 79 | − | continue; | |
| 80 | − | } | |
| 135 | + | const m = mark(state); | |
| 136 | + | if (!prev && !isBad(m)) continue; | |
| 137 | + | const recent = `${prev?.recent ?? ""}${m}`.slice(-window); | |
| 81 | 138 | const streak: Streak = prev | |
| 82 | − | ? { ...prev, count: prev.count + 1, state: prev.state === "down" || state === "down" ? "down" : "degraded" } | |
| 83 | − | : { component: key, state, count: 1, since: at.toISOString(), alerted: false }; | |
| 84 | − | if (!streak.alerted && streak.count >= threshold) { | |
| 85 | − | const trouble = { key, state: streak.state, since: streak.since, checks: streak.count }; | |
| 139 | + | ? { | |
| 140 | + | ...prev, | |
| 141 | + | recent, | |
| 142 | + | checks: prev.checks + 1, | |
| 143 | + | count: prev.count + (isBad(m) ? 1 : 0), | |
| 144 | + | state: prev.state === "down" || state === "down" ? "down" : "degraded", | |
| 145 | + | } | |
| 146 | + | : { component: key, state: state as "degraded" | "down", count: 1, checks: 1, recent, since: at.toISOString(), alerted: false }; | |
| 147 | + | const trouble = (): Trouble => ({ key, state: streak.state, since: streak.since, checks: streak.count, of: streak.checks }); | |
| 148 | + | if (!isBad(m)) { | |
| 149 | + | // Enough good checks in a row end the run, however long it was. Leaving it out of `streaks` ends it. | |
| 150 | + | if (goodTail(recent) >= Math.min(recoverAfter, window)) { | |
| 151 | + | if (streak.alerted) { | |
| 152 | + | // The good checks that ended it are not part of the trouble. | |
| 153 | + | const t = { ...trouble(), of: streak.checks - goodTail(recent) }; | |
| 154 | + | for (const i of covering(key)) out.recovered.push({ incident: i.id, ...t }); | |
| 155 | + | } | |
| 156 | + | continue; | |
| 157 | + | } | |
| 158 | + | } else if (!streak.alerted && badIn(recent) >= need) { | |
| 159 | + | const t = trouble(); | |
| 86 | 160 | const incidents = covering(key); | |
| 87 | 161 | if (incidents.length) { | |
| 88 | 162 | streak.alerted = true; | |
| 89 | − | for (const i of incidents) out.failing.push({ incident: i.id, ...trouble }); | |
| 163 | + | for (const i of incidents) out.failing.push({ incident: i.id, ...t }); | |
| 90 | 164 | } else if (quiet) { | |
| 91 | 165 | out.held.push(key); | |
| 92 | 166 | } else { | |
| 93 | 167 | streak.alerted = true; | |
| 94 | − | out.draft.push(trouble); | |
| 168 | + | out.draft.push(t); | |
| 95 | 169 | } | |
| 96 | 170 | } | |
| 97 | 171 | out.streaks.push(streak); | |
| ⋯ | |||
| 101 | 175 | ||
| 102 | 176 | // --- Deploys -------------------------------------------------------------------------- | |
| 103 | 177 | ||
| 104 | − | /** A deploy as the deploy tool reported it. */ | |
| 105 | − | export type DeployWindow = { id: string | null; started_at: string; finished_at: string | null }; | |
| 178 | + | /** | |
| 179 | + | * A deploy as the deploy tool reported it. Deploys that overlap (the jobs | |
| 180 | + | * of one stage, in parallel) are one window: `running` counts the starts | |
| 181 | + | * not yet finished, and it is finished when the last one is. | |
| 182 | + | */ | |
| 183 | + | export type DeployWindow = { | |
| 184 | + | id: string | null; | |
| 185 | + | started_at: string; | |
| 186 | + | finished_at: string | null; | |
| 187 | + | /** Starts not yet finished. */ | |
| 188 | + | running: number; | |
| 189 | + | /** The latest start: a window not finished stops counting DEPLOY_MAX_MS after it. */ | |
| 190 | + | last_started_at: string; | |
| 191 | + | }; | |
| 106 | 192 | ||
| 107 | 193 | /** Whether detection holds off at `at`: during a deploy, and for a grace period after. */ | |
| 108 | 194 | export function deployQuiet(window: DeployWindow | null, at: Date): boolean { | |
| ⋯ | |||
| 111 | 197 | const t = at.getTime(); | |
| 112 | 198 | if (Number.isNaN(start) || t < start - 60_000) return false; | |
| 113 | 199 | if (window.finished_at) return t < Date.parse(window.finished_at) + DEPLOY_GRACE_MS; | |
| 114 | − | return t < start + DEPLOY_MAX_MS; | |
| 200 | + | const last = Date.parse(window.last_started_at); | |
| 201 | + | return t < (Number.isNaN(last) ? start : Math.max(start, last)) + DEPLOY_MAX_MS; | |
| 115 | 202 | } | |
| 116 | 203 | ||
| 204 | + | /** When detection stops holding off for this window. */ | |
| 205 | + | export function quietUntil(window: DeployWindow): string { | |
| 206 | + | const end = window.finished_at | |
| 207 | + | ? Date.parse(window.finished_at) + DEPLOY_GRACE_MS | |
| 208 | + | : Math.max(Date.parse(window.started_at), Date.parse(window.last_started_at)) + DEPLOY_MAX_MS; | |
| 209 | + | return new Date(end).toISOString(); | |
| 210 | + | } | |
| 211 | + | ||
| 117 | 212 | /** The deploy tool's start or finish, folded into what is kept. */ | |
| 118 | 213 | export function deployChange(window: DeployWindow | null, phase: "started" | "finished", id: string | null, at: Date): DeployWindow { | |
| 119 | 214 | const now = at.toISOString(); | |
| 215 | + | // Still quiet: running, or in its grace period. A start then joins the window, keeping its start. | |
| 216 | + | const live = window && deployQuiet(window, at) ? window : null; | |
| 217 | + | const running = live && !live.finished_at ? Math.max(1, live.running) : 0; | |
| 120 | 218 | if (phase === "started") { | |
| 121 | − | // A second start while one is running keeps the earlier start. | |
| 122 | − | const running = window && !window.finished_at && deployQuiet(window, at); | |
| 123 | − | return { id, started_at: running ? window.started_at : now, finished_at: null }; | |
| 219 | + | return { id: id ?? live?.id ?? null, started_at: live ? live.started_at : now, finished_at: null, running: running + 1, last_started_at: now }; | |
| 124 | 220 | } | |
| 125 | − | const running = window && !window.finished_at && deployQuiet(window, at); | |
| 126 | − | return { id: id ?? window?.id ?? null, started_at: running ? window.started_at : now, finished_at: now }; | |
| 221 | + | if (running > 1) return { ...live!, id: live!.id ?? id, running: running - 1 }; | |
| 222 | + | // The last one running finished; a finish with no start is a window of its own. | |
| 223 | + | return { | |
| 224 | + | id: id ?? window?.id ?? null, | |
| 225 | + | started_at: running ? live!.started_at : now, | |
| 226 | + | finished_at: now, | |
| 227 | + | running: 0, | |
| 228 | + | last_started_at: running ? live!.last_started_at : now, | |
| 229 | + | }; | |
| 127 | 230 | } | |
| 128 | 231 | ||
| 129 | − | // --- Detected drafts that recover --------------------------------------------------------- | |
| 232 | + | // --- Detected drafts that recover, and drafts left waiting --------------------------------- | |
| 130 | 233 | ||
| 131 | − | /** A detected draft no one has picked up yet, and since when its parts have been healthy. */ | |
| 132 | − | export type WatchedDraft = { id: string; title: string; components: string[]; started_at: string; healthy_since: string | null }; | |
| 234 | + | /** A detected draft no one has picked up yet, since when its parts have been healthy, and when it was last raised again. */ | |
| 235 | + | export type WatchedDraft = { | |
| 236 | + | id: string; | |
| 237 | + | title: string; | |
| 238 | + | components: string[]; | |
| 239 | + | started_at: string; | |
| 240 | + | /** When the draft was made: STALE_AFTER_MS counts from here. */ | |
| 241 | + | declared_at: string; | |
| 242 | + | healthy_since: string | null; | |
| 243 | + | /** When the alert last went out again for it; null before the first time. */ | |
| 244 | + | reminded_at: string | null; | |
| 245 | + | }; | |
| 133 | 246 | ||
| 134 | 247 | export type Settled = { | |
| 135 | 248 | /** Every watched draft's healthy-since after this round: null while a part is in trouble. */ | |
| ⋯ | |||
| 140 | 253 | ||
| 141 | 254 | /** | |
| 142 | 255 | * Which detected drafts have recovered for good. `troubled` is every part | |
| 143 | − | * with a run of failed or slow checks after this round. | |
| 256 | + | * whose latest check was failed or slow, in a run still going (detect.ts | |
| 257 | + | * `troubledNow`). | |
| 144 | 258 | */ | |
| 145 | 259 | export function settleDrafts(drafts: WatchedDraft[], troubled: Set<string>, at: Date, after = RECOVERED_FOR_MS): Settled { | |
| 146 | 260 | const out: Settled = { healthy: [], dismiss: [] }; | |
| ⋯ | |||
| 159 | 273 | return out; | |
| 160 | 274 | } | |
| 161 | 275 | ||
| 276 | + | /** | |
| 277 | + | * Detected drafts to raise again: unacknowledged for STALE_AFTER_MS since | |
| 278 | + | * they were made, the first time; then every STALE_EVERY_MS after the last | |
| 279 | + | * time. `drafts` are the ones still waiting after this round's dismissals. | |
| 280 | + | */ | |
| 281 | + | export function staleDrafts( | |
| 282 | + | drafts: Pick<WatchedDraft, "id" | "title" | "declared_at" | "reminded_at">[], | |
| 283 | + | at: Date, | |
| 284 | + | { after = STALE_AFTER_MS, every = STALE_EVERY_MS } = {}, | |
| 285 | + | ): { id: string; title: string; waiting_ms: number }[] { | |
| 286 | + | const t = at.getTime(); | |
| 287 | + | return drafts | |
| 288 | + | .filter((d) => (d.reminded_at ? t - Date.parse(d.reminded_at) >= every : t - Date.parse(d.declared_at) >= after)) | |
| 289 | + | .map((d) => ({ id: d.id, title: d.title, waiting_ms: Math.max(0, t - Date.parse(d.declared_at)) })); | |
| 290 | + | } | |
| 291 | + | ||
| 162 | 292 | // --- Wording -------------------------------------------------------------------------------- | |
| 163 | 293 | ||
| 164 | 294 | /** What a detected failure does to its part, for the draft. */ | |
| ⋯ | |||
| 187 | 317 | return `${Math.floor(minutes / 60)}h ${String(minutes % 60).padStart(2, "0")}m`; | |
| 188 | 318 | } | |
| 189 | 319 | ||
| 320 | + | /** "4 checks in a row", or "4 of 5 checks" when good ones came between. */ | |
| 321 | + | function checksWords(t: { checks: number; of?: number }): string { | |
| 322 | + | const of = t.of ?? t.checks; | |
| 323 | + | return of > t.checks ? `${t.checks} of ${of} checks` : `${t.checks} check${t.checks === 1 ? "" : "s"} in a row`; | |
| 324 | + | } | |
| 325 | + | ||
| 190 | 326 | /** | |
| 191 | 327 | * One part's trouble in a sentence, slow and down said apart: | |
| 192 | − | * "Git has been slow — over 1.5 s — on 3 checks in a row since 6 Oct 07:25 UTC." | |
| 193 | − | * "API has not answered on 3 checks in a row since 6 Oct 07:25 UTC." | |
| 328 | + | * "Git has been slow — over 1.5 s — on 4 checks in a row since 6 Oct 07:25 UTC." | |
| 329 | + | * "API has not answered on 4 of 5 checks since 6 Oct 07:25 UTC." | |
| 194 | 330 | * `since` is already written out, in whatever zone the reader needs. | |
| 195 | 331 | */ | |
| 196 | − | export function troubleSentence(name: string, t: { state: "degraded" | "down"; checks: number }, since: string, slowMs: number): string { | |
| 197 | − | const checks = `${t.checks} check${t.checks === 1 ? "" : "s"} in a row`; | |
| 332 | + | export function troubleSentence(name: string, t: { state: "degraded" | "down"; checks: number; of?: number }, since: string, slowMs: number): string { | |
| 333 | + | const checks = checksWords(t); | |
| 198 | 334 | return t.state === "down" | |
| 199 | 335 | ? `${name} has not answered on ${checks} since ${since}.` | |
| 200 | 336 | : `${name} has been slow — over ${limitWords(slowMs)} — on ${checks} since ${since}.`; | |
| 201 | 337 | } | |
| 202 | 338 | ||
| 203 | 339 | /** A part answering again, after a run that crossed the line. */ | |
| 204 | − | export function recoverySentence(name: string, t: { state: "degraded" | "down"; checks: number }, since: string): string { | |
| 205 | − | const checks = `${t.checks} check${t.checks === 1 ? "" : "s"} in a row`; | |
| 340 | + | export function recoverySentence(name: string, t: { state: "degraded" | "down"; checks: number; of?: number }, since: string): string { | |
| 341 | + | const checks = checksWords(t); | |
| 206 | 342 | return t.state === "down" | |
| 207 | 343 | ? `${name} is answering again, after not answering on ${checks} since ${since}.` | |
| 208 | 344 | : `${name} is back to normal speed, after being slow on ${checks} since ${since}.`; | |
| ⋯ | |||
| 212 | 348 | export function autoDismissText(lastedMs: number, recoveredAt: string, healthyFor = RECOVERED_FOR_MS): string { | |
| 213 | 349 | return `Recovered after ${minutesWords(lastedMs)}, at ${recoveredAt}, and stayed healthy for ${minutesWords(healthyFor)}; dismissed automatically. It never appeared on the status page.`; | |
| 214 | 350 | } | |
| 351 | + | ||
| 352 | + | /** The timeline line when a draft left waiting is raised again. */ | |
| 353 | + | export function staleText(waitingMs: number, emailed: boolean): string { | |
| 354 | + | return `Unacknowledged for ${minutesWords(waitingMs)}.${emailed ? " The alert address was emailed again." : ""}`; | |
| 355 | + | } | |
| 9 | 9 | import { DatabaseSync } from "node:sqlite"; | |
| 10 | 10 | import { test } from "node:test"; | |
| 11 | 11 | ||
| 12 | − | import { type Streak, autoDismissText, deployChange, detect, settleDrafts } from "./detect.ts"; | |
| 12 | + | import { type Streak, autoDismissText, deployChange, detect, settleDrafts, staleDrafts, staleText } from "./detect.ts"; | |
| 13 | 13 | import { stamp } from "./postmortem.ts"; | |
| 14 | 14 | import { | |
| 15 | + | CHECK_HISTORY_DAYS, | |
| 15 | 16 | autoDismiss, | |
| 17 | + | checkHistory, | |
| 16 | 18 | createIncident, | |
| 19 | + | historySpan, | |
| 17 | 20 | incidentDetail, | |
| 18 | 21 | loadDeploy, | |
| 19 | 22 | loadStreaks, | |
| 20 | 23 | openRefs, | |
| 24 | + | record, | |
| 21 | 25 | saveDeploy, | |
| 22 | 26 | saveHealthy, | |
| 27 | + | saveReminders, | |
| 23 | 28 | saveStreaks, | |
| 24 | 29 | watchedDrafts, | |
| 25 | 30 | } from "./store.ts"; | |
| ⋯ | |||
| 78 | 83 | ||
| 79 | 84 | test("the 6 Oct draft: a slow run at 03:13 that recovered does not leak into the one at 07:25", async () => { | |
| 80 | 85 | const db = d1(); | |
| 81 | − | // 03:13 and 03:14 slow, then fine: never three in a row. | |
| 86 | + | // 03:13 and 03:14 slow, then fine: never four of five. | |
| 82 | 87 | assert.equal((await round(db, at(3, 13), "degraded")).draft.length, 0); | |
| 83 | 88 | assert.equal((await round(db, at(3, 14), "degraded")).draft.length, 0); | |
| 84 | 89 | await round(db, at(3, 15), "up"); | |
| 85 | − | assert.equal((await loadStreaks(db)).size, 0, "a recovery with nothing else failing leaves no run behind"); | |
| 90 | + | assert.equal((await loadStreaks(db)).size, 1, "one good check does not end a run"); | |
| 91 | + | await round(db, at(3, 16), "up"); | |
| 92 | + | await round(db, at(3, 17), "up"); | |
| 93 | + | assert.equal((await loadStreaks(db)).size, 0, "three good checks in a row, with nothing else failing, leave no run behind"); | |
| 86 | 94 | // 07:25 slow: the first check of a new run, not the third of the old one. | |
| 87 | 95 | const first = await round(db, at(7, 25), "degraded"); | |
| 88 | 96 | assert.equal(first.draft.length, 0); | |
| 89 | − | assert.deepEqual([...(await loadStreaks(db)).values()], [{ component: "git", state: "degraded", count: 1, since: at(7, 25).toISOString(), alerted: false }]); | |
| 97 | + | assert.deepEqual([...(await loadStreaks(db)).values()], [{ component: "git", state: "degraded", count: 1, checks: 1, recent: "s", since: at(7, 25).toISOString(), alerted: false }]); | |
| 90 | 98 | await round(db, at(7, 26), "degraded"); | |
| 91 | − | const third = await round(db, at(7, 27), "degraded"); | |
| 92 | − | assert.deepEqual(third.draft, [{ key: "git", state: "degraded", since: at(7, 25).toISOString(), checks: 3 }]); | |
| 99 | + | await round(db, at(7, 27), "degraded"); | |
| 100 | + | const fourth = await round(db, at(7, 28), "degraded"); | |
| 101 | + | assert.deepEqual(fourth.draft, [{ key: "git", state: "degraded", since: at(7, 25).toISOString(), checks: 4, of: 4 }]); | |
| 93 | 102 | }); | |
| 94 | 103 | ||
| 104 | + | test("a run kept before N of M (no checks, no recent) is read as all bad, and still ends", async () => { | |
| 105 | + | const db = d1(); | |
| 106 | + | await db.prepare(`INSERT INTO streak (component, state, count, since, alerted) VALUES ('git', 'degraded', 180, ?1, 1)`).bind(at(4, 0).toISOString()).run(); | |
| 107 | + | assert.deepEqual((await loadStreaks(db)).get("git"), { component: "git", state: "degraded", count: 180, checks: 180, recent: "sssss", since: at(4, 0).toISOString(), alerted: true }); | |
| 108 | + | await round(db, at(7, 0), "up"); | |
| 109 | + | await round(db, at(7, 1), "up"); | |
| 110 | + | assert.equal((await loadStreaks(db)).size, 1); | |
| 111 | + | await round(db, at(7, 2), "up"); | |
| 112 | + | assert.equal((await loadStreaks(db)).size, 0); | |
| 113 | + | }); | |
| 114 | + | ||
| 95 | 115 | test("a run is kept while it lasts, and only the parts still failing keep one", async () => { | |
| 96 | 116 | const db = d1(); | |
| 97 | − | const streak = (component: string): Streak => ({ component, state: "down", count: 2, since: at(1, 0).toISOString(), alerted: false }); | |
| 117 | + | const streak = (component: string): Streak => ({ component, state: "down", count: 2, checks: 3, recent: "x.x", since: at(1, 0).toISOString(), alerted: false }); | |
| 98 | 118 | await saveStreaks(db, [streak("git"), streak("api")]); | |
| 99 | 119 | await saveStreaks(db, [streak("api")]); | |
| 100 | 120 | assert.deepEqual([...(await loadStreaks(db)).keys()], ["api"]); | |
| 121 | + | assert.deepEqual((await loadStreaks(db)).get("api"), streak("api")); | |
| 101 | 122 | await saveStreaks(db, []); | |
| 102 | 123 | assert.equal((await loadStreaks(db)).size, 0); | |
| 103 | 124 | }); | |
| ⋯ | |||
| 107 | 128 | assert.equal(await loadDeploy(db), null); | |
| 108 | 129 | await saveDeploy(db, deployChange(null, "started", "run-1", at(7, 20))); | |
| 109 | 130 | await saveDeploy(db, deployChange(await loadDeploy(db), "finished", null, at(7, 24))); | |
| 110 | − | assert.deepEqual(await loadDeploy(db), { id: "run-1", started_at: at(7, 20).toISOString(), finished_at: at(7, 24).toISOString() }); | |
| 131 | + | assert.deepEqual(await loadDeploy(db), { id: "run-1", started_at: at(7, 20).toISOString(), finished_at: at(7, 24).toISOString(), running: 0, last_started_at: at(7, 20).toISOString() }); | |
| 132 | + | // A window kept before deploys were counted reads as one deploy. | |
| 133 | + | await db.prepare(`UPDATE meta SET value = ?1 WHERE key = 'deploy'`).bind(JSON.stringify({ id: "old", started_at: at(8, 0).toISOString(), finished_at: null })).run(); | |
| 134 | + | assert.deepEqual(await loadDeploy(db), { id: "old", started_at: at(8, 0).toISOString(), finished_at: null, running: 1, last_started_at: at(8, 0).toISOString() }); | |
| 135 | + | }); | |
| 136 | + | ||
| 137 | + | test("every check is kept for 7 days, with where it ran from, and an incident's page reads its parts' checks", async () => { | |
| 138 | + | const db = d1(); | |
| 139 | + | const minute = (m: number) => new Date(at(7, 0).getTime() + m * 60_000); | |
| 140 | + | for (let m = 0; m < 5; m++) { | |
| 141 | + | await record( | |
| 142 | + | db, | |
| 143 | + | [ | |
| 144 | + | { component: "speed", state: m < 3 ? "degraded" : "up", detail: "", latency_ms: m < 3 ? 1900 : 300, colo: "IAD", first_ms: m < 3 ? 2400 : null }, | |
| 145 | + | { component: "api", state: "up", detail: "", latency_ms: 90, colo: "IAD" }, | |
| 146 | + | { component: "sandboxes", state: "unmonitored", detail: "", latency_ms: null }, | |
| 147 | + | ], | |
| 148 | + | minute(m), | |
| 149 | + | ); | |
| 150 | + | } | |
| 151 | + | const kept = await checkHistory(db, ["speed"], minute(0), minute(4)); | |
| 152 | + | assert.equal(kept.length, 5); | |
| 153 | + | assert.deepEqual(kept[0], { component: "speed", at: minute(0).toISOString(), ms: 1900, outcome: "degraded", colo: "IAD", first_ms: 2400 }); | |
| 154 | + | assert.deepEqual(kept[4], { component: "speed", at: minute(4).toISOString(), ms: 300, outcome: "up", colo: "IAD", first_ms: null }); | |
| 155 | + | assert.equal((await checkHistory(db, ["sandboxes"], minute(0), minute(4))).length, 0, "a part with no check keeps no history"); | |
| 156 | + | // A round 7 days later prunes everything older. | |
| 157 | + | await record(db, [{ component: "api", state: "up", detail: "", latency_ms: 80, colo: "SJC" }], new Date(minute(2).getTime() + CHECK_HISTORY_DAYS * 86_400_000)); | |
| 158 | + | const left = await checkHistory(db, ["speed", "api"], minute(0), new Date(minute(0).getTime() + 8 * 86_400_000)); | |
| 159 | + | assert.deepEqual(left.map((c) => `${c.component}@${c.colo}`), ["api@IAD", "speed@IAD", "api@IAD", "speed@IAD", "api@IAD", "speed@IAD", "api@SJC"], "the two oldest rounds are gone"); | |
| 160 | + | ||
| 161 | + | // The incident page: its parts' checks around it, with the slow line. | |
| 162 | + | const id = await createIncident( | |
| 163 | + | db, | |
| 164 | + | { | |
| 165 | + | title: "Detected: Page speed slow", | |
| 166 | + | severity: "sev3", | |
| 167 | + | status: "investigating", | |
| 168 | + | visibility: "draft", | |
| 169 | + | source: "detected", | |
| 170 | + | components: [{ key: "speed", impact: "degraded" }], | |
| 171 | + | started_at: minute(0).toISOString(), | |
| 172 | + | acknowledged_at: null, | |
| 173 | + | commander: null, | |
| 174 | + | communications: null, | |
| 175 | + | by: "status", | |
| 176 | + | }, | |
| 177 | + | [{ kind: "detected", public: false, status: null, text: "Detected." }], | |
| 178 | + | minute(4), | |
| 179 | + | null, | |
| 180 | + | ); | |
| 181 | + | const detail = (await incidentDetail(db, id, "https://status.g1t.sh", new Map(), { limits: new Map([["speed", 800]]), now: minute(5) }))!; | |
| 182 | + | assert.equal(detail.checks.length, 1); | |
| 183 | + | assert.deepEqual([detail.checks[0]!.key, detail.checks[0]!.slow_ms, detail.checks[0]!.samples.length], ["speed", 800, 3]); | |
| 184 | + | assert.deepEqual(historySpan(minute(0).toISOString(), null, minute(5)), { from: minute(-30), to: minute(5) }); | |
| 185 | + | assert.deepEqual(historySpan(minute(0).toISOString(), minute(10).toISOString(), minute(500)), { from: minute(-30), to: minute(40) }); | |
| 186 | + | // A long one shows its last day. | |
| 187 | + | assert.deepEqual(historySpan(minute(0).toISOString(), minute(3000).toISOString(), minute(4000)), { from: minute(3030 - 1440), to: minute(3030) }); | |
| 188 | + | }); | |
| 189 | + | ||
| 190 | + | test("a draft left waiting is raised again, with a line on its timeline, and forgotten once it is not waiting", async () => { | |
| 191 | + | const db = d1(); | |
| 192 | + | const id = await createIncident( | |
| 193 | + | db, | |
| 194 | + | { | |
| 195 | + | title: "Detected: Page speed slow", | |
| 196 | + | severity: "sev3", | |
| 197 | + | status: "investigating", | |
| 198 | + | visibility: "draft", | |
| 199 | + | source: "detected", | |
| 200 | + | components: [{ key: "speed", impact: "degraded" }], | |
| 201 | + | started_at: at(7, 0).toISOString(), | |
| 202 | + | acknowledged_at: null, | |
| 203 | + | commander: null, | |
| 204 | + | communications: null, | |
| 205 | + | by: "status", | |
| 206 | + | }, | |
| 207 | + | [{ kind: "detected", public: false, status: null, text: "Detected." }], | |
| 208 | + | at(7, 4), | |
| 209 | + | null, | |
| 210 | + | ); | |
| 211 | + | const tick = async (now: Date) => { | |
| 212 | + | const waiting = await watchedDrafts(db); | |
| 213 | + | const due = staleDrafts(waiting, now); | |
| 214 | + | await saveReminders(db, waiting.map((d) => d.id), due.map((d) => ({ id: d.id, text: staleText(d.waiting_ms, true) })), now); | |
| 215 | + | return due.map((d) => d.id); | |
| 216 | + | }; | |
| 217 | + | assert.deepEqual(await tick(at(7, 48)), []); | |
| 218 | + | assert.deepEqual(await tick(at(7, 49)), [id], "45 minutes after the draft was made"); | |
| 219 | + | assert.equal((await watchedDrafts(db))[0]!.reminded_at, at(7, 49).toISOString()); | |
| 220 | + | assert.deepEqual(await tick(at(7, 50)), [], "once"); | |
| 221 | + | assert.deepEqual(await tick(at(13, 48)), []); | |
| 222 | + | assert.deepEqual(await tick(at(13, 49)), [id], "then every 6 hours"); | |
| 223 | + | const detail = (await incidentDetail(db, id, "https://status.g1t.sh", new Map()))!; | |
| 224 | + | assert.deepEqual(detail.timeline.filter((e) => e.kind === "note").map((e) => [e.by, e.text]), [ | |
| 225 | + | ["status", "Unacknowledged for 45 minutes. The alert address was emailed again."], | |
| 226 | + | ["status", "Unacknowledged for 6h 45m. The alert address was emailed again."], | |
| 227 | + | ]); | |
| 228 | + | assert.equal(detail.acknowledged_at, null, "a reminder is not an acknowledgement"); | |
| 229 | + | // Picked up: no longer watched, and its bookkeeping goes. | |
| 230 | + | await db.prepare(`UPDATE incident SET acknowledged_at = ?1 WHERE id = ?2`).bind(at(14, 0).toISOString(), id).run(); | |
| 231 | + | assert.deepEqual(await tick(at(20, 0)), []); | |
| 232 | + | assert.equal((await db.prepare(`SELECT COUNT(*) AS n FROM meta WHERE key LIKE 'draft_reminded:%'`).first<{ n: number }>())!.n, 0); | |
| 111 | 233 | }); | |
| 112 | 234 | ||
| 113 | 235 | test("a detected draft that recovered is dismissed after ten healthy minutes; one staff picked up is left alone", async () => { | |
| 115 | 115 | }; | |
| 116 | 116 | } | |
| 117 | 117 | ||
| 118 | + | /** | |
| 119 | + | * The alert again, for a detected draft nobody has acknowledged: after 45 | |
| 120 | + | * minutes, then every 6 hours while it waits (detect.ts `staleDrafts`). | |
| 121 | + | */ | |
| 122 | + | export function staleLetter(input: { title: string; waiting: string; link: string }): Letter { | |
| 123 | + | return { | |
| 124 | + | heading: `Still waiting: ${input.title.replace(/^Detected: /, "")}`, | |
| 125 | + | paragraphs: [ | |
| 126 | + | `A detected draft incident has been waiting ${input.waiting} for someone to pick it up, and its parts have not stayed healthy long enough for it to be dismissed on its own.`, | |
| 127 | + | "Acknowledge it in sudo: publish it, add a note, or dismiss it if it is not an incident. Until then this goes out again every 6 hours.", | |
| 128 | + | ], | |
| 129 | + | action: { label: "Open it in sudo", url: input.link }, | |
| 130 | + | footer: ["Sent by status.g1t.sh to the staff alert address (STATUS_ALERT_EMAIL)."], | |
| 131 | + | }; | |
| 132 | + | } | |
| 133 | + | ||
| 118 | 134 | /** The follow-up when a detected draft recovered and was dismissed on its own. */ | |
| 119 | 135 | export function recoveredLetter(input: { title: string; text: string; link: string }): Letter { | |
| 120 | 136 | return { |
| 53 | 53 | ||
| 54 | 54 | import { type Targets, components } from "./components.ts"; | |
| 55 | 55 | import { | |
| 56 | − | DEPLOY_GRACE_MS, | |
| 57 | − | DEPLOY_MAX_MS, | |
| 58 | 56 | autoDismissText, | |
| 59 | 57 | deployChange, | |
| 60 | 58 | deployQuiet, | |
| 61 | 59 | detect, | |
| 62 | 60 | detectedImpact, | |
| 63 | 61 | draftTitle, | |
| 62 | + | minutesWords, | |
| 63 | + | quietUntil, | |
| 64 | 64 | recoverySentence, | |
| 65 | 65 | settleDrafts, | |
| 66 | + | staleDrafts, | |
| 67 | + | staleText, | |
| 66 | 68 | troubleSentence, | |
| 69 | + | troubledNow, | |
| 67 | 70 | } from "./detect.ts"; | |
| 68 | − | import { type EmailBinding, type Sender, alertLetter, bindingSender, confirmLetter, recoveredLetter, render as renderMail, unsubscribeHeaders, updateLetter } from "./email.ts"; | |
| 71 | + | import { | |
| 72 | + | type EmailBinding, | |
| 73 | + | type Sender, | |
| 74 | + | alertLetter, | |
| 75 | + | bindingSender, | |
| 76 | + | confirmLetter, | |
| 77 | + | recoveredLetter, | |
| 78 | + | render as renderMail, | |
| 79 | + | staleLetter, | |
| 80 | + | unsubscribeHeaders, | |
| 81 | + | updateLetter, | |
| 82 | + | } from "./email.ts"; | |
| 69 | 83 | import { atom, feedItems, jsonFeed } from "./feed.ts"; | |
| 70 | 84 | import { | |
| 71 | 85 | type Entry, | |
| ⋯ | |||
| 85 | 99 | } from "./incidents.ts"; | |
| 86 | 100 | import { INCIDENT_STATUS, type PageModel, SLOW_MS, buildPage, classify, underMaintenance } from "./model.ts"; | |
| 87 | 101 | import { stamp } from "./postmortem.ts"; | |
| 88 | − | import { type StorageReport, runCheck } from "./probe.ts"; | |
| 102 | + | import { type StorageReport, probe } from "./probe.ts"; | |
| 89 | 103 | import { readZone } from "./time.ts"; | |
| 90 | 104 | import { | |
| 91 | 105 | FAVICON, | |
| ⋯ | |||
| 130 | 144 | saveHealthy, | |
| 131 | 145 | saveIncident, | |
| 132 | 146 | savePostmortem, | |
| 147 | + | saveReminders, | |
| 133 | 148 | saveStreaks, | |
| 134 | 149 | scheduleMaintenance, | |
| 135 | 150 | setFollowUp, | |
| ⋯ | |||
| 218 | 233 | const billing = env.BILLING; | |
| 219 | 234 | const repos = env.REPOS; | |
| 220 | 235 | const list = parts(env); | |
| 221 | − | const observations = await Promise.all( | |
| 222 | − | list.map(async (info): Promise<Observation> => { | |
| 223 | − | const result = await runCheck(info.check, { | |
| 224 | − | fetch: (url, init) => fetch(url, init), | |
| 225 | − | billing: billing ? () => billingClient(billing).prices() : null, | |
| 226 | − | storage: repos ? () => storeHealth(repos) : null, | |
| 227 | − | }); | |
| 228 | − | const { state, detail } = classify(result, info.slowMs); | |
| 229 | − | return { component: info.key, state, detail, latency_ms: result ? Math.round(result.ms) : null }; | |
| 236 | + | const results = await Promise.all( | |
| 237 | + | list.map(async (info) => { | |
| 238 | + | // A slow answer is asked again at once before it counts (probe.ts `probe`). | |
| 239 | + | const result = await probe( | |
| 240 | + | info.check, | |
| 241 | + | { | |
| 242 | + | fetch: (url, init) => fetch(url, init), | |
| 243 | + | billing: billing ? () => billingClient(billing).prices() : null, | |
| 244 | + | storage: repos ? () => storeHealth(repos) : null, | |
| 245 | + | }, | |
| 246 | + | info.slowMs ?? SLOW_MS, | |
| 247 | + | ); | |
| 248 | + | return { info, result }; | |
| 230 | 249 | }), | |
| 231 | 250 | ); | |
| 251 | + | // Checks through a binding have no cf-ray of their own: they ran where the others did. | |
| 252 | + | const roundColo = results.find((r) => r.result?.colo)?.result?.colo ?? null; | |
| 253 | + | const observations = results.map(({ info, result }): Observation => { | |
| 254 | + | const { state, detail } = classify(result, info.slowMs); | |
| 255 | + | return { | |
| 256 | + | component: info.key, | |
| 257 | + | state, | |
| 258 | + | detail, | |
| 259 | + | latency_ms: result ? Math.round(result.ms) : null, | |
| 260 | + | colo: result ? (result.colo ?? roundColo) : null, | |
| 261 | + | first_ms: result?.first_ms != null ? Math.round(result.first_ms) : null, | |
| 262 | + | }; | |
| 263 | + | }); | |
| 232 | 264 | const { maintenance } = await load(env.DB, now, originOf(env)); | |
| 233 | 265 | await record(env.DB, observations, now, underMaintenance(maintenance, now)); | |
| 234 | 266 | return observations; | |
| ⋯ | |||
| 341 | 373 | } | |
| 342 | 374 | } | |
| 343 | 375 | // Detected drafts no one picked up, whose parts have stayed healthy long enough: dismissed, with a word to staff. | |
| 344 | − | const troubled = new Set(found.streaks.map((s) => s.component)); | |
| 345 | − | const settled = settleDrafts(await watchedDrafts(env.DB), troubled, now); | |
| 376 | + | // A part counts as healthy from its first good check; a run that is still going but answered well last time does not hold a draft up. | |
| 377 | + | const troubled = new Set(found.streaks.filter(troubledNow).map((s) => s.component)); | |
| 378 | + | const watched = await watchedDrafts(env.DB); | |
| 379 | + | const settled = settleDrafts(watched, troubled, now); | |
| 346 | 380 | await saveHealthy(env.DB, settled.healthy); | |
| 381 | + | const dismissed = new Set<string>(); | |
| 347 | 382 | for (const d of settled.dismiss) { | |
| 348 | 383 | const text = autoDismissText(d.lasted_ms, stamp(d.recovered_at)); | |
| 349 | 384 | if (!(await autoDismiss(env.DB, d.id, d.recovered_at, text, now))) continue; | |
| 385 | + | dismissed.add(d.id); | |
| 350 | 386 | console.log(JSON.stringify({ event: "status.auto_dismissed", id: d.id, lasted_ms: d.lasted_ms })); | |
| 351 | 387 | if (alertTo && send) { | |
| 352 | 388 | const letter = recoveredLetter({ title: d.title, text, link: sudo(d.id) }); | |
| ⋯ | |||
| 354 | 390 | ctx.waitUntil(send.send({ to: alertTo, subject: `[g1t status] ${letter.heading}`, text: body, html }).catch((e) => console.error(JSON.stringify({ event: "status.alert_failed", error: String(e) })))); | |
| 355 | 391 | } | |
| 356 | 392 | } | |
| 393 | + | // Drafts still waiting for someone: the alert goes out again after 45 minutes, then every 6 hours. | |
| 394 | + | const waiting = watched.filter((d) => !dismissed.has(d.id)); | |
| 395 | + | const stale = staleDrafts(waiting, now); | |
| 396 | + | const emailed = !!(alertTo && send); | |
| 397 | + | await saveReminders( | |
| 398 | + | env.DB, | |
| 399 | + | waiting.map((d) => d.id), | |
| 400 | + | stale.map((d) => ({ id: d.id, text: staleText(d.waiting_ms, emailed) })), | |
| 401 | + | now, | |
| 402 | + | ); | |
| 403 | + | for (const d of stale) { | |
| 404 | + | console.warn(JSON.stringify({ event: "status.draft_waiting", id: d.id, waiting_ms: d.waiting_ms })); | |
| 405 | + | if (!emailed) continue; | |
| 406 | + | const letter = staleLetter({ title: d.title, waiting: minutesWords(d.waiting_ms), link: sudo(d.id) }); | |
| 407 | + | const { text: body, html } = renderMail(letter); | |
| 408 | + | ctx.waitUntil(send!.send({ to: alertTo, subject: `[g1t status] ${letter.heading}`, text: body, html }).catch((e) => console.error(JSON.stringify({ event: "status.alert_failed", error: String(e) })))); | |
| 409 | + | } | |
| 357 | 410 | } | |
| 358 | 411 | ||
| 359 | 412 | /** | |
| ⋯ | |||
| 380 | 433 | const now = new Date(); | |
| 381 | 434 | const window = deployChange(await loadDeploy(env.DB), phase, id, now); | |
| 382 | 435 | await saveDeploy(env.DB, window); | |
| 383 | − | console.log(JSON.stringify({ event: `status.deploy_${phase}`, id })); | |
| 384 | − | const quietUntil = window.finished_at ? Date.parse(window.finished_at) + DEPLOY_GRACE_MS : Date.parse(window.started_at) + DEPLOY_MAX_MS; | |
| 385 | − | return json({ deploy: window, quiet_until: new Date(quietUntil).toISOString() }); | |
| 436 | + | console.log(JSON.stringify({ event: `status.deploy_${phase}`, id, running: window.running })); | |
| 437 | + | return json({ deploy: window, quiet_until: quietUntil(window) }); | |
| 386 | 438 | } | |
| 387 | 439 | ||
| 388 | 440 | /** Compares two secrets in constant time, by their hashes. */ | |
| ⋯ | |||
| 668 | 720 | } | |
| 669 | 721 | ||
| 670 | 722 | private async detail(id: string): Promise<AdminIncidentDetail | null> { | |
| 671 | − | return incidentDetail(this.env.DB, String(id), this.origin(), names(this.env)); | |
| 723 | + | const limits = new Map(parts(this.env).map((p) => [p.key, p.slowMs ?? SLOW_MS])); | |
| 724 | + | return incidentDetail(this.env.DB, String(id), this.origin(), names(this.env), { limits }); | |
| 672 | 725 | } | |
| 673 | 726 | ||
| 674 | 727 | private async summary(id: string): Promise<AdminIncident> { | |
| 675 | − | const { timeline: _t, followups: _f, postmortem: _p, postmortem_draft: _d, url: _u, ...incident } = (await this.detail(id))!; | |
| 728 | + | const { timeline: _t, followups: _f, postmortem: _p, postmortem_draft: _d, url: _u, checks: _c, ...incident } = (await this.detail(id))!; | |
| 676 | 729 | return incident; | |
| 677 | 730 | } | |
| 678 | 731 | ||
| 191 | 191 | ["site", "api", "git", "speed", "mcp", "docs", "deployments", "agents", "sandboxes", "billing"], | |
| 192 | 192 | ); | |
| 193 | 193 | const speed = all.find((c) => c.key === "speed")!; | |
| 194 | − | assert.deepEqual(speed.check, { kind: "http", steps: [{ url: "https://g1t.sh/flagon-io/g1t" }, { url: "https://g1t.sh/explore" }] }); | |
| 194 | + | assert.deepEqual(speed.check, { kind: "http", steps: [{ url: "https://g1t.sh/flagon-io/g1t", browser: true }, { url: "https://g1t.sh/explore", browser: true }] }); | |
| 195 | 195 | assert.equal(classify({ ok: true, ms: 900 }, speed.slowMs).state, "degraded"); | |
| 196 | 196 | assert.equal(classify({ ok: true, ms: 300 }, speed.slowMs).state, "up"); | |
| 197 | 197 | const git = all.find((c) => c.key === "git")!; |
| 1 | 1 | import assert from "node:assert/strict"; | |
| 2 | 2 | import { test } from "node:test"; | |
| 3 | 3 | ||
| 4 | − | import { combine, judgeStorage, runCheck, step } from "./probe.ts"; | |
| 4 | + | import { isbot } from "isbot"; | |
| 5 | + | ||
| 6 | + | import { components } from "./components.ts"; | |
| 7 | + | import { BROWSER_USER_AGENT, USER_AGENT, coloOf, combine, confirmSlow, judgeStorage, probe, runCheck, step } from "./probe.ts"; | |
| 5 | 8 | ||
| 6 | 9 | const answer = (status: number) => async () => new Response("x", { status }); | |
| 7 | 10 | ||
| 11 | + | test("page loads say they are a browser, so the site streams them; the name stays on the end", async () => { | |
| 12 | + | // The isbot apps/web's entry.server.tsx uses: a match waits for the full render. | |
| 13 | + | assert.equal(isbot(USER_AGENT), true, "the plain user agent reads as a crawler"); | |
| 14 | + | assert.equal(isbot(BROWSER_USER_AGENT), false); | |
| 15 | + | assert.match(BROWSER_USER_AGENT, /g1t-status\/1\.0/); | |
| 16 | + | const seen: string[] = []; | |
| 17 | + | const fetcher = async (_url: string, init: RequestInit) => { | |
| 18 | + | seen.push(new Headers(init.headers).get("user-agent") ?? ""); | |
| 19 | + | return new Response("x"); | |
| 20 | + | }; | |
| 21 | + | await step(fetcher, { url: "https://a/", browser: true }); | |
| 22 | + | await step(fetcher, { url: "https://a/" }); | |
| 23 | + | assert.deepEqual(seen, [BROWSER_USER_AGENT, USER_AGENT]); | |
| 24 | + | // The site's pages load as a browser would; git, the API and the rest as before. | |
| 25 | + | const parts = components({ SITE_URL: "https://g1t.sh", API_URL: "https://api.g1t.sh", PROBE_REPO: "flagon-io/g1t", DOCS_URL: "https://docs.g1t.sh" }); | |
| 26 | + | const browsing = parts.flatMap((p) => (p.check.kind === "http" ? p.check.steps.filter((s) => s.browser).map((s) => s.url) : [])); | |
| 27 | + | assert.deepEqual(browsing, ["https://g1t.sh/login", "https://g1t.sh/flagon-io/g1t", "https://g1t.sh/explore"]); | |
| 28 | + | }); | |
| 29 | + | ||
| 30 | + | test("the data centre that answered is read from cf-ray", async () => { | |
| 31 | + | assert.equal(coloOf("8c1f2e3d4a5b6c7d-IAD"), "IAD"); | |
| 32 | + | assert.equal(coloOf("8c1f2e3d4a5b6c7d-ams"), "AMS"); | |
| 33 | + | assert.equal(coloOf(null), null); | |
| 34 | + | assert.equal(coloOf("nonsense"), null); | |
| 35 | + | const ray = async () => new Response("x", { headers: { "cf-ray": "8c1f2e3d4a5b6c7d-SJC" } }); | |
| 36 | + | assert.equal((await step(ray, { url: "https://a/" })).colo, "SJC"); | |
| 37 | + | assert.equal((await step(answer(200), { url: "https://a/" })).colo, undefined); | |
| 38 | + | assert.equal(combine([{ ok: true, ms: 1 }, { ok: true, ms: 2, colo: "FRA" }]).colo, "FRA"); | |
| 39 | + | }); | |
| 40 | + | ||
| 41 | + | test("a slow answer is asked again at once: one slow answer is not slow, two are", async () => { | |
| 42 | + | // Fast the second time: counts as the fast one, keeping the first time. | |
| 43 | + | assert.deepEqual(confirmSlow({ ok: true, ms: 2400, colo: "IAD" }, { ok: true, ms: 300, colo: "IAD" }), { ok: true, ms: 300, colo: "IAD", first_ms: 2400 }); | |
| 44 | + | // Slow twice: slow, at the faster of the two. | |
| 45 | + | assert.deepEqual(confirmSlow({ ok: true, ms: 2400 }, { ok: true, ms: 1900 }), { ok: true, ms: 1900, first_ms: 2400 }); | |
| 46 | + | // A second try that failed does not make it worse. | |
| 47 | + | assert.deepEqual(confirmSlow({ ok: true, ms: 2400 }, { ok: false, ms: 5000, error: "timed out" }), { ok: true, ms: 2400, first_ms: 2400 }); | |
| 48 | + | ||
| 49 | + | let calls = 0; | |
| 50 | + | const times = [1200, 200]; | |
| 51 | + | let clock = 0; | |
| 52 | + | const timedFetch = async () => { | |
| 53 | + | clock += times[calls++] ?? 0; | |
| 54 | + | return new Response("x"); | |
| 55 | + | }; | |
| 56 | + | const check = { kind: "http" as const, steps: [{ url: "https://a/" }] }; | |
| 57 | + | // A fake clock through the fetch: probe() asks again only when the first is slow. | |
| 58 | + | const realNow = Date.now; | |
| 59 | + | Date.now = () => clock; | |
| 60 | + | try { | |
| 61 | + | const confirmed = await probe(check, { fetch: timedFetch, billing: null }, 800); | |
| 62 | + | assert.equal(calls, 2); | |
| 63 | + | assert.deepEqual(confirmed, { ok: true, ms: 200, first_ms: 1200 }); | |
| 64 | + | calls = 0; | |
| 65 | + | clock = 0; | |
| 66 | + | times.splice(0, 2, 300, 300); | |
| 67 | + | assert.deepEqual(await probe(check, { fetch: timedFetch, billing: null }, 800), { ok: true, ms: 300 }); | |
| 68 | + | assert.equal(calls, 1, "a check in time is not asked twice"); | |
| 69 | + | } finally { | |
| 70 | + | Date.now = realNow; | |
| 71 | + | } | |
| 72 | + | // Failures are not asked again: detection's N of M decides about them (detect.ts). | |
| 73 | + | calls = 0; | |
| 74 | + | const failing = async () => { | |
| 75 | + | calls += 1; | |
| 76 | + | return new Response("x", { status: 502 }); | |
| 77 | + | }; | |
| 78 | + | assert.equal((await probe(check, { fetch: failing, billing: null }, 800))!.ok, false); | |
| 79 | + | assert.equal(calls, 1); | |
| 80 | + | }); | |
| 81 | + | ||
| 8 | 82 | test("a step works on 2xx, or on exactly the status it expects", async () => { | |
| 9 | 83 | assert.equal((await step(answer(200), { url: "https://a/" })).ok, true); | |
| 10 | 84 | const refused = await step(answer(502), { url: "https://a/" }); |
| 13 | 13 | error?: string; | |
| 14 | 14 | /** Why it worked but not well, when that is not just slowness. */ | |
| 15 | 15 | degraded?: string; | |
| 16 | + | /** | |
| 17 | + | * The Cloudflare data centre that answered, from the `cf-ray` header's | |
| 18 | + | * suffix (`8c1f…-IAD`): where the check ran from, as far as g1t saw it. | |
| 19 | + | */ | |
| 20 | + | colo?: string; | |
| 21 | + | /** Slow at first and checked again at once (`confirmSlow`): the first try's time. */ | |
| 22 | + | first_ms?: number; | |
| 16 | 23 | }; | |
| 17 | 24 | ||
| 18 | 25 | /** How one git store namespace answered lately: repos `store_health`. */ | |
| ⋯ | |||
| 62 | 69 | /** No request waits longer than this. */ | |
| 63 | 70 | export const TIMEOUT_MS = 5000; | |
| 64 | 71 | ||
| 72 | + | /** What every check but a page load says it is. */ | |
| 65 | 73 | export const USER_AGENT = "g1t-status (+https://status.g1t.sh)"; | |
| 66 | 74 | ||
| 75 | + | /** | |
| 76 | + | * What a page load (`Step.browser`) says it is: a browser's user agent with | |
| 77 | + | * `g1t-status/1.0 (+status.g1t.sh)` on the end, so it still says who it is. | |
| 78 | + | * | |
| 79 | + | * The site renders a page for a crawler in full before sending a byte (an | |
| 80 | + | * `isbot` match makes apps/web's entry.server.tsx wait for `allReady`), | |
| 81 | + | * and streams the shell first for a browser. USER_AGENT matches isbot (on | |
| 82 | + | * "http", and "status/"), so with it Page speed timed a crawler's full | |
| 83 | + | * render, while its budget is to the first byte. probe.test.ts checks this | |
| 84 | + | * one against the isbot the site uses. Keep the name after "Safari/537.36", | |
| 85 | + | * and keep "http" and "compatible;" out of it: isbot matches a URL, and | |
| 86 | + | * "status/" inside a "compatible" comment. | |
| 87 | + | */ | |
| 88 | + | export const BROWSER_USER_AGENT = | |
| 89 | + | "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/130.0.0.0 Safari/537.36 g1t-status/1.0 (+status.g1t.sh)"; | |
| 90 | + | ||
| 67 | 91 | type Fetch = (url: string, init: RequestInit) => Promise<Response>; | |
| 68 | 92 | ||
| 69 | 93 | class Timeout extends Error {} | |
| ⋯ | |||
| 96 | 120 | } | |
| 97 | 121 | ||
| 98 | 122 | /** One request, answered with the status that means it works. */ | |
| 99 | − | export function step(fetcher: Fetch, { url, headers = {}, expect }: Step, timeoutMs = TIMEOUT_MS): Promise<ProbeResult> { | |
| 100 | − | return timed(async (signal) => { | |
| 123 | + | export async function step(fetcher: Fetch, { url, headers = {}, expect, browser = false }: Step, timeoutMs = TIMEOUT_MS): Promise<ProbeResult> { | |
| 124 | + | let colo: string | null = null; | |
| 125 | + | const result = await timed(async (signal) => { | |
| 101 | 126 | const response = await fetcher(url, { | |
| 102 | 127 | signal, | |
| 103 | 128 | redirect: "manual", | |
| 104 | − | headers: { "user-agent": USER_AGENT, "cache-control": "no-cache", ...headers }, | |
| 129 | + | headers: { "user-agent": browser ? BROWSER_USER_AGENT : USER_AGENT, "cache-control": "no-cache", ...headers }, | |
| 105 | 130 | }); | |
| 131 | + | // Timed to the answer's headers: the body is never read. | |
| 132 | + | colo = coloOf(response.headers.get("cf-ray")); | |
| 106 | 133 | await response.body?.cancel().catch(() => undefined); | |
| 107 | 134 | const good = expect == null ? response.ok : response.status === expect; | |
| 108 | 135 | return good || `HTTP ${response.status}`; | |
| 109 | 136 | }, timeoutMs); | |
| 137 | + | return colo ? { ...result, colo } : result; | |
| 110 | 138 | } | |
| 111 | 139 | ||
| 140 | + | /** The data centre in a `cf-ray` header: `8c1f2e3d4a5b6c7d-IAD` is `IAD`. */ | |
| 141 | + | export function coloOf(ray: string | null | undefined): string | null { | |
| 142 | + | const m = /-([A-Za-z]{3,4})$/.exec((ray ?? "").trim()); | |
| 143 | + | return m ? m[1]!.toUpperCase() : null; | |
| 144 | + | } | |
| 145 | + | ||
| 112 | 146 | /** A check's requests together: it works when every one does, and takes as long as the slowest. */ | |
| 113 | 147 | export function combine(results: ProbeResult[]): ProbeResult { | |
| 114 | 148 | const ms = Math.max(0, ...results.map((r) => r.ms)); | |
| 115 | 149 | const failed = results.find((r) => !r.ok); | |
| 116 | − | return failed ? { ok: false, ms, error: failed.error ?? "no answer" } : { ok: true, ms }; | |
| 150 | + | const colo = results.find((r) => r.colo)?.colo; | |
| 151 | + | const out: ProbeResult = failed ? { ok: false, ms, error: failed.error ?? "no answer" } : { ok: true, ms }; | |
| 152 | + | return colo ? { ...out, colo } : out; | |
| 117 | 153 | } | |
| 118 | 154 | ||
| 155 | + | /** Whether a result is only slow: it worked, with nothing else wrong, but over `slowMs`. */ | |
| 156 | + | export function onlySlow(result: ProbeResult | null, slowMs: number): boolean { | |
| 157 | + | return result != null && result.ok && !result.degraded && Math.round(result.ms) > slowMs; | |
| 158 | + | } | |
| 159 | + | ||
| 160 | + | /** | |
| 161 | + | * A slow check, and the same check run again at once: the better of the | |
| 162 | + | * two. One slow answer (a cold isolate, a cache refill, a busy moment on | |
| 163 | + | * the path) does not count when the next answers in time; slow twice is | |
| 164 | + | * slow, at the faster of the two times. A second try that failed does not | |
| 165 | + | * make a slow check worse. `first_ms` keeps the first try's time. | |
| 166 | + | */ | |
| 167 | + | export function confirmSlow(first: ProbeResult, again: ProbeResult | null): ProbeResult { | |
| 168 | + | if (!again || !again.ok || again.degraded) return { ...first, first_ms: first.ms }; | |
| 169 | + | const better = again.ms < first.ms ? again : first; | |
| 170 | + | const colo = better.colo ?? first.colo ?? again.colo; | |
| 171 | + | return { ...better, ...(colo ? { colo } : {}), first_ms: first.ms }; | |
| 172 | + | } | |
| 173 | + | ||
| 119 | 174 | /** What runs a check. `billing` is null when there is no binding to it. */ | |
| 120 | 175 | export type Probers = { | |
| 121 | 176 | fetch: Fetch; | |
| ⋯ | |||
| 150 | 205 | return null; | |
| 151 | 206 | } | |
| 152 | 207 | } | |
| 208 | + | ||
| 209 | + | /** | |
| 210 | + | * Runs one part's check as the cron does: an address that answered, but | |
| 211 | + | * slowly, is asked once more straight away (`confirmSlow`) before the slow | |
| 212 | + | * answer counts. Checks through a binding are not repeated: git storage | |
| 213 | + | * reports the minutes gone by, and asking twice says the same. | |
| 214 | + | */ | |
| 215 | + | export async function probe(check: Check, probers: Probers, slowMs: number): Promise<ProbeResult | null> { | |
| 216 | + | const first = await runCheck(check, probers); | |
| 217 | + | if (check.kind !== "http" || !first || !onlySlow(first, slowMs)) return first; | |
| 218 | + | return confirmSlow(first, await runCheck(check, probers)); | |
| 219 | + | } | |
| 7 | 7 | AdminIncident, | |
| 8 | 8 | AdminIncidentDetail, | |
| 9 | 9 | AdminMaintenance, | |
| 10 | + | CheckHistory, | |
| 11 | + | CheckSample, | |
| 10 | 12 | ComponentImpact, | |
| 11 | 13 | FollowUp, | |
| 12 | 14 | ImpactInput, | |
| ⋯ | |||
| 23 | 25 | TimelineKind, | |
| 24 | 26 | } from "@g1t/contracts"; | |
| 25 | 27 | ||
| 26 | − | import type { DeployWindow, Streak, WatchedDraft } from "./detect.ts"; | |
| 28 | + | import { type DeployWindow, type Streak, type WatchedDraft, upgradeStreak } from "./detect.ts"; | |
| 27 | 29 | import { type Entry, type IncidentFacts, durations, shortId } from "./incidents.ts"; | |
| 28 | 30 | import { type Current, type DayRow, HISTORY_DAYS, dayOf, overallImpact } from "./model.ts"; | |
| 29 | 31 | import { postmortemDraft } from "./postmortem.ts"; | |
| ⋯ | |||
| 33 | 35 | const iso = (ms: number) => new Date(ms).toISOString(); | |
| 34 | 36 | ||
| 35 | 37 | /** One part's check, ready to keep. */ | |
| 36 | − | export type Observation = Current & { component: string }; | |
| 38 | + | export type Observation = Current & { | |
| 39 | + | component: string; | |
| 40 | + | /** The data centre the check ran from (cf-ray), when known. */ | |
| 41 | + | colo?: string | null; | |
| 42 | + | /** A slow answer asked again (probe.ts `confirmSlow`): the first try's time. */ | |
| 43 | + | first_ms?: number | null; | |
| 44 | + | }; | |
| 45 | + | ||
| 46 | + | /** How long every single check is kept (`check_history`), for sudo's incident pages. */ | |
| 47 | + | export const CHECK_HISTORY_DAYS = 7; | |
| 37 | 48 | ||
| 38 | 49 | /** | |
| 39 | − | * Keeps one round of checks: each part's state, today's tally, and the | |
| 40 | − | * time. Parts under maintenance keep their last check but are left out of | |
| 41 | − | * the tally: failures in a planned window do not count against uptime. | |
| 50 | + | * Keeps one round of checks: each part's state, today's tally, every | |
| 51 | + | * check for CHECK_HISTORY_DAYS, and the time. Parts under maintenance keep | |
| 52 | + | * their last check but are left out of the tally: failures in a planned | |
| 53 | + | * window do not count against uptime. | |
| 42 | 54 | */ | |
| 43 | 55 | export async function record(db: D1Database, observations: Observation[], at: Date, maintenance: Set<string> = new Set()): Promise<void> { | |
| 44 | 56 | const when = at.toISOString(); | |
| ⋯ | |||
| 54 | 66 | ) | |
| 55 | 67 | .bind(o.component, o.state, o.detail, o.latency_ms, when), | |
| 56 | 68 | ); | |
| 57 | − | if (o.state === "unmonitored" || maintenance.has(o.component)) continue; | |
| 69 | + | if (o.state === "unmonitored") continue; | |
| 70 | + | statements.push( | |
| 71 | + | db | |
| 72 | + | .prepare(`INSERT OR REPLACE INTO check_history (component, at, ms, outcome, colo, first_ms) VALUES (?1, ?2, ?3, ?4, ?5, ?6)`) | |
| 73 | + | .bind(o.component, when, o.latency_ms, o.state, o.colo ?? null, o.first_ms ?? null), | |
| 74 | + | ); | |
| 75 | + | if (maintenance.has(o.component)) continue; | |
| 58 | 76 | const up = o.state === "up" ? 1 : 0; | |
| 59 | 77 | const degraded = o.state === "degraded" ? 1 : 0; | |
| 60 | 78 | const down = o.state === "down" ? 1 : 0; | |
| ⋯ | |||
| 77 | 95 | db.prepare(`INSERT INTO meta (key, value) VALUES ('checked_at', ?1) ON CONFLICT (key) DO UPDATE SET value = ?1`).bind(when), | |
| 78 | 96 | ); | |
| 79 | 97 | statements.push(db.prepare(`DELETE FROM daily WHERE day < ?1`).bind(oldest)); | |
| 98 | + | statements.push(db.prepare(`DELETE FROM check_history WHERE at < ?1`).bind(iso(at.getTime() - CHECK_HISTORY_DAYS * DAY_MS))); | |
| 80 | 99 | await db.batch(statements); | |
| 81 | 100 | } | |
| 82 | 101 | ||
| 102 | + | /** Every check of `components` from `from` to `to`, oldest first. */ | |
| 103 | + | export async function checkHistory(db: D1Database, components: string[], from: Date, to: Date): Promise<CheckSample[]> { | |
| 104 | + | if (!components.length) return []; | |
| 105 | + | const list = rows<CheckSample>( | |
| 106 | + | (await db | |
| 107 | + | .prepare( | |
| 108 | + | `SELECT component, at, ms, outcome, colo, first_ms FROM check_history | |
| 109 | + | WHERE at >= ? AND at <= ? AND component IN (${inList(components)}) ORDER BY at, component`, | |
| 110 | + | ) | |
| 111 | + | .bind(from.toISOString(), to.toISOString(), ...components) | |
| 112 | + | .all()) as D1Result, | |
| 113 | + | ); | |
| 114 | + | return list.map((r) => ({ ...r, ms: r.ms == null ? null : Number(r.ms), first_ms: r.first_ms == null ? null : Number(r.first_ms) })); | |
| 115 | + | } | |
| 116 | + | ||
| 117 | + | /** Before the impact began, and after it ended, the incident page shows this much more. */ | |
| 118 | + | const AROUND_MS = 30 * 60_000; | |
| 119 | + | /** The most of one incident's checks the incident page shows: the last day of it. */ | |
| 120 | + | const SPAN_MS = DAY_MS; | |
| 121 | + | ||
| 122 | + | /** The span of checks an incident's page shows: from before it began to after it ended (or now), at most a day, within what is kept. */ | |
| 123 | + | export function historySpan(started_at: string, resolved_at: string | null, now: Date): { from: Date; to: Date } { | |
| 124 | + | const to = Math.min(now.getTime(), resolved_at ? Date.parse(resolved_at) + AROUND_MS : now.getTime()); | |
| 125 | + | const from = Math.max(Date.parse(started_at) - AROUND_MS, to - SPAN_MS, now.getTime() - CHECK_HISTORY_DAYS * DAY_MS); | |
| 126 | + | return { from: new Date(Math.min(from, to)), to: new Date(to) }; | |
| 127 | + | } | |
| 128 | + | ||
| 83 | 129 | // --- Rows ------------------------------------------------------------------------ | |
| 84 | 130 | ||
| 85 | 131 | type IncidentRow = { | |
| ⋯ | |||
| 340 | 386 | return row?.n ?? 0; | |
| 341 | 387 | } | |
| 342 | 388 | ||
| 343 | − | export async function incidentDetail(db: D1Database, id: string, origin: string, names: Map<string, string>): Promise<AdminIncidentDetail | null> { | |
| 389 | + | export async function incidentDetail( | |
| 390 | + | db: D1Database, | |
| 391 | + | id: string, | |
| 392 | + | origin: string, | |
| 393 | + | names: Map<string, string>, | |
| 394 | + | { limits = new Map<string, number>(), now = new Date() }: { limits?: Map<string, number>; now?: Date } = {}, | |
| 395 | + | ): Promise<AdminIncidentDetail | null> { | |
| 344 | 396 | const data = await adminIncidents(db, `id = ?1`, [id]); | |
| 345 | 397 | const row = data.list[0]; | |
| 346 | 398 | if (!row) return null; | |
| 399 | + | // Every check of its parts around it, for the latency chart. | |
| 400 | + | const keys = [...new Set(data.comps.filter((c) => c.incident_id === row.id).map((c) => c.component))]; | |
| 401 | + | const span = historySpan(row.started_at, row.resolved_at, now); | |
| 402 | + | const samples = await checkHistory(db, keys, span.from, span.to); | |
| 403 | + | const checks: CheckHistory[] = keys.map((key) => ({ | |
| 404 | + | key, | |
| 405 | + | slow_ms: limits.get(key) ?? null, | |
| 406 | + | from: span.from.toISOString(), | |
| 407 | + | to: span.to.toISOString(), | |
| 408 | + | samples: samples.filter((s) => s.component === key), | |
| 409 | + | })); | |
| 347 | 410 | const pmRow = data.pms[0] ?? null; | |
| 348 | 411 | const incident = toAdmin(row, data.comps, data.timeline, data.followups, pmRow); | |
| 349 | 412 | const timeline = data.timeline.map(toTimeline); | |
| ⋯ | |||
| 376 | 439 | postmortem, | |
| 377 | 440 | postmortem_draft: postmortemDraft(incident, timeline, followups, names), | |
| 378 | 441 | url: incidentUrl(origin, id), | |
| 442 | + | checks, | |
| 379 | 443 | }; | |
| 380 | 444 | } | |
| 381 | 445 | ||
| ⋯ | |||
| 699 | 763 | // --- Detection --------------------------------------------------------------------------- | |
| 700 | 764 | ||
| 701 | 765 | export async function loadStreaks(db: D1Database): Promise<Map<string, Streak>> { | |
| 702 | − | const list = rows<{ component: string; state: "degraded" | "down"; count: number; since: string; alerted: number }>( | |
| 703 | − | (await db.prepare(`SELECT * FROM streak`).all()) as D1Result, | |
| 766 | + | const list = rows<{ component: string; state: "degraded" | "down"; count: number; checks: number | null; recent: string | null; since: string; alerted: number }>( | |
| 767 | + | (await db.prepare(`SELECT component, state, count, checks, recent, since, alerted FROM streak`).all()) as D1Result, | |
| 704 | 768 | ); | |
| 705 | − | return new Map(list.map((s) => [s.component, { ...s, alerted: s.alerted === 1 }])); | |
| 769 | + | // Runs kept before migration 0003 have no `checks` or `recent`: upgradeStreak fills them in. | |
| 770 | + | return new Map(list.map((s) => [s.component, upgradeStreak({ ...s, alerted: s.alerted === 1 })])); | |
| 706 | 771 | } | |
| 707 | 772 | ||
| 708 | 773 | /** | |
| ⋯ | |||
| 717 | 782 | ...streaks.map((s) => | |
| 718 | 783 | db | |
| 719 | 784 | .prepare( | |
| 720 | − | `INSERT INTO streak (component, state, count, since, alerted) VALUES (?1, ?2, ?3, ?4, ?5) | |
| 721 | − | ON CONFLICT (component) DO UPDATE SET state = ?2, count = ?3, since = ?4, alerted = ?5`, | |
| 785 | + | `INSERT INTO streak (component, state, count, since, alerted, checks, recent) VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7) | |
| 786 | + | ON CONFLICT (component) DO UPDATE SET state = ?2, count = ?3, since = ?4, alerted = ?5, checks = ?6, recent = ?7`, | |
| 722 | 787 | ) | |
| 723 | − | .bind(s.component, s.state, s.count, s.since, s.alerted ? 1 : 0), | |
| 788 | + | .bind(s.component, s.state, s.count, s.since, s.alerted ? 1 : 0, s.checks, s.recent), | |
| 724 | 789 | ), | |
| 725 | 790 | ]); | |
| 726 | 791 | } | |
| ⋯ | |||
| 750 | 815 | if (!row?.value) return null; | |
| 751 | 816 | try { | |
| 752 | 817 | const w = JSON.parse(row.value) as Partial<DeployWindow>; | |
| 753 | − | return typeof w.started_at === "string" ? { id: w.id ?? null, started_at: w.started_at, finished_at: w.finished_at ?? null } : null; | |
| 818 | + | if (typeof w.started_at !== "string") return null; | |
| 819 | + | const finished_at = w.finished_at ?? null; | |
| 820 | + | return { | |
| 821 | + | id: w.id ?? null, | |
| 822 | + | started_at: w.started_at, | |
| 823 | + | finished_at, | |
| 824 | + | // Kept before deploys were counted: one, unless it finished. | |
| 825 | + | running: typeof w.running === "number" ? w.running : finished_at ? 0 : 1, | |
| 826 | + | last_started_at: typeof w.last_started_at === "string" ? w.last_started_at : w.started_at, | |
| 827 | + | }; | |
| 754 | 828 | } catch { | |
| 755 | 829 | return null; | |
| 756 | 830 | } | |
| ⋯ | |||
| 764 | 838 | } | |
| 765 | 839 | ||
| 766 | 840 | const HEALTHY = "draft_healthy:"; | |
| 841 | + | const REMINDED = "draft_reminded:"; | |
| 767 | 842 | ||
| 768 | 843 | /** | |
| 769 | 844 | * Detected drafts no one has picked up (unacknowledged, never published), | |
| 770 | − | * with their parts and since when those have been healthy. | |
| 845 | + | * with their parts, since when those have been healthy, and when the | |
| 846 | + | * alert last went out again for them. | |
| 771 | 847 | */ | |
| 772 | 848 | export async function watchedDrafts(db: D1Database): Promise<WatchedDraft[]> { | |
| 773 | − | const list = rows<{ id: string; title: string; started_at: string; healthy_since: string | null; component: string | null }>( | |
| 849 | + | const list = rows<{ | |
| 850 | + | id: string; | |
| 851 | + | title: string; | |
| 852 | + | started_at: string; | |
| 853 | + | declared_at: string; | |
| 854 | + | healthy_since: string | null; | |
| 855 | + | reminded_at: string | null; | |
| 856 | + | component: string | null; | |
| 857 | + | }>( | |
| 774 | 858 | (await db | |
| 775 | 859 | .prepare( | |
| 776 | − | `SELECT i.id, i.title, i.started_at, m.value AS healthy_since, c.component FROM incident i | |
| 860 | + | `SELECT i.id, i.title, i.started_at, i.declared_at, m.value AS healthy_since, r.value AS reminded_at, c.component FROM incident i | |
| 777 | 861 | LEFT JOIN incident_component c ON c.incident_id = i.id AND c.impact != 'operational' | |
| 778 | 862 | LEFT JOIN meta m ON m.key = '${HEALTHY}' || i.id | |
| 863 | + | LEFT JOIN meta r ON r.key = '${REMINDED}' || i.id | |
| 779 | 864 | WHERE i.source = 'detected' AND i.visibility = 'draft' AND i.acknowledged_at IS NULL AND i.resolved_at IS NULL AND i.published_at IS NULL`, | |
| 780 | 865 | ) | |
| 781 | 866 | .all()) as D1Result, | |
| 782 | 867 | ); | |
| 783 | 868 | const map = new Map<string, WatchedDraft>(); | |
| 784 | 869 | for (const r of list) { | |
| 785 | − | const d = map.get(r.id) ?? { id: r.id, title: r.title, started_at: r.started_at, healthy_since: r.healthy_since ?? null, components: [] }; | |
| 870 | + | const d = map.get(r.id) ?? { | |
| 871 | + | id: r.id, | |
| 872 | + | title: r.title, | |
| 873 | + | started_at: r.started_at, | |
| 874 | + | declared_at: r.declared_at, | |
| 875 | + | healthy_since: r.healthy_since ?? null, | |
| 876 | + | reminded_at: r.reminded_at ?? null, | |
| 877 | + | components: [], | |
| 878 | + | }; | |
| 786 | 879 | if (r.component) d.components.push(r.component); | |
| 787 | 880 | map.set(r.id, d); | |
| 788 | 881 | } | |
| ⋯ | |||
| 807 | 900 | } | |
| 808 | 901 | ||
| 809 | 902 | /** | |
| 903 | + | * Notes that the alert went out again for these drafts (`staleDrafts`), | |
| 904 | + | * with a line on each one's timeline, and forgets the drafts no longer | |
| 905 | + | * watched (`watching`: every watched draft's id). | |
| 906 | + | */ | |
| 907 | + | export async function saveReminders(db: D1Database, watching: string[], reminded: { id: string; text: string }[], now: Date): Promise<void> { | |
| 908 | + | const keys = watching.map((id) => `${REMINDED}${id}`); | |
| 909 | + | await db.batch([ | |
| 910 | + | keys.length | |
| 911 | + | ? db.prepare(`DELETE FROM meta WHERE key LIKE '${REMINDED}%' AND key NOT IN (${inList(keys)})`).bind(...keys) | |
| 912 | + | : db.prepare(`DELETE FROM meta WHERE key LIKE '${REMINDED}%'`), | |
| 913 | + | ...reminded.flatMap((r) => [ | |
| 914 | + | db | |
| 915 | + | .prepare(`INSERT INTO meta (key, value) VALUES (?1, ?2) ON CONFLICT (key) DO UPDATE SET value = excluded.value`) | |
| 916 | + | .bind(`${REMINDED}${r.id}`, now.toISOString()), | |
| 917 | + | ...timelineStatements(db, r.id, [{ kind: "note", public: false, status: null, text: r.text }], now, "status"), | |
| 918 | + | ]), | |
| 919 | + | ]); | |
| 920 | + | } | |
| 921 | + | ||
| 922 | + | /** | |
| 810 | 923 | * Dismisses a detected draft that recovered, as `status`, resolved at the | |
| 811 | 924 | * moment it recovered. Only while it is still an untouched draft: returns | |
| 812 | 925 | * false (and changes nothing) when staff got to it first. | |
| ⋯ | |||
| 822 | 935 | if ((done.meta?.changes ?? 0) === 0) return false; | |
| 823 | 936 | await db.batch([ | |
| 824 | 937 | ...timelineStatements(db, id, [{ kind: "dismissed", public: false, status: null, text }], now, "status"), | |
| 825 | − | db.prepare(`DELETE FROM meta WHERE key = ?1`).bind(`${HEALTHY}${id}`), | |
| 938 | + | db.prepare(`DELETE FROM meta WHERE key IN (?1, ?2)`).bind(`${HEALTHY}${id}`, `${REMINDED}${id}`), | |
| 826 | 939 | auditStatement(db, now.toISOString(), "status", "incident_dismissed", id, `Dismissed automatically: ${text}`), | |
| 827 | 940 | ]); | |
| 828 | 941 | return true; | |
| 39 | 39 | // npx wrangler secret put STATUS_SECRET | |
| 40 | 40 | // Without either, the page offers the feeds only. | |
| 41 | 41 | // | |
| 42 | − | // The deploy tool says when a deploy starts and finishes (POST /deploys, | |
| 43 | − | // bearer STATUS_DEPLOY_TOKEN), so restarts do not draft incidents. | |
| 44 | − | // Optional; without it, deploys are not announced: | |
| 42 | + | // The deploy tool (scripts/deploy.mjs) says when a deploy starts and | |
| 43 | + | // finishes (POST /deploys, bearer STATUS_DEPLOY_TOKEN), so restarts do | |
| 44 | + | // not draft incidents. The same value is the STATUS_DEPLOY_TOKEN Actions | |
| 45 | + | // secret on flagon-io/g1t. Optional; without it, deploys are not announced: | |
| 45 | 46 | // npx wrangler secret put STATUS_DEPLOY_TOKEN | |
| 46 | 47 | "send_email": [{ "name": "EMAIL", "remote": true }], | |
| 47 | 48 | "vars": { | |
| ⋯ | |||
| 61 | 62 | "STATUS_URL": "https://status.g1t.sh", | |
| 62 | 63 | // sudo, for the link in the staff alert. | |
| 63 | 64 | "SUDO_URL": "https://sudo.g1t.sh", | |
| 64 | − | // Who hears when a part fails three checks in a row and a draft | |
| 65 | − | // incident is made. Empty sends none. | |
| 65 | + | // Who hears when a part fails four of five checks and a draft | |
| 66 | + | // incident is made, and again when it waits unacknowledged (after | |
| 67 | + | // 45 minutes, then every 6 hours). Empty sends none. | |
| 66 | 68 | "STATUS_ALERT_EMAIL": "hey@flagon.io", | |
| 67 | 69 | "STATUS_FROM": "g1t status <noreply@g1t.sh>", | |
| 68 | 70 | "OG_IMAGE": "https://og.g1t.sh/image?path=%2Fstatus&v=2" | |
| 1 | + | /** | |
| 2 | + | * An incident's parts, check by check: a latency chart per part, drawn as | |
| 3 | + | * SVG on the server, with the slow line, slow checks dotted and failures | |
| 4 | + | * marked along the top, and the latest checks as a table under it. No | |
| 5 | + | * script and no inline style (sudo ships no JavaScript); the table is the | |
| 6 | + | * way to read exact figures. | |
| 7 | + | */ | |
| 8 | + | import type { CheckHistory } from "@g1t/contracts"; | |
| 9 | + | ||
| 10 | + | import { When } from "~/components/ui"; | |
| 11 | + | import { latencyPlot, latencySummary, msWords, summaryWords } from "~/lib/latency"; | |
| 12 | + | ||
| 13 | + | /** How many of the latest checks the table lists. */ | |
| 14 | + | const LISTED = 30; | |
| 15 | + | ||
| 16 | + | const OUTCOME = { up: "OK", degraded: "Slow", down: "Not answering" } as const; | |
| 17 | + | ||
| 18 | + | function Chart({ history, name }: { history: CheckHistory; name: string }) { | |
| 19 | + | const p = latencyPlot(history); | |
| 20 | + | return ( | |
| 21 | + | <svg viewBox={`0 0 ${p.width} ${p.height}`} className="block h-auto w-full" role="img" aria-label={`${name}: how long each check took, ${summaryWords(latencySummary(history.samples))}`}> | |
| 22 | + | {p.ticks.map((t) => ( | |
| 23 | + | <g key={t.label}> | |
| 24 | + | <line x1={p.plot.x} x2={p.plot.x + p.plot.width} y1={t.y} y2={t.y} stroke="var(--g1t-line)" strokeWidth="1" strokeDasharray={t.label === "0" ? undefined : "2 4"} /> | |
| 25 | + | <text x={p.plot.x - 6} y={t.y + 3.5} textAnchor="end" fontSize="10" className="fill-faint tabular"> | |
| 26 | + | {t.label} | |
| 27 | + | </text> | |
| 28 | + | </g> | |
| 29 | + | ))} | |
| 30 | + | {p.slowY != null && ( | |
| 31 | + | <g> | |
| 32 | + | <line x1={p.plot.x} x2={p.plot.x + p.plot.width} y1={p.slowY} y2={p.slowY} stroke="var(--g1t-warn)" strokeWidth="1" strokeDasharray="4 3" /> | |
| 33 | + | <text x={p.plot.x + p.plot.width} y={p.slowY - 3} textAnchor="end" fontSize="10" className="fill-warn"> | |
| 34 | + | slow over {msWords(history.slow_ms!)} | |
| 35 | + | </text> | |
| 36 | + | </g> | |
| 37 | + | )} | |
| 38 | + | {p.down.map((d, i) => ( | |
| 39 | + | <rect key={`d${i}`} x={d.x - 1} y={p.plot.y} width="2" height={p.plot.height} className="fill-danger/35" /> | |
| 40 | + | ))} | |
| 41 | + | <path d={p.line} fill="none" stroke="var(--g1t-accent)" strokeWidth="1.5" strokeLinejoin="round" strokeLinecap="round" /> | |
| 42 | + | {p.slow.map((s, i) => ( | |
| 43 | + | <circle key={`s${i}`} cx={s.x} cy={s.y} r="2.5" className="fill-warn" /> | |
| 44 | + | ))} | |
| 45 | + | <text x={p.plot.x} y={p.height - 4} fontSize="10" className="fill-faint"> | |
| 46 | + | {new Date(history.from).toISOString().slice(11, 16)} UTC | |
| 47 | + | </text> | |
| 48 | + | <text x={p.plot.x + p.plot.width} y={p.height - 4} textAnchor="end" fontSize="10" className="fill-faint"> | |
| 49 | + | {new Date(history.to).toISOString().slice(11, 16)} UTC | |
| 50 | + | </text> | |
| 51 | + | </svg> | |
| 52 | + | ); | |
| 53 | + | } | |
| 54 | + | ||
| 55 | + | function Part({ history, name }: { history: CheckHistory; name: string }) { | |
| 56 | + | const summary = latencySummary(history.samples); | |
| 57 | + | const latest = history.samples.slice(-LISTED).reverse(); | |
| 58 | + | return ( | |
| 59 | + | <div className="space-y-2"> | |
| 60 | + | <div className="flex flex-wrap items-baseline justify-between gap-x-3 gap-y-0.5"> | |
| 61 | + | <h3 className="text-sm font-medium">{name}</h3> | |
| 62 | + | {summary.checks > 0 && <p className="text-xs text-faint">{summaryWords(summary)}</p>} | |
| 63 | + | </div> | |
| 64 | + | {history.samples.length === 0 ? ( | |
| 65 | + | <p className="text-sm text-muted">No checks kept for this span: checks are kept for 7 days.</p> | |
| 66 | + | ) : ( | |
| 67 | + | <> | |
| 68 | + | <Chart history={history} name={name} /> | |
| 69 | + | <details className="group"> | |
| 70 | + | <summary className="cursor-pointer text-xs text-muted select-none hover:text-fg"> | |
| 71 | + | The latest {Math.min(LISTED, history.samples.length)} checks | |
| 72 | + | </summary> | |
| 73 | + | <div className="mt-2 overflow-x-auto"> | |
| 74 | + | <table className="w-full text-left text-xs tabular"> | |
| 75 | + | <thead className="text-faint"> | |
| 76 | + | <tr> | |
| 77 | + | <th className="py-1 pr-3 font-normal">At</th> | |
| 78 | + | <th className="py-1 pr-3 font-normal">Took</th> | |
| 79 | + | <th className="py-1 pr-3 font-normal">Result</th> | |
| 80 | + | <th className="py-1 pr-3 font-normal">From</th> | |
| 81 | + | <th className="py-1 font-normal">First try</th> | |
| 82 | + | </tr> | |
| 83 | + | </thead> | |
| 84 | + | <tbody> | |
| 85 | + | {latest.map((s) => ( | |
| 86 | + | <tr key={s.at} className="border-t border-line"> | |
| 87 | + | <td className="py-1 pr-3 whitespace-nowrap"> | |
| 88 | + | <When at={s.at} time /> | |
| 89 | + | </td> | |
| 90 | + | <td className="py-1 pr-3">{s.ms != null ? msWords(s.ms) : "—"}</td> | |
| 91 | + | <td className={`py-1 pr-3 ${s.outcome === "down" ? "text-danger" : s.outcome === "degraded" ? "text-warn" : "text-muted"}`}>{OUTCOME[s.outcome]}</td> | |
| 92 | + | <td className="py-1 pr-3 font-mono">{s.colo ?? "—"}</td> | |
| 93 | + | <td className="py-1 text-faint">{s.first_ms != null ? `${msWords(s.first_ms)}, asked again` : ""}</td> | |
| 94 | + | </tr> | |
| 95 | + | ))} | |
| 96 | + | </tbody> | |
| 97 | + | </table> | |
| 98 | + | </div> | |
| 99 | + | </details> | |
| 100 | + | </> | |
| 101 | + | )} | |
| 102 | + | </div> | |
| 103 | + | ); | |
| 104 | + | } | |
| 105 | + | ||
| 106 | + | /** Every part's checks around an incident. */ | |
| 107 | + | export function IncidentChecks({ checks, names }: { checks: CheckHistory[]; names: Map<string, string> }) { | |
| 108 | + | return ( | |
| 109 | + | <div className="space-y-5"> | |
| 110 | + | {checks.map((h) => ( | |
| 111 | + | <Part key={h.key} history={h} name={names.get(h.key) ?? h.key} /> | |
| 112 | + | ))} | |
| 113 | + | </div> | |
| 114 | + | ); | |
| 115 | + | } |
| 1 | + | import assert from "node:assert/strict"; | |
| 2 | + | import { test } from "node:test"; | |
| 3 | + | ||
| 4 | + | import type { CheckSample } from "@g1t/contracts"; | |
| 5 | + | ||
| 6 | + | import { latencyPlot, latencySummary, msWords, summaryWords } from "./latency.ts"; | |
| 7 | + | ||
| 8 | + | const at = (minute: number) => new Date(Date.UTC(2026, 9, 8, 7, minute)).toISOString(); | |
| 9 | + | const sample = (minute: number, ms: number | null, outcome: CheckSample["outcome"], extra: Partial<CheckSample> = {}): CheckSample => ({ | |
| 10 | + | component: "speed", | |
| 11 | + | at: at(minute), | |
| 12 | + | ms, | |
| 13 | + | outcome, | |
| 14 | + | colo: "IAD", | |
| 15 | + | first_ms: null, | |
| 16 | + | ...extra, | |
| 17 | + | }); | |
| 18 | + | ||
| 19 | + | test("the chart: answered checks as a line, broken by failures and gaps; slow ones dotted; the slow line drawn", () => { | |
| 20 | + | const samples = [ | |
| 21 | + | sample(0, 300, "up"), | |
| 22 | + | sample(1, 1200, "degraded", { first_ms: 2400 }), | |
| 23 | + | sample(2, 5000, "down"), | |
| 24 | + | sample(3, 400, "up"), | |
| 25 | + | // Five minutes with no check: a gap. | |
| 26 | + | sample(9, 500, "up"), | |
| 27 | + | sample(10, 450, "up"), | |
| 28 | + | ]; | |
| 29 | + | const p = latencyPlot({ key: "speed", slow_ms: 800, from: at(0), to: at(10), samples }, { width: 640, height: 120 }); | |
| 30 | + | assert.equal(p.max, 1500, "half again over the slow line, or the slowest answer, rounded up; a failure's time is not a speed"); | |
| 31 | + | // Three segments: 0-1, 3, and 9-10. | |
| 32 | + | assert.equal(p.line.match(/M/g)!.length, 3); | |
| 33 | + | assert.equal(p.line.match(/L/g)!.length, 2); | |
| 34 | + | assert.equal(p.slow.length, 1); | |
| 35 | + | assert.equal(p.down.length, 1); | |
| 36 | + | assert.ok(p.slowY! > p.plot.y && p.slowY! < p.plot.y + p.plot.height); | |
| 37 | + | // The first check is at the left edge, the last at the right. | |
| 38 | + | assert.ok(p.line.startsWith(`M${p.plot.x} `)); | |
| 39 | + | assert.ok(p.line.includes(`L${p.plot.x + p.plot.width} `)); | |
| 40 | + | assert.deepEqual(p.ticks.map((t) => t.label), ["0", "750 ms", "1.5 s"]); | |
| 41 | + | }); | |
| 42 | + | ||
| 43 | + | test("the chart's scale leaves room over the slow line when every check was fast", () => { | |
| 44 | + | const p = latencyPlot({ key: "api", slow_ms: 1500, from: at(0), to: at(1), samples: [sample(0, 90, "up")] }); | |
| 45 | + | assert.equal(p.max, 2500); | |
| 46 | + | const none = latencyPlot({ key: "api", slow_ms: null, from: at(0), to: at(1), samples: [] }); | |
| 47 | + | assert.equal(none.line, ""); | |
| 48 | + | assert.equal(none.slowY, null); | |
| 49 | + | }); | |
| 50 | + | ||
| 51 | + | test("the summary over the chart", () => { | |
| 52 | + | const s = latencySummary([ | |
| 53 | + | sample(0, 300, "up"), | |
| 54 | + | sample(1, 1200, "degraded", { first_ms: 2400 }), | |
| 55 | + | sample(2, 5000, "down", { colo: "EWR" }), | |
| 56 | + | sample(3, 400, "up"), | |
| 57 | + | ]); | |
| 58 | + | assert.deepEqual(s, { checks: 4, slow: 1, down: 1, median_ms: 400, slowest_ms: 1200, asked_again: 1, colos: ["IAD", "EWR"] }); | |
| 59 | + | assert.equal(summaryWords(s), "4 checks · 1 slow · 1 not answering · median 400 ms · slowest 1.2 s · 1 asked again · from IAD, EWR"); | |
| 60 | + | assert.equal(msWords(800), "800 ms"); | |
| 61 | + | assert.equal(msWords(1500), "1.5 s"); | |
| 62 | + | }); |
| 1 | + | /** | |
| 2 | + | * An incident's parts, check by check, as the status worker keeps them | |
| 3 | + | * (7 days, `AdminIncidentDetail.checks`): the layout of the latency chart | |
| 4 | + | * on the incident page, and the words over it. Drawn on the server as SVG; | |
| 5 | + | * nothing here runs in the browser. | |
| 6 | + | */ | |
| 7 | + | import type { CheckHistory, CheckSample } from "@g1t/contracts"; | |
| 8 | + | ||
| 9 | + | import { median } from "./incidents.ts"; | |
| 10 | + | ||
| 11 | + | /** Checks further apart than this are drawn as a gap, not a line across it. */ | |
| 12 | + | const GAP_MS = 3 * 60_000; | |
| 13 | + | ||
| 14 | + | export type LatencyPlot = { | |
| 15 | + | width: number; | |
| 16 | + | height: number; | |
| 17 | + | plot: { x: number; y: number; width: number; height: number }; | |
| 18 | + | /** The top of the scale, in milliseconds. */ | |
| 19 | + | max: number; | |
| 20 | + | /** The answered checks as one path; a check that failed, or a gap, breaks it. */ | |
| 21 | + | line: string; | |
| 22 | + | /** Where the slow line is; null when the part's limit is not known. */ | |
| 23 | + | slowY: number | null; | |
| 24 | + | /** Slow checks, as dots on the line. */ | |
| 25 | + | slow: { x: number; y: number }[]; | |
| 26 | + | /** Checks that failed, as marks along the top. */ | |
| 27 | + | down: { x: number }[]; | |
| 28 | + | /** Gridlines, with their label. */ | |
| 29 | + | ticks: { y: number; label: string }[]; | |
| 30 | + | }; | |
| 31 | + | ||
| 32 | + | /** "800 ms", "1.5 s". */ | |
| 33 | + | export function msWords(ms: number): string { | |
| 34 | + | return ms >= 1000 ? `${Number((ms / 1000).toFixed(1))} s` : `${Math.round(ms)} ms`; | |
| 35 | + | } | |
| 36 | + | ||
| 37 | + | /** A round top for the scale: the next 250 ms under a second, then the next half second. */ | |
| 38 | + | function niceMax(ms: number): number { | |
| 39 | + | const step = ms <= 1000 ? 250 : 500; | |
| 40 | + | return Math.max(step, Math.ceil(ms / step) * step); | |
| 41 | + | } | |
| 42 | + | ||
| 43 | + | export function latencyPlot(history: CheckHistory, { width = 640, height = 120 } = {}): LatencyPlot { | |
| 44 | + | const plot = { x: 44, y: 8, width: width - 52, height: height - 26 }; | |
| 45 | + | const answered = history.samples.filter((s) => s.outcome !== "down" && s.ms != null); | |
| 46 | + | const top = Math.max(history.slow_ms != null ? history.slow_ms * 1.5 : 0, ...answered.map((s) => s.ms!), 1); | |
| 47 | + | const max = niceMax(top); | |
| 48 | + | const from = Date.parse(history.from); | |
| 49 | + | const span = Math.max(1, Date.parse(history.to) - from); | |
| 50 | + | const xOf = (at: string) => plot.x + (Math.min(Math.max(Date.parse(at) - from, 0), span) / span) * plot.width; | |
| 51 | + | const yOf = (ms: number) => plot.y + plot.height - (Math.min(ms, max) / max) * plot.height; | |
| 52 | + | const round = (n: number) => Math.round(n * 10) / 10; | |
| 53 | + | ||
| 54 | + | let line = ""; | |
| 55 | + | let last: CheckSample | null = null; | |
| 56 | + | for (const s of history.samples) { | |
| 57 | + | if (s.outcome === "down" || s.ms == null) { | |
| 58 | + | last = null; | |
| 59 | + | continue; | |
| 60 | + | } | |
| 61 | + | const joined = last != null && Date.parse(s.at) - Date.parse(last.at) <= GAP_MS; | |
| 62 | + | line += `${joined ? "L" : "M"}${round(xOf(s.at))} ${round(yOf(s.ms))}`; | |
| 63 | + | last = s; | |
| 64 | + | } | |
| 65 | + | const ticks = [0, max / 2, max].map((v) => ({ y: round(yOf(v)), label: v === 0 ? "0" : msWords(v) })); | |
| 66 | + | return { | |
| 67 | + | width, | |
| 68 | + | height, | |
| 69 | + | plot, | |
| 70 | + | max, | |
| 71 | + | line, | |
| 72 | + | slowY: history.slow_ms != null ? round(yOf(history.slow_ms)) : null, | |
| 73 | + | slow: history.samples.filter((s) => s.outcome === "degraded" && s.ms != null).map((s) => ({ x: round(xOf(s.at)), y: round(yOf(s.ms!)) })), | |
| 74 | + | down: history.samples.filter((s) => s.outcome === "down").map((s) => ({ x: round(xOf(s.at)) })), | |
| 75 | + | ticks, | |
| 76 | + | }; | |
| 77 | + | } | |
| 78 | + | ||
| 79 | + | export type LatencySummary = { | |
| 80 | + | checks: number; | |
| 81 | + | slow: number; | |
| 82 | + | down: number; | |
| 83 | + | /** Of the checks that answered. */ | |
| 84 | + | median_ms: number | null; | |
| 85 | + | slowest_ms: number | null; | |
| 86 | + | /** Slow at first and asked again at once. */ | |
| 87 | + | asked_again: number; | |
| 88 | + | /** Where the checks ran from, most first. */ | |
| 89 | + | colos: string[]; | |
| 90 | + | }; | |
| 91 | + | ||
| 92 | + | export function latencySummary(samples: CheckSample[]): LatencySummary { | |
| 93 | + | const answered = samples.filter((s) => s.outcome !== "down" && s.ms != null).map((s) => s.ms!); | |
| 94 | + | const colos = new Map<string, number>(); | |
| 95 | + | for (const s of samples) if (s.colo) colos.set(s.colo, (colos.get(s.colo) ?? 0) + 1); | |
| 96 | + | return { | |
| 97 | + | checks: samples.length, | |
| 98 | + | slow: samples.filter((s) => s.outcome === "degraded").length, | |
| 99 | + | down: samples.filter((s) => s.outcome === "down").length, | |
| 100 | + | median_ms: median(answered), | |
| 101 | + | slowest_ms: answered.length ? Math.max(...answered) : null, | |
| 102 | + | asked_again: samples.filter((s) => s.first_ms != null).length, | |
| 103 | + | colos: [...colos].sort((a, b) => b[1] - a[1]).map(([c]) => c), | |
| 104 | + | }; | |
| 105 | + | } | |
| 106 | + | ||
| 107 | + | /** The summary in a line: "62 checks · 14 slow · 2 not answering · median 640 ms · slowest 2.4 s · from IAD". */ | |
| 108 | + | export function summaryWords(s: LatencySummary): string { | |
| 109 | + | const parts = [`${s.checks} check${s.checks === 1 ? "" : "s"}`, `${s.slow} slow`, `${s.down} not answering`]; | |
| 110 | + | if (s.median_ms != null) parts.push(`median ${msWords(s.median_ms)}`); | |
| 111 | + | if (s.slowest_ms != null) parts.push(`slowest ${msWords(s.slowest_ms)}`); | |
| 112 | + | if (s.asked_again) parts.push(`${s.asked_again} asked again`); | |
| 113 | + | if (s.colos.length) parts.push(`from ${s.colos.join(", ")}`); | |
| 114 | + | return parts.join(" · "); | |
| 115 | + | } |
| 5 | 5 | ||
| 6 | 6 | import type { Route } from "./+types/incident"; | |
| 7 | 7 | import { BackLink, ImpactBadge, ImpactPicker, PhaseBadge, SeverityBadge, Timer } from "~/components/incidents"; | |
| 8 | + | import { IncidentChecks } from "~/components/latency"; | |
| 8 | 9 | import { Badge, Button, Field, Input, Notice, Section, Select, Textarea, When } from "~/components/ui"; | |
| 9 | 10 | import { text } from "~/lib/forms"; | |
| 10 | 11 | import { | |
| ⋯ | |||
| 309 | 310 | <h2 className="font-semibold">This is a draft</h2> | |
| 310 | 311 | <p className="mt-1 text-sm text-muted"> | |
| 311 | 312 | {incident.source === "detected" | |
| 312 | − | ? "The checks failed or were slow three times in a row and made this. Nobody outside sees it until you publish it. If it was a blip, dismiss it; if no one picks it up and its parts stay healthy for 10 minutes, it is dismissed on its own." | |
| 313 | + | ? "The checks failed or were slow on four of five checks in a row and made this. Nobody outside sees it until you publish it. If it was a blip, dismiss it; if no one picks it up and its parts stay healthy for 10 minutes, it is dismissed on its own. Left unacknowledged, the alert goes out again after 45 minutes, then every 6 hours." | |
| 313 | 314 | : "Nobody outside sees it until you publish it."} | |
| 314 | 315 | </p> | |
| 315 | 316 | <div className="mt-4 grid gap-4 lg:grid-cols-[minmax(0,1fr)_18rem]"> | |
| ⋯ | |||
| 349 | 350 | <div className="mt-6 grid gap-6 lg:grid-cols-[minmax(0,1fr)_20rem]"> | |
| 350 | 351 | <div className="min-w-0 space-y-6"> | |
| 351 | 352 | {incident.visibility !== "dismissed" && <UpdateForm incident={incident} components={components} error={errorFor("update")} />} | |
| 353 | + | {(incident.checks?.length ?? 0) > 0 && ( | |
| 354 | + | <Section | |
| 355 | + | id="checks" | |
| 356 | + | title="Checks" | |
| 357 | + | description="How long each check of its parts took, from 30 minutes before it began to 30 minutes after it ended (at most a day), with the data centre each ran from. Kept for 7 days." | |
| 358 | + | > | |
| 359 | + | <IncidentChecks checks={incident.checks} names={names} /> | |
| 360 | + | </Section> | |
| 361 | + | )} | |
| 352 | 362 | <Section title="Timeline" description="Newest first. Public updates are what the status page shows; everything else is for staff."> | |
| 353 | 363 | <ol className="space-y-2"> | |
| 354 | 364 | {timeline.map((entry) => ( | |
| 258 | 258 | : filters.tab === "open" | |
| 259 | 259 | ? "The status page shows only its own checks." | |
| 260 | 260 | : filters.tab === "drafts" | |
| 261 | − | ? "When a part fails or is slow on three checks in a row, a draft appears here and the alert address gets an email. If no one picks it up and the part stays healthy for 10 minutes, it is dismissed on its own. Restarts during a deploy are not drafted unless they outlast it." | |
| 261 | + | ? "When a part fails or is slow on four of five checks in a row, a draft appears here and the alert address gets an email, again after 45 minutes if no one picks it up, then every 6 hours. If no one picks it up and the part stays healthy for 10 minutes, it is dismissed on its own. Restarts during a deploy are not drafted unless they outlast it." | |
| 262 | 262 | : null} | |
| 263 | 263 | </EmptyState> | |
| 264 | 264 | ) : ( |
| 173 | 173 | #### Telling the status page about a deploy | |
| 174 | 174 | ||
| 175 | 175 | Restarts during a deploy can make a part slow for a minute, which the | |
| 176 | − | status page's checks would otherwise draft as an incident. Before the | |
| 177 | − | first stage and after the last, a deploy can say so with | |
| 178 | − | `scripts/deploy/status-window.mjs` (`announceDeploy("started" | "finished", | |
| 179 | − | { id })`, or `node scripts/deploy/status-window.mjs started|finished [id]`). | |
| 180 | − | It posts to `POST https://status.g1t.sh/deploys` with | |
| 176 | + | status page's checks would otherwise draft as an incident. So | |
| 177 | + | `scripts/deploy.mjs deploy` says when it starts its stages and when they | |
| 178 | + | end (`withDeployWindow` in `scripts/deploy/status-window.mjs`; never in a | |
| 179 | + | dry run, and only once there is something to ship), by hand and in g1t | |
| 180 | + | Actions alike. It posts to `POST https://status.g1t.sh/deploys` with | |
| 181 | 181 | `Authorization: Bearer $STATUS_DEPLOY_TOKEN`, the same value as the status | |
| 182 | − | Worker's `STATUS_DEPLOY_TOKEN` secret. During the deploy and for 3 minutes | |
| 183 | − | after it, detection keeps counting failed and slow checks but makes no new | |
| 184 | − | draft; trouble that outlasts that is drafted with its true start. A | |
| 185 | − | start with no finish stops counting after 30 minutes. Without the token | |
| 186 | − | the helper does nothing, and it never fails a deploy. | |
| 182 | + | Worker's `STATUS_DEPLOY_TOKEN` secret, and `{"phase": "started" | | |
| 183 | + | "finished", "id": "<commit>"}`. During the deploy and for 3 minutes after | |
| 184 | + | it, detection keeps counting failed and slow checks but makes no new | |
| 185 | + | draft; trouble that outlasts that is drafted with its true start. Deploys | |
| 186 | + | that overlap (the jobs of one stage run at once, each announcing itself) | |
| 187 | + | are one window: the status Worker counts the starts, and the window closes | |
| 188 | + | when the last one finishes. A start with no finish stops counting 30 | |
| 189 | + | minutes after the latest start. Without the token nothing is sent, and an | |
| 190 | + | announcement never fails a deploy: a refusal or network error is one | |
| 191 | + | warning line. By hand: `node scripts/deploy/status-window.mjs | |
| 192 | + | started|finished [id]`. | |
| 193 | + | ||
| 194 | + | To turn it on (once; until then deploys are not announced): | |
| 187 | 195 | ||
| 196 | + | 1. Make a token and set it as the status Worker's secret: | |
| 197 | + | `npx wrangler secret put STATUS_DEPLOY_TOKEN` in `apps/status` (as of | |
| 198 | + | 2026-10-08 the Worker has only `STATUS_SECRET`). Without it, | |
| 199 | + | `POST /deploys` answers 404. | |
| 200 | + | 2. Set the same value as the **`STATUS_DEPLOY_TOKEN`** Actions secret on | |
| 201 | + | flagon-io/g1t (Settings, Secrets and variables, or | |
| 202 | + | `PUT /repos/flagon-io/g1t/actions/secrets/STATUS_DEPLOY_TOKEN`); | |
| 203 | + | `.g1t/workflows/deploy.yml` passes it to every deploy job. | |
| 204 | + | 3. Add `status.g1t.sh | deploy.yml | production` to the project's | |
| 205 | + | **Workflow-only domains** (see Network below), or the job's request is | |
| 206 | + | refused by the guardrails (the deploy still goes on, with a warning). | |
| 207 | + | 4. For deploys by hand, set `STATUS_DEPLOY_TOKEN` in your shell's | |
| 208 | + | environment (the tool does not read `.env`). | |
| 209 | + | ||
| 188 | 210 | On a laptop the tool uses your `wrangler login` (or `CLOUDFLARE_DEPLOY_TOKEN` | |
| 189 | 211 | if set), as `scripts/deploy.sh` always did: a `CLOUDFLARE_API_TOKEN` or | |
| 190 | 212 | global API key in your shell, or in the repository's `.env`, is ignored. | |
| ⋯ | |||
| 478 | 500 | ```text | |
| 479 | 501 | api.cloudflare.com | deploy.yml | production | |
| 480 | 502 | registry.cloudflare.com | deploy.yml, runner-base.yml | production | |
| 503 | + | status.g1t.sh | deploy.yml | production | |
| 481 | 504 | ``` | |
| 482 | 505 | ||
| 483 | 506 | `api.cloudflare.com` is Wrangler's API; `registry.cloudflare.com` is where | |
| 484 | 507 | the deploy asks whether the runner's image is already built, and where the | |
| 485 | 508 | `runner-image` job pulls the base from and pushes the runner's image to | |
| 486 | − | (as `runner-base.yml` pushes the base). The job's Docker Engine shares the | |
| 509 | + | (as `runner-base.yml` pushes the base); `status.g1t.sh` hears the deploy | |
| 510 | + | start and finish (see "Telling the status page about a deploy"). The job's Docker Engine shares the | |
| 487 | 511 | job's network, so these lines are what let it reach the registry. If a pull | |
| 488 | 512 | is refused with `g1t guardrails: <host> is not on this project's allowed | |
| 489 | 513 | domains`, the registry sent the layers from another host: add that host on | |
| 56 | 56 | ||
| 57 | 57 | ## Detected drafts | |
| 58 | 58 | ||
| 59 | − | When a part fails or is slow three checks in a row (three minutes), the | |
| 60 | − | status worker makes a **draft** incident and emails `STATUS_ALERT_EMAIL` | |
| 61 | − | (hey@flagon.io) with a link. A draft is not on the status page; the | |
| 62 | − | part's own state already is, from the checks. | |
| 59 | + | When a part fails or is slow on four of its last five checks (a check a | |
| 60 | + | minute), the status worker makes a **draft** incident and emails | |
| 61 | + | `STATUS_ALERT_EMAIL` (hey@flagon.io) with a link. A draft is not on the | |
| 62 | + | status page; the part's own state already is, from the checks. | |
| 63 | + | ||
| 64 | + | How the checks decide (`apps/status/src/detect.ts`, `probe.ts`): | |
| 65 | + | ||
| 66 | + | - **A slow answer is asked again at once.** It counts as slow only if the | |
| 67 | + | second answer is slow too, so one cold start or cache refill is not a | |
| 68 | + | slow check. A check that fails (an error or a timeout) is not asked | |
| 69 | + | again; four of five decides. | |
| 70 | + | - **Four of five, not three in a row.** A good check in between does not | |
| 71 | + | hide trouble that keeps coming; three good checks in a row end a run of | |
| 72 | + | trouble, however long it lasted, and the next trouble starts a new one | |
| 73 | + | with its own start. A draft's lines say "on 4 checks in a row" or "on 4 | |
| 74 | + | of 5 checks". | |
| 75 | + | - **Page loads are timed to the first byte.** The site's pages are loaded | |
| 76 | + | with a browser's user agent (ending `g1t-status/1.0 (+status.g1t.sh)`), | |
| 77 | + | because the site renders the whole page first for a crawler. See | |
| 78 | + | `docs/PERFORMANCE.md`. | |
| 79 | + | - **Every check is kept for 7 days**: how long it took, what it meant, and | |
| 80 | + | the Cloudflare data centre it ran from (from the answer's `cf-ray`). The | |
| 81 | + | incident page shows a **Checks** chart per part, from 30 minutes before | |
| 82 | + | the impact began to 30 minutes after it ended (at most a day), with the | |
| 83 | + | slow line, slow checks dotted and failures marked, and the latest 30 | |
| 84 | + | checks as a table. | |
| 85 | + | - **A draft nobody acknowledges is raised again**: the alert goes out once | |
| 86 | + | more after 45 minutes, then every 6 hours while it waits, with a note on | |
| 87 | + | its timeline each time. Publishing it, posting a note or dismissing it | |
| 88 | + | acknowledges it and stops the reminders. | |
| 89 | + | - **Deploys are announced.** `scripts/deploy.mjs` tells the status worker | |
| 90 | + | when a deploy starts and finishes (`docs/DEPLOYING.md`); during one, and | |
| 91 | + | for 3 minutes after, trouble is counted but not drafted unless it | |
| 92 | + | outlasts the deploy. | |
| 63 | 93 | ||
| 64 | 94 | Open it from the **Drafts** tab (the sidebar's Incidents count includes | |
| 65 | 95 | drafts) and either: | |
| ⋯ | |||
| 71 | 101 | ||
| 72 | 102 | While an incident is open on a part, more failures on it add a line to | |
| 73 | 103 | that incident's timeline instead of a new draft, and the part answering | |
| 74 | − | again adds a "answering again" line. | |
| 104 | + | again (three good checks in a row) adds an "answering again" line. | |
| 75 | 105 | ||
| 76 | 106 | ## Running it | |
| 77 | 107 | ||
| 324 | 324 | | Streamed panels | within 1 s | | |
| 325 | 325 | ||
| 326 | 326 | The status page's **Page speed** part checks a public project page and | |
| 327 | − | Explore every minute and shows them as degraded over 800 ms | |
| 328 | − | (`apps/status/src/components.ts`, `SPEED_BUDGET_MS`). | |
| 327 | + | Explore every minute, timed to the first byte (the answer's headers), and | |
| 328 | + | shows them as degraded over 800 ms (`apps/status/src/components.ts`, | |
| 329 | + | `SPEED_BUDGET_MS`). It asks as a browser does: a crawler's user agent makes | |
| 330 | + | the site render the whole page before the first byte (`isbot` in | |
| 331 | + | `apps/web/app/entry.server.tsx`), so the check sends a browser's user | |
| 332 | + | agent ending in `g1t-status/1.0 (+status.g1t.sh)`, which isbot reads as a | |
| 333 | + | browser (`apps/status/src/probe.ts`, `BROWSER_USER_AGENT`; the sign-in page | |
| 334 | + | of **Website and sign-in** is loaded the same way). A slow answer is asked | |
| 335 | + | again at once and counts only if the second is slow too, at the faster of | |
| 336 | + | the two times; every check is kept for 7 days with the data centre it ran | |
| 337 | + | from, and sudo's incident page charts them. | |
| 329 | 338 | ||
| 330 | 339 | ## Measuring | |
| 331 | 340 |
| 38 | 38 | "dependencies": { | |
| 39 | 39 | "@g1t/contracts": "*", | |
| 40 | 40 | "@g1t/theme": "*" | |
| 41 | + | }, | |
| 42 | + | "devDependencies": { | |
| 43 | + | "isbot": "^5.1.36" | |
| 41 | 44 | } | |
| 42 | 45 | }, | |
| 43 | 46 | "apps/sudo": { |
| 224 | 224 | postmortem_draft: PostmortemFields; | |
| 225 | 225 | /** Its page on the status site. */ | |
| 226 | 226 | url: string; | |
| 227 | + | /** | |
| 228 | + | * Every check of each of its parts around it, for the latency chart: | |
| 229 | + | * from 30 minutes before it began to 30 minutes after it ended (or now), | |
| 230 | + | * at most a day of it. Checks are kept for 7 days, so an older incident | |
| 231 | + | * has none. | |
| 232 | + | */ | |
| 233 | + | checks: CheckHistory[]; | |
| 234 | + | }; | |
| 235 | + | ||
| 236 | + | /** One check of one part, as the status worker keeps it (7 days). */ | |
| 237 | + | export type CheckSample = { | |
| 238 | + | component: string; | |
| 239 | + | at: string; | |
| 240 | + | /** How long it took; null when it took no time to speak of (a part with no check). */ | |
| 241 | + | ms: number | null; | |
| 242 | + | outcome: "up" | "degraded" | "down"; | |
| 243 | + | /** The Cloudflare data centre the check ran from, from the answer's cf-ray; null when unknown. */ | |
| 244 | + | colo: string | null; | |
| 245 | + | /** When the first try was slow and it was asked again at once: the first try's time. */ | |
| 246 | + | first_ms: number | null; | |
| 247 | + | }; | |
| 248 | + | ||
| 249 | + | /** One part's checks over a span, and the time over which an answer counts as slow. */ | |
| 250 | + | export type CheckHistory = { | |
| 251 | + | key: string; | |
| 252 | + | /** Slower than this counts as degraded; null when not known. */ | |
| 253 | + | slow_ms: number | null; | |
| 254 | + | from: string; | |
| 255 | + | to: string; | |
| 256 | + | /** Oldest first. */ | |
| 257 | + | samples: CheckSample[]; | |
| 227 | 258 | }; | |
| 228 | 259 | ||
| 229 | 260 | export type AdminMaintenance = StatusMaintenance & { created_at: string; created_by: string }; |
| 61 | 61 | import { decide, git, planJson, pool, table } from "./deploy/plan.mjs"; | |
| 62 | 62 | import { reportDeployment } from "./deploy/report.mjs"; | |
| 63 | 63 | import { ROOT, byStage, codeStages, findWranglerConfigs, npmCiArgs, npmWorkspace, pick, problems, resolvedStack } from "./deploy/stack.mjs"; | |
| 64 | + | import { withDeployWindow } from "./deploy/status-window.mjs"; | |
| 64 | 65 | ||
| 65 | 66 | const USAGE = "usage: node scripts/deploy.mjs plan|deploy|build|migrate|manifest|doctor|install|build-base|image [--all] [--only a,b] [--skip a,b] [--force] [--rollback] [--concurrency N] [--stage S] [--json]"; | |
| 66 | 67 | ||
| ⋯ | |||
| 414 | 415 | // dirty tree is not a commit anyone can look at, so it is left out. | |
| 415 | 416 | const settle = dryRun || dirty ? null : await reportDeployment({ head, subject: context.subject, units: touched.map((u) => u.id), log }); | |
| 416 | 417 | ||
| 418 | + | // status.g1t.sh hears the deploy start and finish (STATUS_DEPLOY_TOKEN; | |
| 419 | + | // nothing without it), so the restarts it causes are not drafted as | |
| 420 | + | // incidents. Never in a dry run, and it never fails a deploy. | |
| 417 | 421 | let failed = false; | |
| 418 | − | for (const { stage, units } of byStage(stack, touched)) { | |
| 419 | − | if (failed) { | |
| 420 | − | for (const unit of units) results.push({ unit: unit.id, stage, ok: false, skipped: true, ms: 0, note: "an earlier stage failed" }); | |
| 421 | − | continue; | |
| 422 | − | } | |
| 423 | − | log(`== ${stage}: ${units.map((u) => u.id).join(", ")}`); | |
| 424 | − | const shipped = await pool(units, opts.concurrency, (unit) => ship(unit, deploying.find((d) => d.unit === unit), context)); | |
| 425 | − | results.push(...shipped); | |
| 426 | − | failed = shipped.some((r) => !r.ok); | |
| 427 | − | } | |
| 422 | + | await withDeployWindow( | |
| 423 | + | async () => { | |
| 424 | + | for (const { stage, units } of byStage(stack, touched)) { | |
| 425 | + | if (failed) { | |
| 426 | + | for (const unit of units) results.push({ unit: unit.id, stage, ok: false, skipped: true, ms: 0, note: "an earlier stage failed" }); | |
| 427 | + | continue; | |
| 428 | + | } | |
| 429 | + | log(`== ${stage}: ${units.map((u) => u.id).join(", ")}`); | |
| 430 | + | const shipped = await pool(units, opts.concurrency, (unit) => ship(unit, deploying.find((d) => d.unit === unit), context)); | |
| 431 | + | results.push(...shipped); | |
| 432 | + | failed = shipped.some((r) => !r.ok); | |
| 433 | + | } | |
| 434 | + | }, | |
| 435 | + | { id: head ?? null, dryRun, log }, | |
| 436 | + | ); | |
| 428 | 437 | summary(results); | |
| 429 | 438 | await settle?.(!failed); | |
| 430 | 439 | console.log(`\n${failed ? "Failed" : dryRun ? "Built" : "Deployed"} in ${seconds(Date.now() - started)}.`); | |
| 10 | 10 | // STATUS_URL defaults to https://status.g1t.sh. Never fails a deploy: | |
| 11 | 11 | // without the token it does nothing, and any error is a warning. | |
| 12 | 12 | // | |
| 13 | − | // In scripts/deploy.mjs `deploy()`, once there is something to ship and | |
| 14 | − | // before the first stage (not in a dry run): | |
| 15 | − | // | |
| 16 | − | // import { announceDeploy } from "./deploy/status-window.mjs"; | |
| 17 | − | // const id = head ?? null; | |
| 18 | − | // if (!dryRun) await announceDeploy("started", { id }); | |
| 19 | − | // try { ...the stages... } finally { if (!dryRun) await announceDeploy("finished", { id }); } | |
| 13 | + | // scripts/deploy.mjs `deploy()` wraps its stages in `withDeployWindow` | |
| 14 | + | // once there is something to ship (never in a dry run), so every deploy, | |
| 15 | + | // by hand or in g1t Actions (.g1t/workflows/deploy.yml passes the | |
| 16 | + | // STATUS_DEPLOY_TOKEN secret), says so. Jobs that run at once (a stage's | |
| 17 | + | // matrix) each say started and finished; the status Worker counts them and | |
| 18 | + | // the window closes when the last one finishes. | |
| 20 | 19 | ||
| 21 | 20 | import { pathToFileURL } from "node:url"; | |
| 22 | 21 | ||
| 23 | 22 | /** | |
| 23 | + | * Runs `work` inside a deploy window: "started" before, "finished" after, | |
| 24 | + | * whether it succeeded or threw. Neither announcement can fail the deploy. | |
| 25 | + | * | |
| 26 | + | * @template T | |
| 27 | + | * @param {() => Promise<T>} work | |
| 28 | + | * @param {{ id?: string | null, dryRun?: boolean, announce?: typeof announceDeploy, env?: Record<string, string | undefined>, log?: (line: string) => void }} [options] | |
| 29 | + | * @returns {Promise<T>} | |
| 30 | + | */ | |
| 31 | + | export async function withDeployWindow(work, { id = null, dryRun = false, announce = announceDeploy, env = process.env, log } = {}) { | |
| 32 | + | if (dryRun) return work(); | |
| 33 | + | const options = { id, env, ...(log ? { log } : {}) }; | |
| 34 | + | await announce("started", options); | |
| 35 | + | try { | |
| 36 | + | return await work(); | |
| 37 | + | } finally { | |
| 38 | + | await announce("finished", options); | |
| 39 | + | } | |
| 40 | + | } | |
| 41 | + | ||
| 42 | + | /** | |
| 24 | 43 | * @param {"started" | "finished"} phase | |
| 25 | 44 | * @param {{ id?: string | null, env?: Record<string, string | undefined>, fetchImpl?: typeof fetch, log?: (line: string) => void }} [options] | |
| 26 | 45 | * @returns {Promise<boolean>} whether status.g1t.sh took it |
| 1 | + | // node --test "scripts/deploy/*.test.mjs" (npm run test:deploy) | |
| 2 | + | import assert from "node:assert/strict"; | |
| 3 | + | import { readFileSync } from "node:fs"; | |
| 4 | + | import { join } from "node:path"; | |
| 5 | + | import { test } from "node:test"; | |
| 6 | + | ||
| 7 | + | import { announceDeploy, withDeployWindow } from "./status-window.mjs"; | |
| 8 | + | import { ROOT } from "./stack.mjs"; | |
| 9 | + | ||
| 10 | + | /** A fetch that keeps what it was asked, and answers `status`. */ | |
| 11 | + | function recorder(status = 200) { | |
| 12 | + | const calls = []; | |
| 13 | + | const fetchImpl = async (url, init) => { | |
| 14 | + | calls.push({ url, auth: init.headers.authorization, body: JSON.parse(init.body) }); | |
| 15 | + | return new Response("{}", { status }); | |
| 16 | + | }; | |
| 17 | + | return { calls, fetchImpl }; | |
| 18 | + | } | |
| 19 | + | ||
| 20 | + | test("a deploy is announced to status.g1t.sh with the token, and without one nothing is sent", async () => { | |
| 21 | + | const { calls, fetchImpl } = recorder(); | |
| 22 | + | assert.equal(await announceDeploy("started", { id: "abc123", env: { STATUS_DEPLOY_TOKEN: " t0k " }, fetchImpl }), true); | |
| 23 | + | assert.deepEqual(calls, [{ url: "https://status.g1t.sh/deploys", auth: "Bearer t0k", body: { phase: "started", id: "abc123" } }]); | |
| 24 | + | await announceDeploy("finished", { env: { STATUS_DEPLOY_TOKEN: "t", STATUS_URL: "http://localhost:8787/" }, fetchImpl }); | |
| 25 | + | assert.deepEqual(calls[1], { url: "http://localhost:8787/deploys", auth: "Bearer t", body: { phase: "finished" } }); | |
| 26 | + | const none = recorder(); | |
| 27 | + | assert.equal(await announceDeploy("started", { id: "abc", env: {}, fetchImpl: none.fetchImpl }), false); | |
| 28 | + | assert.equal(none.calls.length, 0, "no token: silently nothing"); | |
| 29 | + | }); | |
| 30 | + | ||
| 31 | + | test("an announcement that fails is a warning, never a failed deploy", async () => { | |
| 32 | + | const lines = []; | |
| 33 | + | const refused = recorder(401); | |
| 34 | + | assert.equal(await announceDeploy("started", { env: { STATUS_DEPLOY_TOKEN: "t" }, fetchImpl: refused.fetchImpl, log: (l) => lines.push(l) }), false); | |
| 35 | + | const broken = async () => { | |
| 36 | + | throw new TypeError("fetch failed"); | |
| 37 | + | }; | |
| 38 | + | assert.equal(await announceDeploy("finished", { env: { STATUS_DEPLOY_TOKEN: "t" }, fetchImpl: broken, log: (l) => lines.push(l) }), false); | |
| 39 | + | assert.equal(lines.length, 2); | |
| 40 | + | assert.match(lines[0], /401/); | |
| 41 | + | assert.match(lines[1], /fetch failed/); | |
| 42 | + | }); | |
| 43 | + | ||
| 44 | + | test("the stages run inside the window: started before, finished after, even when they throw; a dry run says nothing", async () => { | |
| 45 | + | const said = []; | |
| 46 | + | const announce = async (phase, { id }) => void said.push(`${phase} ${id}`); | |
| 47 | + | const order = []; | |
| 48 | + | const value = await withDeployWindow( | |
| 49 | + | async () => { | |
| 50 | + | order.push(said.length); | |
| 51 | + | return 42; | |
| 52 | + | }, | |
| 53 | + | { id: "abc", announce }, | |
| 54 | + | ); | |
| 55 | + | assert.equal(value, 42); | |
| 56 | + | assert.deepEqual(said, ["started abc", "finished abc"]); | |
| 57 | + | assert.deepEqual(order, [1], "the work ran after started, before finished"); | |
| 58 | + | ||
| 59 | + | said.length = 0; | |
| 60 | + | await assert.rejects(withDeployWindow(async () => Promise.reject(new Error("wrangler failed")), { id: "def", announce }), /wrangler failed/); | |
| 61 | + | assert.deepEqual(said, ["started def", "finished def"]); | |
| 62 | + | ||
| 63 | + | said.length = 0; | |
| 64 | + | await withDeployWindow(async () => 1, { id: "ghi", dryRun: true, announce }); | |
| 65 | + | assert.deepEqual(said, []); | |
| 66 | + | }); | |
| 67 | + | ||
| 68 | + | test("deploy.mjs announces every deploy, and the workflow passes it the token", () => { | |
| 69 | + | const tool = readFileSync(join(ROOT, "scripts", "deploy.mjs"), "utf8"); | |
| 70 | + | assert.match(tool, /import \{ withDeployWindow \} from "\.\/deploy\/status-window\.mjs"/); | |
| 71 | + | assert.match(tool, /await withDeployWindow\(/); | |
| 72 | + | const workflow = readFileSync(join(ROOT, ".g1t", "workflows", "deploy.yml"), "utf8"); | |
| 73 | + | // Every step that runs `deploy.mjs deploy` has the secret in its env. | |
| 74 | + | const steps = workflow.split(/\n\s+- name: /).filter((s) => /node scripts\/deploy\.mjs deploy /.test(s)); | |
| 75 | + | assert.ok(steps.length >= 1); | |
| 76 | + | for (const s of steps) assert.match(s, /STATUS_DEPLOY_TOKEN: \$\{\{ secrets\.STATUS_DEPLOY_TOKEN \}\}/); | |
| 77 | + | }); |