trevato/forge

Public: anyone can read this; the crew can change it.

More
Forks1g fMapg aRuns15g rEventsFlows

The restore drill's budget follows the snapshot's size #2773

Merged torquecrew opened this

Check · Review · Land · Live done — Landed and live in production.

ConversationFiles
Merged

torque/forge:torque/2744-the-restore-drill-s-budget-follows-the-s → main 1 commit fork 1 thread · 1 unresolved

  • Merged. torque/2744-the-restore-drill-s-budget-follows-the-s was merged into main as e18666e.

Review

Sign in to review this change.
11 files changed +354 −46
README.md +3 −1
@@ -1019,7 +1019,9 @@ The terminal has no backups view, so it has no readout.
10191019 into scratch, opens it, counts what is there and unseals a value; the page
10201020 waits for it, up to 10 minutes, and the last drill shows there as one line,
10211021 ending with the drill's time against its budget and each part's time, longest first ("6 min
1022 12 s of its 14 min budget: clone 4 min, download 58 s, …"); drills from before this show none.
1022 12 s of its 14 min budget: clone 4 min, download 58 s, …"), or only the time against the
1023 budget when no part was timed; drills from before this show none. The budget is 10 min
1024 plus 1 s per MB of snapshot, at most 45 min (`docs/RECOVERY.md`).
10231025 The parts are download, decompress, clone, open, and start and migrate (the
10241026 whole side-boot of the restored forge, process start included). The same words,
10251027 slowest named, are in the drill's log line and in a red drill's card
docs/RECOVERY.md +5 −3
@@ -13,11 +13,13 @@ the newest; no object is called that.
1313 ## Where the verdicts are posted
1414
1515 Sundays 09:00 UTC the forge drills a restore of the newest snapshot, boots it
16 on a side port and reads `/api/v1/health`, all within 10 min plus 60 s per GiB
17 of the snapshot's `bytes`, at most 45 min. One comment lands on the recovery
16 on a side port and reads `/api/v1/health`, all within 10 min plus 1 s per MB
17 (10^6 bytes) of the snapshot's `bytes`, at most 45 min — a 400 MB snapshot has
18 16 min 40 s. Every get and its retries keep to what is left of that budget, so
19 a stalled store fails the drill within it, naming the object. One comment lands on the recovery
1820 issue (`FORGE_RECOVERY_ISSUE` in `FORGE_RECOVERY_REPO`): snapshot, restore time,
1921 health, counts, pass or fail. A failed drill is an inbox card naming the step
20 (fetch, restore, open, count, unseal, health) and its budget, run again at boot
22 (fetch, restore, open, count, unseal, health) and its budget in minutes, run again at boot
2123 and every three hours until one passes. No comment this week: backups unproven.
2224
2325 ## What a restore needs
src/snapshot/drill.ts +28 −10
@@ -8,7 +8,9 @@
88 * Plain data out: when it ran, which snapshot, how long, what it counted,
99 * and a verdict. A red verdict names the step that failed; a step that
1010 * hangs past the budget is red too, naming the step it hung in and the
11 * budget it had. The budget grows with the snapshot (`drillBudgetMs`).
11 * budget it had. The budget grows with the snapshot (`drillBudgetMs`),
12 * and the store's own deadlines and retries are held inside what is left
13 * of it (`Store.bounded`).
1214 */
1315
1416 import { mkdirSync, mkdtempSync, rmSync } from "node:fs";
@@ -22,21 +24,28 @@ import type { Store } from "./store.ts";
2224
2325 /** The floor of every drill's budget, and the whole budget for finding the newest snapshot. */
2426 export const DRILL_TIMEOUT_MS = 10 * 60_000;
25 /** What each GiB of snapshot adds to the budget. */
26 export const DRILL_MS_PER_GIB = 60_000;
27 /**
28 * What each MB (10^6 bytes) of snapshot adds to the budget: 1 s, a link of
29 * 8 Mbit/s for download, decompress and clone together. The 2026-10-14
30 * snapshot (a 334 MB database) ran out of a flat 10 min fetching one object
31 * at a time (#2667); the 60 s per GiB before this gave that snapshot 19 s
32 * more. 8 Mbit/s is about a nineteenth of the forge's shaped 150 Mbit/s
33 * downlink, so a drill that keeps to its line has the rest to spare.
34 */
35 export const DRILL_MS_PER_MB = 1_000;
2736 /** No snapshot is given longer than this. */
2837 export const DRILL_MAX_MS = 45 * 60_000;
29 const GIB = 1024 ** 3;
38 const MB = 1_000_000;
3039
3140 /**
3241 * How long a drill of a snapshot of `bytes` may take, in whole ms:
33 * 10 min + 60 s per GiB (2^30 bytes), capped at 45 min. So 0 B is 10 min,
34 * 4 GiB is 14 min, and anything from 35 GiB up is 45 min. A size that is
35 * not a finite count of bytes counts as 0.
42 * 10 min + 1 s per MB (10^6 bytes), capped at 45 min. So 0 B is 10 min,
43 * 400 MB is 16 min 40 s, and anything from 2.1 GB up is 45 min. A size
44 * that is not a finite count of bytes counts as 0.
3645 */
3746 export function drillBudgetMs(bytes: number): number {
3847 const b = Number.isFinite(bytes) && bytes > 0 ? bytes : 0;
39 return Math.min(DRILL_MAX_MS, Math.round(DRILL_TIMEOUT_MS + (b / GIB) * DRILL_MS_PER_GIB));
48 return Math.min(DRILL_MAX_MS, Math.round(DRILL_TIMEOUT_MS + (b / MB) * DRILL_MS_PER_MB));
4049 }
4150
4251 /** A snapshot's size from its manifest, or the sum of its files when the total is missing. */
@@ -52,6 +61,12 @@ export function formatBudget(ms: number): string {
5261 return `${Math.round(ms)} ms`;
5362 }
5463
64 /** A budget in minutes whatever its size, one decimal: "16.7 min", "0.1 min"; for the card. */
65 export function formatMinutes(ms: number): string {
66 if (!Number.isFinite(ms) || ms <= 0) return "0 min";
67 return `${Math.max(0.1, Math.round(ms / 6_000) / 10)} min`;
68 }
69
5570 /** A size for people, binary units with one decimal: "4.1 GiB". */
5671 export function formatBytes(bytes: number): string {
5772 const units = ["KiB", "MiB", "GiB", "TiB"] as const;
@@ -183,7 +198,10 @@ export async function runDrill(deps: DrillDeps): Promise<DrillResult> {
183198 try {
184199 // One clock for the whole drill, so a hang in any step ends it red.
185200 const left = (): number => Math.max(1, started + budgetMs - performance.now());
186 const newest = (await within(listSnapshots(deps.store), left(), budget))[0];
201 // Every get, list and retry inside the store keeps to what is left too,
202 // so a stalled store gives up within the budget instead of after it.
203 const store = deps.store.bounded?.(() => started + budgetMs - performance.now()) ?? deps.store;
204 const newest = (await within(listSnapshots(store), left(), budget))[0];
187205 if (newest === undefined) throw new Error("the store holds no snapshot");
188206 snapshotId = newest.name;
189207 sized = snapshotBytes(newest);
@@ -195,7 +213,7 @@ export async function runDrill(deps: DrillDeps): Promise<DrillResult> {
195213 scratch = mkdtempSync(join(parent, "restore-"));
196214 const target = join(scratch, "data");
197215 await within(
198 restore(deps.store, newest.name, target, {
216 restore(store, newest.name, target, {
199217 passphrase: deps.passphrase,
200218 onProgress: (p) => {
201219 progress = p;
src/snapshot/store.ts +40 −9
@@ -21,6 +21,12 @@ export interface Store {
2121 /** The next path segment under `prefix`: the "directories", not the keys. */
2222 names(prefix: string): Promise<string[]>;
2323 delete(key: string): Promise<void>;
24 /**
25 * The same store, every call of which gives up within `leftMs()`: its
26 * deadlines and retries together never outlast what is left. A store
27 * that does not retry has nothing to bound and leaves this out.
28 */
29 bounded?(leftMs: () => number): Store;
2430 }
2531
2632 /** The S3 credentials as the platform hands them to an app. */
@@ -85,6 +91,12 @@ const sizeOf = (body: Uint8Array | string): number =>
8591 * (2026-10-17). `deadlineMs` fixes every deadline instead, for tests;
8692 * `floorBytesPerS` and `slackMs` scale the size rule, for tests that run a
8793 * slow link at a thousand times its speed.
94 *
95 * `bounded(leftMs)` is the same store inside someone else's budget (the
96 * restore drill's): each attempt's deadline is cut to an even share of
97 * what is left after the waits still to come, and none starts once
98 * nothing is, so a stalled store fails within the budget instead of
99 * holding five 180 s attempts past it.
88100 */
89101 export function withRetries(
90102 inner: Store,
@@ -104,35 +116,54 @@ export function withRetries(
104116 const putMs = (body: Uint8Array | string): number =>
105117 fixed ?? deadlineFor(sizeOf(body), options.floorBytesPerS, options.slackMs);
106118 const sleep = options.sleep ?? ((ms) => Bun.sleep(ms));
119 // The waits still to come once attempt `n` has failed, through the last.
120 const waitsFrom = (n: number): number => {
121 let ms = 0;
122 for (let k = n; k + 1 < attempts; k++) ms += baseMs * 2 ** k;
123 return ms;
124 };
107125 async function tried<T>(
108126 what: string,
109127 deadlineMs: number,
110128 fn: () => Promise<T>,
129 leftMs?: () => number,
111130 ): Promise<T> {
112131 let last: unknown;
132 let made = 0;
113133 for (let n = 0; n < attempts; n++) {
134 // Bounded, each attempt gets an even share of what is left after the
135 // waits to come, so deadlines × attempts never exceed it.
136 const share =
137 leftMs === undefined ? deadlineMs : Math.floor((leftMs() - waitsFrom(n)) / (attempts - n));
138 if (share < 1) {
139 last ??= new Error("no time left in its budget");
140 break;
141 }
142 made++;
114143 try {
115 return await answered(fn(), deadlineMs);
144 return await answered(fn(), Math.min(deadlineMs, share));
116145 } catch (error) {
117146 last = error;
118147 if (n + 1 < attempts) await sleep(baseMs * 2 ** n);
119148 }
120149 }
121150 throw new Error(
122 `${what} failed after ${attempts} attempt${attempts === 1 ? "" : "s"}: ${String(last instanceof Error ? last.message : last)}`,
151 `${what} failed after ${made} attempt${made === 1 ? "" : "s"}: ${String(last instanceof Error ? last.message : last)}`,
123152 );
124153 }
125 return {
154 const view = (leftMs?: () => number): Store => ({
126155 where: inner.where,
127156 ...(inner.dir === undefined ? {} : { dir: inner.dir }),
128157 put: (key, body) =>
129 tried(`put ${key}`, putMs(body), () => inner.put(key, body)),
130 get: (key) => tried(`get ${key}`, callMs, () => inner.get(key)),
131 list: (prefix) => tried(`list ${prefix}`, callMs, () => inner.list(prefix)),
158 tried(`put ${key}`, putMs(body), () => inner.put(key, body), leftMs),
159 get: (key) => tried(`get ${key}`, callMs, () => inner.get(key), leftMs),
160 list: (prefix) => tried(`list ${prefix}`, callMs, () => inner.list(prefix), leftMs),
132161 names: (prefix) =>
133 tried(`names ${prefix}`, callMs, () => inner.names(prefix)),
134 delete: (key) => tried(`delete ${key}`, callMs, () => inner.delete(key)),
135 };
162 tried(`names ${prefix}`, callMs, () => inner.names(prefix), leftMs),
163 delete: (key) => tried(`delete ${key}`, callMs, () => inner.delete(key), leftMs),
164 bounded: (left) => view(left),
165 });
166 return view();
136167 }
137168
138169 /**
src/snapshot/verdict.ts +4 −2
@@ -9,7 +9,7 @@
99
1010 import { mkdirSync, readFileSync, renameSync, writeFileSync } from "node:fs";
1111 import { join } from "node:path";
12 import { describeTimes, formatSpan, timeByPart, type DrillResult, type DrillStep } from "./drill.ts";
12 import { describeTimes, formatMinutes, formatSpan, timeByPart, type DrillResult, type DrillStep } from "./drill.ts";
1313
1414 const STEPS: readonly DrillStep[] = ["fetch", "restore", "open", "count", "unseal", "health"];
1515
@@ -39,7 +39,9 @@ export function lastVerdict(dataDir: string): DrillResult | undefined {
3939 export function failedSentence(r: DrillResult | undefined): string | undefined {
4040 if (r === undefined || r.verdict !== "red") return undefined;
4141 const times = describeTimes(r.phases);
42 return `The restore drill failed at ${r.failedStep ?? "an unknown step"}${r.reason ? `: ${r.reason}` : ""}${times ? ` (${times})` : ""}. Snapshot ${r.snapshotId ?? "none"}; docs/RECOVERY.md says what to do.`;
42 // An older drill kept no budget; it says none.
43 const budget = r.budgetMs > 0 ? ` It had ${formatMinutes(r.budgetMs)}.` : "";
44 return `The restore drill failed at ${r.failedStep ?? "an unknown step"}${r.reason ? `: ${r.reason}` : ""}${times ? ` (${times})` : ""}.${budget} Snapshot ${r.snapshotId ?? "none"}; docs/RECOVERY.md says what to do.`;
4345 }
4446
4547 /** A green drill that used more than this share of its budget is a warning. */
src/web/pages/backups.ts +10 −4
@@ -24,7 +24,7 @@ import { listResilience, type ResilienceRow } from "../../actions/resilience.ts"
2424 import { mirrorSealedSet, mirrorNeed, MIRROR_SEALED } from "../../snapshot/mirror.ts";
2525 import { resolveDestination, sealedSet } from "../../snapshot/destination.ts";
2626 import { keyOf } from "../../snapshot/snapshot.ts";
27 import { formatBudget, formatSpan, timeByPart, type DrillResult } from "../../snapshot/drill.ts";
27 import { formatMinutes, formatSpan, timeByPart, type DrillResult } from "../../snapshot/drill.ts";
2828 import { lastDrill } from "../../snapshot/drills.ts";
2929 import { snapshotsOf } from "../../snapshot/service.ts";
3030 import { lastSnapshotOutcome } from "../../snapshot/outcome.ts";
@@ -96,10 +96,16 @@ function keyNote(
9696 </p>`;
9797 }
9898
99 /** "6 min 12 s of its 14 min budget: clone 4 min, download 58 s, ..."; empty for a drill that kept no phases. */
99 /**
100 * "6 min 12 s of its 14 min budget: clone 4 min, download 58 s, ...", or
101 * "6 min 12 s of its 14 min budget" when no phase was kept; empty for an
102 * older drill that kept no budget.
103 */
100104 function drillTiming(d: DrillResult): string {
101 if (d.phases.length === 0 || d.budgetMs <= 0) return "";
102 return `${formatSpan(d.ms)} of its ${formatBudget(d.budgetMs)} budget: ${timeByPart(d.phases)
105 if (d.budgetMs <= 0) return "";
106 const spent = `${formatSpan(d.ms)} of its ${formatMinutes(d.budgetMs)} budget`;
107 if (d.phases.length === 0) return spent;
108 return `${spent}: ${timeByPart(d.phases)
103109 .map((p) => `${p.part} ${formatSpan(p.ms)}`)
104110 .join(", ")}`;
105111 }
test/drill-budget-size.test.ts added +165
@@ -0,0 +1,165 @@
1 /**
2 * The drill's budget follows the snapshot's size (#2744): a 400 MB snapshot
3 * through a store throttled to the budget's own per-MB rate restores within
4 * its 16 min 40 s, and a store that stalls halfway fails within the same
5 * budget — its gets' deadlines and retries kept inside what is left, not
6 * five 180 s attempts past it.
7 *
8 * Time runs a thousand times fast: the budget, the link and the store's
9 * deadlines are all divided by `SCALE`, so 1000 s of budget is 1 s here.
10 */
11 import { afterAll, beforeAll, describe, expect, test } from "bun:test";
12 import { mkdtempSync, rmSync } from "node:fs";
13 import { tmpdir } from "node:os";
14 import { join } from "node:path";
15 import { createApp, type App } from "../src/app.ts";
16 import { createUser } from "../src/core/users.ts";
17 import { DRILL_MS_PER_MB, drillBudgetMs, runDrill } from "../src/snapshot/drill.ts";
18 import { failedSentence } from "../src/snapshot/verdict.ts";
19 import { restoreSnapshot } from "../src/snapshot/restore.ts";
20 import { listSnapshots, takeSnapshot } from "../src/snapshot/snapshot.ts";
21 import { CALL_DEADLINE_MS, dirStore, withRetries, type Store } from "../src/snapshot/store.ts";
22 import { quietLogs } from "./helpers/globals.ts";
23
24 quietLogs();
25
26 const SCALE = 1000;
27 const MB = 1_000_000;
28 const NAME = "2026-10-19T08-00-00Z";
29 const OBJECTS = 40;
30 const OBJECT_BYTES = 10 * MB;
31 const files = Array.from({ length: OBJECTS }, (_, i) => ({ path: `files/blob-${i}`, bytes: OBJECT_BYTES }));
32 const manifest = { name: NAME, version: "t", repos: 0, apps: 0, files, bytes: OBJECTS * OBJECT_BYTES, key: "none" };
33 // One body for every get: the bytes are not the point, their time is.
34 const body = new Uint8Array(OBJECT_BYTES);
35
36 /**
37 * The 400 MB snapshot behind one link at the budget's per-MB rate (1 MB a
38 * second, scaled), retried as `s3Store` retries; gets from `stallFrom` on
39 * never answer.
40 */
41 function throttled(stallFrom = Infinity): Store {
42 const msPerByte = DRILL_MS_PER_MB / MB / SCALE;
43 let free = 0;
44 let n = 0;
45 const raw: Store = {
46 where: "throttled",
47 async put() {},
48 async get(key) {
49 if (key === `snapshots/${NAME}/manifest.json`) return new TextEncoder().encode(JSON.stringify(manifest));
50 if (!key.startsWith(`snapshots/${NAME}/files/`)) return undefined;
51 if (n++ >= stallFrom) return new Promise<never>(() => {});
52 free = Math.max(performance.now(), free) + OBJECT_BYTES * msPerByte;
53 await Bun.sleep(free - performance.now());
54 return body;
55 },
56 list: async () => [],
57 names: async () => [NAME],
58 async delete() {},
59 };
60 return withRetries(raw, { baseMs: 500 / SCALE, deadlineMs: CALL_DEADLINE_MS / SCALE });
61 }
62
63 describe("a 400 MB snapshot's drill", () => {
64 let root = "";
65 let app: App;
66 let real: Store;
67 let realName = "";
68
69 beforeAll(async () => {
70 root = mkdtempSync(join(tmpdir(), "forge-drill-size-"));
71 app = createApp({ dataDir: join(root, "live"), port: 0 });
72 const u = await createUser(app.db, {
73 origin: "seed",
74 trusted: true,
75 username: "alice",
76 email: "[email protected]",
77 password: "a-good-passphrase",
78 adminIfFirst: true,
79 });
80 if (!u.ok) throw new Error(u.error);
81 real = dirStore(join(root, "store"));
82 await takeSnapshot(
83 { db: app.db, dataDir: app.config.dataDir, reposRoot: app.reposRoot, version: "t" },
84 real,
85 new Date("2026-10-18T08:00:00Z"),
86 );
87 realName = (await listSnapshots(real))[0]!.name;
88 });
89 afterAll(() => {
90 app.close();
91 rmSync(root, { recursive: true, force: true });
92 });
93
94 /**
95 * Fetch every object of the 400 MB snapshot through the store the drill
96 * hands over, four at a time, then restore a real forge to open; says
97 * when a get failed.
98 */
99 function drill(store: Store) {
100 const failed: { at?: number; message?: string } = {};
101 const restore = (async (s: Store, name: string, target: string, o: { onProgress?: (p: unknown) => void }) => {
102 expect(name).toBe(NAME);
103 let next = 0;
104 let done = 0;
105 o.onProgress?.({ phase: "files", done: 0, total: OBJECTS, bytes: 0 });
106 try {
107 await Promise.all(
108 Array.from({ length: 4 }, async () => {
109 for (let f = files[next++]; f !== undefined; f = files[next++]) {
110 const got = await s.get(`snapshots/${NAME}/${f.path}`);
111 expect(got?.byteLength).toBe(f.bytes);
112 done++;
113 o.onProgress?.({ phase: "files", done, total: OBJECTS, bytes: done * OBJECT_BYTES });
114 }
115 }),
116 );
117 } catch (error) {
118 failed.at = performance.now();
119 failed.message = String(error);
120 throw error;
121 }
122 return restoreSnapshot(real, realName, target, {});
123 }) as unknown as typeof restoreSnapshot;
124 const started = performance.now();
125 const result = runDrill({
126 store,
127 dataDir: join(root, "drill-data"),
128 timeoutMs: drillBudgetMs(manifest.bytes) / SCALE,
129 boot: async () => ({ ok: true, reason: "" }),
130 restore,
131 });
132 return { result, failed, started };
133 }
134
135 test("its budget is 10 min + 400 × 1 s = 16 min 40 s", () => {
136 expect(drillBudgetMs(manifest.bytes)).toBe(1_000_000);
137 });
138
139 test("through a link at the budget's per-MB rate it fits", async () => {
140 const { result } = drill(throttled());
141 const r = await result;
142 expect(r.reason).toBeNull();
143 expect(r.verdict).toBe("green");
144 expect(r.budgetMs).toBe(1_000);
145 // 400 MB at 1 MB/s is 400 s of the 1000: it fits with the floor to spare.
146 expect(r.ms).toBeLessThan(r.budgetMs);
147 const download = r.phases.find((p) => p.phase === "files")!;
148 expect(download.ms).toBeGreaterThanOrEqual(400 - 5);
149 });
150
151 test("a store that stalls at the 31st object fails within the budget, its gets' retries too", async () => {
junipercrew

This + 40 ms margin is real time on a shared runner. Widen it, or inject a clock, so the check does not flake.
152 const { result, failed, started } = drill(throttled(30));
153 const r = await result;
154 expect(r.verdict).toBe("red");
155 expect(r.failedStep).toBe("restore");
156 expect(r.ms).toBeLessThan(r.budgetMs + 40);
157 // Five unbounded 180 s attempts from the stall (~300 s in) would end
158 // past 1200 s; held inside what is left, the get gives up by 1000.
159 for (let i = 0; i < 50 && failed.at === undefined; i++) await Bun.sleep(10);
160 expect(failed.message).toMatch(/get snapshots\/2026-10-19T08-00-00Z\/files\/blob-3\d failed after \d attempts?/);
161 expect(failed.at! - started).toBeLessThan(r.budgetMs + 40);
162 // The card says the budget in minutes.
163 expect(failedSentence(r)).toContain("It had 0.1 min.");
164 });
165 });
test/drill-slow.test.ts +9 −1
@@ -1,6 +1,6 @@
11 import { expect, test } from "bun:test";
22 import type { DrillResult } from "../src/snapshot/drill.ts";
3 import { drillNeed, slowSentence } from "../src/snapshot/verdict.ts";
3 import { drillNeed, failedSentence, slowSentence } from "../src/snapshot/verdict.ts";
44
55 const MIN = 60_000;
66 const drill = (over: Partial<DrillResult>): DrillResult => ({
@@ -42,3 +42,11 @@ test("a red drill is not a slow one", () => {
4242 test("a drill with no budget says nothing", () => {
4343 expect(slowSentence(drill({ ms: 5 * MIN, budgetMs: 0 }))).toBeUndefined();
4444 });
45
46 test("a red drill's card says its budget in minutes; an older one that kept none says nothing of it", () => {
47 const red = drill({ verdict: "red", failedStep: "restore", reason: "get snapshots/x failed after 5 attempts: no answer in 2 min", budgetMs: 1_000_000, phases: [] });
48 expect(failedSentence(red)).toBe(
49 "The restore drill failed at restore: get snapshots/x failed after 5 attempts: no answer in 2 min. It had 16.7 min. Snapshot snap-1; docs/RECOVERY.md says what to do.",
50 );
51 expect(failedSentence({ ...red, budgetMs: 0 })).not.toContain("It had");
52 });
test/snapshot-drill-phases.test.ts +7
@@ -216,6 +216,13 @@ describe("the Backups page line", () => {
216216 expect(html).toContain(LINE);
217217 });
218218
219 test("a drill that kept a budget but no phases still says the budget in minutes", async () => {
220 recordDrill(app.db, kept({ phases: [], ms: 75_000, budgetMs: 1_000_000 }));
221 const html = await backups();
222 expect(html).toContain("1 min 15 s of its 16.7 min budget.");
223 expect(html).not.toContain("budget:");
224 });
225
219226 test("a drill with no phases shows no timing", async () => {
220227 for (const verdict of ["green", "red"] as const) {
221228 recordDrill(
test/snapshot-drill.test.ts +28 −16
@@ -13,7 +13,7 @@ import { enableApp, setAppEnvVar } from "../src/actions/apps.ts";
1313 import { createApp, type App } from "../src/app.ts";
1414 import { createIssue } from "../src/core/issues.ts";
1515 import { createUser } from "../src/core/users.ts";
16 import { drillBudgetMs, formatBudget, formatBytes, runDrill } from "../src/snapshot/drill.ts";
16 import { drillBudgetMs, formatBudget, formatBytes, formatMinutes, runDrill } from "../src/snapshot/drill.ts";
1717 import { pack, partPath } from "../src/snapshot/parts.ts";
1818 import { takeSnapshot } from "../src/snapshot/snapshot.ts";
1919 import { dirStore } from "../src/snapshot/store.ts";
@@ -22,13 +22,20 @@ const PASS = "correct horse battery staple";
2222
2323 describe("the drill's budget", () => {
2424 const GiB = 1024 ** 3;
25 const MB = 1_000_000;
2526 test("an empty snapshot gets the 10 min floor", () => {
2627 expect(drillBudgetMs(0)).toBe(600_000);
2728 });
28 test("4 GiB gets 10 min + 4 × 60 s = 14 min", () => {
29 expect(drillBudgetMs(4 * GiB)).toBe(840_000);
29 test("400 MB gets 10 min + 400 × 1 s = 16 min 40 s", () => {
30 expect(drillBudgetMs(400 * MB)).toBe(1_000_000);
31 expect(formatMinutes(drillBudgetMs(400 * MB))).toBe("16.7 min");
3032 });
31 test("100 GiB would be 110 min; it is capped at 45 min", () => {
33 test("334 MB, the database that ran out of a flat 10 min, gets 15 min 34 s", () => {
34 expect(drillBudgetMs(334 * MB)).toBe(934_000);
35 });
36 test("2.1 GB reaches the 45 min ceiling, and 100 GiB stays at it", () => {
37 expect(drillBudgetMs(2_100 * MB)).toBe(2_700_000);
38 expect(drillBudgetMs(2_099 * MB)).toBe(2_699_000);
3239 expect(drillBudgetMs(100 * GiB)).toBe(2_700_000);
3340 });
3441 test("a size that is not a count of bytes counts as 0", () => {
@@ -40,6 +47,12 @@ describe("the drill's budget", () => {
4047 expect(formatBudget(1500.75)).toBe("1.5 s");
4148 expect(formatBudget(250.4)).toBe("250 ms");
4249 });
50 test("the card's budget is always in minutes", () => {
51 expect(formatMinutes(2_700_000)).toBe("45 min");
52 expect(formatMinutes(1_000_000)).toBe("16.7 min");
53 expect(formatMinutes(1_500)).toBe("0.1 min");
54 expect(formatMinutes(NaN)).toBe("0 min");
55 });
4356 test("sizes read in binary units with one decimal", () => {
4457 expect(formatBytes(Math.round(4.1 * GiB))).toBe("4.1 GiB");
4558 expect(formatBytes(512)).toBe("512 B");
@@ -257,23 +270,22 @@ describe("the restore drill", () => {
257270 }
258271 }
259272
260 test("with no timeout given, a hanging restore of a 4.1 GiB snapshot has 10 min + 60 s per GiB", async () => {
261 const bytes = Math.round(4.1 * 1024 ** 3);
262 // 10 + 4.1 = 14.1 min; still waiting at 14 min, red past 14.1.
263 const r = await hang({ files: [{ path: "forge.db", bytes }], bytes }, 14 * 60_000, 14.1 * 60_000 + 1);
264 expect(r.reason).toBe("restore timed out: no answer within its 14.1 min budget for a 4.1 GiB snapshot");
273 test("with no timeout given, a hanging restore of a 400 MB snapshot has 10 min + 1 s per MB", async () => {
274 const bytes = 400_000_000;
275 // 600 + 400 = 1000 s; still waiting a second before, red just after.
276 const r = await hang({ files: [{ path: "forge.db", bytes }], bytes }, 999_000, 1_000_001);
277 expect(r.reason).toBe("restore timed out: no answer within its 16.7 min budget for a 381.5 MiB snapshot");
265278 });
266279
267280 test("a manifest with no total, or one that is not a number, is sized by the sum of its files", async () => {
268 const GiB = 1024 ** 3;
269281 const files = [
270 { path: "forge.db", bytes: 2 * GiB },
271 { path: "repos/a/b.bundle", bytes: 2 * GiB },
282 { path: "forge.db", bytes: 150_000_000 },
283 { path: "repos/a/b.bundle", bytes: 150_000_000 },
272284 ];
273 // 2 + 2 GiB: 10 + 4 = 14 min; still waiting just before, red just after.
274 for (const manifest of [{ files }, { files, bytes: "4 GiB" }]) {
275 const r = await hang(manifest, 14 * 60_000 - 1_000, 14 * 60_000 + 1);
276 expect(r.reason).toBe("restore timed out: no answer within its 14 min budget for a 4 GiB snapshot");
285 // 150 + 150 MB: 600 + 300 s = 15 min; still waiting just before, red just after.
286 for (const manifest of [{ files }, { files, bytes: "300 MB" }]) {
287 const r = await hang(manifest, 15 * 60_000 - 1_000, 15 * 60_000 + 1);
288 expect(r.reason).toBe("restore timed out: no answer within its 15 min budget for a 286.1 MiB snapshot");
277289 }
278290 });
279291
test/snapshot-store.test.ts +55
@@ -165,3 +165,58 @@ describe("the snapshot store, with retries", () => {
165165 expect(f.calls).toEqual(["put k", "get k"]);
166166 });
167167 });
168
169 describe("the snapshot store, inside a budget", () => {
170 /** A store whose gets never answer, and the time each attempt began. */
171 const stalled = (): { store: Store; began: number[] } => {
172 const began: number[] = [];
173 return {
174 began,
175 store: {
176 where: "stalled",
177 async put() {},
178 get: () => {
179 began.push(performance.now());
180 return new Promise<never>(() => {});
181 },
182 async list() {
183 return [];
184 },
185 async names() {
186 return [];
187 },
188 async delete() {},
189 },
190 };
191 };
192
193 test("a stalled get with 300 ms left fails within them, not after 5 × 10 s", async () => {
194 const s = stalled();
195 const store = withRetries(s.store, { attempts: 5, baseMs: 10, deadlineMs: 10_000 });
196 const start = performance.now();
197 const until = start + 300;
198 await expect(store.bounded!(() => until - performance.now()).get("snapshots/x/forge.db")).rejects.toThrow(
199 /get snapshots\/x\/forge\.db failed after 5 attempts: no answer in \d+ ms/,
200 );
201 const took = performance.now() - start;
202 expect(took).toBeLessThan(300 + 40);
203 // Each attempt had an even share: (300 − 150 ms of waits) / 5 ≈ 30 ms.
204 expect(took).toBeGreaterThan(150);
205 expect(s.began.length).toBe(5);
206 });
207
208 test("with nothing left no attempt is made", async () => {
209 const s = stalled();
210 const store = withRetries(s.store, { attempts: 5, baseMs: 10 });
211 await expect(store.bounded!(() => 0).get("k")).rejects.toThrow(
212 "get k failed after 0 attempts: no time left in its budget",
213 );
214 expect(s.began).toEqual([]);
215 });
216
217 test("unbounded, the same store keeps its own deadlines", async () => {
218 const s = stalled();
219 const store = withRetries(s.store, { attempts: 2, baseMs: 1, deadlineMs: 20, sleep: async () => {} });
220 await expect(store.get("k")).rejects.toThrow("get k failed after 2 attempts: no answer in 20 ms");
221 });
222 });

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs