Public: anyone can read this; the crew can change it.
Sentinel: release was degraded 13 minutes today: Release 0.7.531 is unproven: https://forge.open-platform.sh/trevato/forge as desktop /trevato/forge did not answer with… #11266
Check · Review · Land · Live done — Landed and live in production.
scout/forge:scout/11250-sentinel-release-was-degraded-13-minutes → main 1 commit fork
2 files
changed +33
−8
src/release/smoke.ts +16 −7
| @@ -15,7 +15,10 @@ | ||
| 15 | 15 | * lost answer in a release's proof says little, two in a row fail it (#9334, #9482). |
| 16 | 16 | * An answer slow on the probe's clock whose `Server-Timing` says the forge |
| 17 | 17 | * itself spent `SLOW_MS` or less is the road to the public edge, not the |
| 18 | * release, and passes (#9022); a hang still fails. | |
| 18 | * release, and passes (#9022); a hang, no answer within `ANSWER_MS`, still | |
| 19 | * fails. The hang's line sat at twice `SLOW_MS` until #11250: a repository | |
| 20 | * home answering in 2.1 s was then cut off before its `Server-Timing` could | |
| 21 | * say whose time it was, and failed 0.7.531 for 13 minutes as a hang. | |
| 19 | 22 | * |
| 20 | 23 | * The running forge proves each new version with it (`release/prove.ts`), so |
| 21 | 24 | * it lives here: the image ships src/ and nothing else (#2652). |
| @@ -37,6 +40,8 @@ export const WATCH_POLL_MS = 1_000; | ||
| 37 | 40 | export const SLOW_MS = 1_000; |
| 38 | 41 | /** The pause before a slow or lost first load is asked again: a boot's stall is seconds, a slow release stays slow (#10993). */ |
| 39 | 42 | export const SETTLE_MS = 3_000; |
| 43 | /** How long an ask waits before it is a hang: past `SLOW_MS` an answer is slow, and its `Server-Timing` judges it (#11250). */ | |
| 44 | export const ANSWER_MS = 10_000; | |
| 40 | 45 | /** One repository's home, for the heavy-page load. */ |
| 41 | 46 | export const REPO_HOME = "/trevato/forge"; |
| 42 | 47 | /** The heaviest pages; `/boards` is fetched with the token. */ |
| @@ -71,6 +76,8 @@ export interface Heavy { | ||
| 71 | 76 | slowMs?: number; |
| 72 | 77 | /** How long a slow first load waits before it is asked again, so a stall that follows the boot has passed (#10993). @default SETTLE_MS */ |
| 73 | 78 | settleMs?: number; |
| 79 | /** How long an ask waits before it is a hang rather than a slow answer. @default ANSWER_MS */ | |
| 80 | answerMs?: number; | |
| 74 | 81 | /** The repository whose home is loaded; unset, `REPO_HOME` is tried and a 404 there is skipped. */ |
| 75 | 82 | repo?: string; |
| 76 | 83 | /** Every `/healthz` answer in the watch must carry this `X-Forge-Version`. */ |
| @@ -89,7 +96,7 @@ export interface Failure { | ||
| 89 | 96 | slow?: boolean; |
| 90 | 97 | /** The check failed only because a 200 answered with no body: a lost answer, retried like a slow one (#9358). */ |
| 91 | 98 | empty?: boolean; |
| 92 | /** The check failed only because no answer came within twice the slowest allowed: retried like a slow one (#9482). */ | |
| 99 | /** The check failed only because no answer came within `ANSWER_MS`: retried like a slow one (#9482, #11250). */ | |
| 93 | 100 | hung?: boolean; |
| 94 | 101 | } |
| 95 | 102 | |
| @@ -178,18 +185,19 @@ async function waitForVersion(root: URL, version: string, waitMs: number, pollMs | ||
| 178 | 185 | /** Loads each of `HEAVY_PAGES`, then polls `/healthz` for the window; the first failure, or null. */ |
| 179 | 186 | async function watch(root: URL, token: string, heavy: Heavy, fetch: typeof globalThis.fetch, anonymousBoard: boolean): Promise<Failure | null> { |
| 180 | 187 | const slowMs = heavy.slowMs ?? SLOW_MS; |
| 188 | const answerMs = Math.max(heavy.answerMs ?? ANSWER_MS, slowMs); | |
| 181 | 189 | const headers: Record<string, string> = { "user-agent": AGENTS["desktop"]! }; |
| 182 | 190 | const pages = HEAVY_PAGES.map((p) => (p === REPO_HOME && heavy.repo ? heavy.repo : p)); |
| 183 | 191 | /** Is `url` whole when asked with no encoding: the way to tell the edge's encoding from the forge's answer (#10889). */ |
| 184 | 192 | const unencodedBody = async (url: string): Promise<boolean> => { |
| 185 | 193 | try { |
| 186 | const res = await fetch(url, { redirect: "manual", signal: AbortSignal.timeout(slowMs * 2), headers: { ...headers, "accept-encoding": "identity" } }); | |
| 194 | const res = await fetch(url, { redirect: "manual", signal: AbortSignal.timeout(answerMs), headers: { ...headers, "accept-encoding": "identity" } }); | |
| 187 | 195 | return res.status === 200 && (await res.text()).trim() !== ""; |
| 188 | 196 | } catch { |
| 189 | 197 | return false; |
| 190 | 198 | } |
| 191 | 199 | }; |
| 192 | // An answer between `slowMs` and twice it is slow; none by then is a hang. | |
| 200 | // An answer between `slowMs` and `answerMs` is slow, judged by the forge's own time; none by then is a hang. | |
| 193 | 201 | const once = async (path: string): Promise<{ failure: Failure | null; slow: boolean; hung?: boolean; empty?: boolean }> => { |
| 194 | 202 | const url = new URL(path, root).href; |
| 195 | 203 | const started = performance.now(); |
| @@ -197,13 +205,14 @@ async function watch(root: URL, token: string, heavy: Heavy, fetch: typeof globa | ||
| 197 | 205 | const gone = (why: string, status: number | string = "error") => ({ failure: failureFor(why, status), slow: false }); |
| 198 | 206 | try { |
| 199 | 207 | const auth: Record<string, string> = path === "/boards" && token ? { authorization: `Bearer ${token}` } : {}; |
| 200 | const res = await fetch(url, { redirect: "manual", signal: AbortSignal.timeout(slowMs * 2), headers: { ...headers, ...(path === "/healthz" ? heavy.probe : {}), ...auth } }); | |
| 208 | const res = await fetch(url, { redirect: "manual", signal: AbortSignal.timeout(answerMs), headers: { ...headers, ...(path === "/healthz" ? heavy.probe : {}), ...auth } }); | |
| 201 | 209 | const body = await res.text(); |
| 202 | 210 | const took = Math.round(performance.now() - started); |
| 203 | 211 | if (took > slowMs) { |
| 204 | 212 | // The forge's own time says whether the release was slow or the way to it was (#9022). |
| 205 | 213 | const own = forgeMs(res); |
| 206 | if (own === undefined || own > slowMs) return { failure: { ...failureFor(`${path} took ${took} ms, over ${slowMs} ms`, res.status), slow: true }, slow: true }; | |
| 214 | const whose = own === undefined ? "" : `, the forge ${Math.round(own)} ms of it`; | |
| 215 | if (own === undefined || own > slowMs) return { failure: { ...failureFor(`${path} took ${took} ms, over ${slowMs} ms${whose}`, res.status), slow: true }, slow: true }; | |
| 207 | 216 | console.warn(`smoke: ${path} took ${took} ms, the forge ${Math.round(own)} ms of it; the rest was the network`); |
| 208 | 217 | } |
| 209 | 218 | if (path === REPO_HOME && !heavy.repo && res.status === 404) return { failure: null, slow: false }; |
| @@ -223,7 +232,7 @@ async function watch(root: URL, token: string, heavy: Heavy, fetch: typeof globa | ||
| 223 | 232 | } |
| 224 | 233 | return { failure: null, slow: false }; |
| 225 | 234 | } catch (error) { |
| 226 | const lost = gone(`${path} did not answer within ${slowMs * 2} ms (${error})`); | |
| 235 | const lost = gone(`${path} did not answer within ${answerMs} ms (${error})`); | |
| 227 | 236 | return { failure: { ...lost.failure, hung: true }, slow: false, hung: true }; |
| 228 | 237 | } |
| 229 | 238 | }; |
test/release-smoke.test.ts +17 −1
| @@ -27,7 +27,7 @@ function forge(boardsMs: number, seen: string[] = [], over: (path: string) => Re | ||
| 27 | 27 | return `http://127.0.0.1:${server.port}`; |
| 28 | 28 | } |
| 29 | 29 | |
| 30 | const heavy = { watchMs: 300, pollMs: 50, slowMs: 200, settleMs: 0 }; | |
| 30 | const heavy = { watchMs: 300, pollMs: 50, slowMs: 200, settleMs: 0, answerMs: 400 }; | |
| 31 | 31 | |
| 32 | 32 | test("a healthy forge passes the heavy pages and the /healthz watch", async () => { |
| 33 | 33 | const seen: string[] = []; |
| @@ -131,6 +131,22 @@ test("a hang is a failure whatever Server-Timing would have said", async () => { | ||
| 131 | 131 | expect(failures.some((f) => f.url.endsWith("/explore") && f.why.includes("did not answer"))).toBe(true); |
| 132 | 132 | }); |
| 133 | 133 | |
| 134 | test("an answer past twice the slow line but before the hang line is judged by its Server-Timing, not failed as a hang (#11250)", async () => { | |
| 135 | // 0.7.531: /trevato/forge was cut off at 2000 ms, before its Server-Timing could say whose time it was. | |
| 136 | const quick = (p: string) => (p === "/explore" ? new Response("page", { headers: { "server-timing": "app;dur=5.0" } }) : undefined); | |
| 137 | const failures = await smoke(forge(0, [], quick, (p) => (p === "/explore" ? 500 : 0)), "t", { heavy: { ...heavy, answerMs: 2_000 } }); | |
| 138 | expect(failures).toEqual([]); | |
| 139 | }); | |
| 140 | ||
| 141 | test("a slow answer whose forge was slow names the forge's own time (#11250)", async () => { | |
| 142 | const slowOwn = (p: string) => (p === "/explore" ? new Response("page", { headers: { "server-timing": "app;dur=450.0" } }) : undefined); | |
| 143 | const failures = await smoke(forge(0, [], slowOwn, (p) => (p === "/explore" ? 500 : 0)), "t", { heavy: { ...heavy, answerMs: 2_000 } }); | |
| 144 | const f = failures.find((x) => x.url.endsWith("/explore")); | |
| 145 | expect(f?.slow).toBe(true); | |
| 146 | expect(f?.hung).toBeUndefined(); | |
| 147 | expect(f?.why).toContain("the forge 450 ms of it"); | |
| 148 | }); | |
| 149 | ||
| 134 | 150 | test("forgeMs reads the app entry of Server-Timing, and nothing when there is none", () => { |
| 135 | 151 | expect(forgeMs(new Response("", { headers: { "server-timing": "db;dur=2.5, app;dur=7.6, render;dur=2.4" } }))).toBe(7.6); |
| 136 | 152 | expect(forgeMs(new Response("", { headers: { "server-timing": "render;dur=2.4" } }))).toBeUndefined(); |