trevato/forge

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

More
Forks1g fMapg aRuns3g rEventsFlows

Every GET page walked against a budget, naming its slowest phase #10579

Merged scoutcrew opened this

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

ConversationFiles
Merged

scout/forge:scout/10535-every-get-page-walked-against-a-budget-n → main 5 commits fork 3 threads · 3 unresolved

  • Merged. scout/10535-every-get-page-walked-against-a-budget-n was merged into main as f3a7883.

Review

Sign in to review this change.
3 files changed +245 −3
test/helpers/statements.ts +3 −2
@@ -32,7 +32,7 @@ const RUNS = 5;
3232 type Door = { query: unknown };
3333
3434 /** Run `work` once with the statement counter on; return what it cost. */
35 async function once(
35 export async function once(
3636 db: Database,
3737 work: () => Promise<void> | void,
3838 ): Promise<number> {
@@ -76,9 +76,10 @@ export async function quiet(db: Database): Promise<void> {
7676 export async function statements(
7777 db: Database,
7878 work: () => Promise<void> | void,
79 runs: number = RUNS,
7980 ): Promise<number> {
8081 let fewest = Number.POSITIVE_INFINITY;
81 for (let run = 0; run < RUNS; run++) {
82 for (let run = 0; run < runs; run++) {
8283 await quiet(db);
8384 fewest = Math.min(fewest, await once(db, work));
8485 }
test/helpers/work.ts +55 −1
@@ -9,7 +9,8 @@
99 */
1010 import type { Database } from "bun:sqlite";
1111 import { expect } from "bun:test";
12 import { statements } from "./statements.ts";
12 import { gitRecord } from "../../src/perf/live.ts";
13 import { once, statements } from "./statements.ts";
1314
1415 /** The fewest SQL statements one request for `url` costs (server and test share `db`). */
1516 export async function requestStatements(db: Database, url: string, init?: RequestInit): Promise<number> {
@@ -22,3 +23,56 @@ export async function requestStatements(db: Database, url: string, init?: Reques
2223 export function expectWork(measured: number, opts: { max: number }): void {
2324 expect(measured).toBeLessThanOrEqual(opts.max);
2425 }
26
27 /** The git processes `work` spawns, counted from the spawn record (every `runGit` notes one). */
28 export async function gitSpawns(work: () => Promise<void> | void): Promise<number> {
29 const total = () => gitRecord.patterns().reduce((n, k) => n + gitRecord.traffic(k, 0).length, 0);
30 const before = total();
31 await work();
32 return total() - before;
33 }
34
35 /** What one warm request cost: counted work for the pull, the clock only to print. */
36 export interface PageWork {
37 status: number;
38 statements: number;
39 git: number;
40 /** Server-Timing phases in ms, slowest first. */
41 phases: Array<{ name: string; ms: number }>;
42 ms: number;
43 }
44
45 /** Parses a Server-Timing header into phases, slowest first. */
46 export function parsePhases(header: string): Array<{ name: string; ms: number }> {
47 return header
48 .split(",")
49 .map((p) => p.trim().split(";"))
50 .map(([name, ...rest]) => ({ name: name!, ms: Number(rest.find((r) => r.startsWith("dur="))?.slice(4) ?? 0) }))
51 .filter((p) => p.name !== "" && p.name !== "lag" && Number.isFinite(p.ms))
52 .sort((a, b) => b.ms - a.ms);
53 }
54
55 /**
56 * Walks one URL warm: a first request fills the caches, a second is measured
57 * (statements, git spawns, Server-Timing) with no wait for rest, so a sweep of
58 * every page stays in seconds. Stray background work only raises a count.
59 */
60 export async function pageWork(db: Database, url: string, init?: RequestInit): Promise<PageWork> {
61 await (await fetch(url, init)).arrayBuffer();
62 let status = 0;
63 let header = "";
64 let ms = 0;
65 let git = Number.POSITIVE_INFINITY;
66 const count = await once(db, async () => {
67 const g = await gitSpawns(async () => {
68 const t = performance.now();
69 const res = await fetch(url, init);
70 await res.arrayBuffer();
71 ms = performance.now() - t;
72 status = res.status;
73 header = res.headers.get("server-timing") ?? "";
74 });
75 git = Math.min(git, g);
76 });
77 return { status, statements: count, git, phases: parsePhases(header), ms };
78 }
test/pages-budget.test.ts added +187
@@ -0,0 +1,187 @@
1 /**
2 * Every GET page, walked warm against a budget (#10535). The routes come from
3 * `server.ts` and `settings_routes.ts` themselves, as in the Server-Timing
4 * sweep, so a page is walked the day it is added.
5 *
6 * What a pull judges is counted work (`helpers/work.ts`, #7824): SQL
7 * statements and git processes per page, which an N+1 raises in every run.
8 * The clock is printed per phase and never judged here. A failure names the
9 * route and its slowest Server-Timing phase. A route that needs an id the
10 * fixture does not hold is listed by name, and `MAX_UNFIXTURED` pins how many
11 * there may be: a new page needs a fixture, or the count is raised on purpose.
12 */
13 import { afterAll, beforeAll, expect, test } from "bun:test";
14 import { mkdtempSync, rmSync } from "node:fs";
15 import { tmpdir } from "node:os";
16 import { join } from "node:path";
17 import { commitToBranch, createRepo } from "../src/actions/repos.ts";
18 import { createApp, type App } from "../src/app.ts";
19 import { createIssue } from "../src/core/issues.ts";
20 import { pin } from "../src/core/pins.ts";
21 import { getRepo } from "../src/core/repos.ts";
22 import { createUser, type User } from "../src/core/users.ts";
23 import { buildApiRouter, buildRouter, serve, type Servers } from "../src/http/server.ts";
24 import { quietLogs } from "./helpers/globals.ts";
25 import { promote } from "./helpers/members.ts";
26 import { proveAll } from "./helpers/verified.ts";
27 import { pageWork, type PageWork } from "./helpers/work.ts";
28
29 quietLogs();
30
31 /** Statements and git processes one warm page may cost unless listed below. */
32 const DEFAULT = { statements: 60, git: 8 };
33 /** Pages that cost more today, with the most they may: lower these, never raise them. */
34 const HEAVIER: Record<string, { statements?: number; git?: number }> = {
35 "/:owner/:name/issues/:number": { statements: 70 },
36 "/:owner/:name/next": { statements: 64 },
37 "/:owner/:name/pulls/:number": { statements: 106 },
38 "/admin/limits": { statements: 80 },
39 "/board": { statements: 64 },
40 "/settings/capacity": { statements: 65 },
41 };
42
43 /** Patterns with no fixture today: lower this as fixtures are added, never raise it silently. */
44 const MAX_UNFIXTURED = 144;
45
46 /** Streams and live fragments: no page. */
47 const NOT_PAGES = new Set([
48 "/events", "/system/stream", "/settings/teams/stream", "/fleet/graph/live",
49 "/settings/traffic/scrapes/export", "/settings/backups/live", "/:owner/:name/stream",
50 ]);
51
52 /** Patterns with an id in them, and the path the fixture fills them with. */
junipercrew outdated

Regex on source text is fragile. Compare against the router's GET patterns in a test.
53 const FIXTURE: Record<string, string> = {
54 "/:owner/:name/issues/:number": "/alice/forge/issues/1",
55 "/:owner/:name/pulls/:number": "/alice/forge/pulls/2",
56 "/:owner/:name/display": "/alice/forge/display",
57 };
58
59 function registeredGets(): Set<string> {
60 const found = new Set<string>();
61 for (const router of [buildRouter(), buildApiRouter()])
62 for (const r of router.routes()) if (r.method === "GET") found.add(r.pattern);
63 return found;
64 }
65
66 /** Every GET pattern the routers hold, split into walked paths and patterns with no fixture. */
67 export function plan(): { walked: Array<[pattern: string, path: string]>; unfixtured: string[] } {
68 const walked: Array<[string, string]> = [];
69 const unfixtured: string[] = [];
70 for (const p of [...registeredGets()].sort()) {
71 if (NOT_PAGES.has(p) || p.startsWith("/assets/") || p.endsWith("/live") || p.includes("/__forge/")) continue;
72 const path = FIXTURE[p] ?? p.replace(":owner", "alice").replace(":name", "forge");
73 if (path.includes(":") || path.includes("*")) unfixtured.push(p);
74 else walked.push([p, path]);
75 }
76 return { walked, unfixtured };
77 }
78
79 /** The findings for one page's measured work: each names the route and its slowest phase. */
80 export function judge(pattern: string, w: PageWork): string[] {
81 const max = { ...DEFAULT, ...HEAVIER[pattern] };
82 const slowest = w.phases[0] === undefined ? "no phases" : `slowest phase ${w.phases[0].name} ${w.phases[0].ms.toFixed(1)} ms`;
83 const out: string[] = [];
84 if (w.statements > max.statements) out.push(`${pattern}: ${w.statements} SQL statements, budget ${max.statements} (${slowest})`);
85 if (w.git > max.git) out.push(`${pattern}: ${w.git} git processes, budget ${max.git} (${slowest})`);
86 return out;
87 }
88
89 let root = "";
90 let app: App;
91 let servers: Servers;
92 let cookie = "";
93
94 async function user(name: string, first: boolean): Promise<User> {
95 const u = await createUser(app.db, {
96 origin: "seed", trusted: true, username: name, email: `${name}@forge.local`,
97 password: "a-good-passphrase", adminIfFirst: first,
98 });
99 if (!u.ok) throw new Error(u.error);
100 promote(app.db, u.value);
101 return u.value;
102 }
103
104 beforeAll(async () => {
105 root = mkdtempSync(join(tmpdir(), "forge-pages-budget-"));
106 app = createApp({ dataDir: root, port: 0, forgeRepo: "alice/forge" });
107 const alice = await user("alice", true);
108 const bob = await user("bob", false);
109 await user("carol", false);
110 proveAll(app);
111 for (const [who, name, visibility] of [
112 [alice, "forge", "public"], [alice, "vault", "private"], [bob, "notes", "public"], [bob, "diary", "private"],
113 ] as const) {
114 const made = await createRepo(app, who, { name, visibility });
115 if (!made.ok) throw new Error(String(made.error));
116 }
117 const forge = getRepo(app.db, "alice", "forge")!;
118 const files = await commitToBranch(app, alice, forge, {
119 message: "display",
120 files: [
121 { path: "README.md", content: "# forge\n" },
122 { path: "display.json", content: JSON.stringify({ title: "Night", layout: "grid", sources: ["alice/forge"] }) },
123 ],
124 });
125 if (!files.ok) throw new Error(JSON.stringify(files.error));
126 pin(app.db, alice.id, forge.id);
127 pin(app.db, alice.id, getRepo(app.db, "bob", "notes")!.id);
128 const issue = createIssue(app.db, { repoId: forge.id, authorId: bob.id, title: "An issue", body: "body" });
129 if (!issue.ok) throw new Error(issue.error);
130 const pull = createIssue(app.db, { repoId: forge.id, authorId: bob.id, title: "A pull", body: "body", kind: "pull" });
131 if (!pull.ok) throw new Error(pull.error);
132 app.db.run("INSERT INTO pull (issue_id, base_branch, head_branch, base_oid, head_oid) VALUES (?1, 'main', 'topic', '', 'h')", [pull.value.id]);
133 servers = await serve(app);
134 const signin = await fetch(`${servers.url}/signin`, {
135 method: "POST",
136 headers: { origin: servers.url },
137 body: new URLSearchParams({ username: "alice", password: "a-good-passphrase" }),
138 redirect: "manual",
139 });
140 cookie = (signin.headers.get("set-cookie") ?? "").split(";")[0]!;
141 }, 60_000);
142 afterAll(() => {
143 servers.stop();
144 app.close();
145 rmSync(root, { recursive: true, force: true });
146 });
junipercrew outdated

Too slow for a pull's check: cold fetch plus 2 measured runs per page. Drop to one warm run, or restrict to reachable pages.
147
148 test("every GET page is within its counted work, warm, naming its slowest phase", async () => {
149 const { walked, unfixtured } = plan();
150 expect(walked.length).toBeGreaterThan(20);
151 const findings: string[] = [];
152 const table: string[] = [];
153 const init = { headers: { cookie }, redirect: "manual" as const };
154 for (const [pattern, path] of walked) {
155 let w = await pageWork(app.db, `${servers.url}${path}`, init);
156 // A page over budget is measured twice more: stray background work raises a count once, an N+1 every time.
157 for (let again = 0; again < 2 && judge(pattern, w).length > 0; again++) {
158 const next = await pageWork(app.db, `${servers.url}${path}`, init);
159 if (next.statements + next.git < w.statements + w.git) w = next;
160 }
161 if (w.status >= 500) findings.push(`${pattern}: answered ${w.status}`);
162 if (w.status >= 300) continue; // a redirect is not a page (see server-timing-sweep)
163 const top = w.phases[0];
164 table.push(`${pattern}\t${w.statements} sql\t${w.git} git\t${w.ms.toFixed(1)} ms\t${top ? `${top.name} ${top.ms.toFixed(1)}` : "-"}`);
165 findings.push(...judge(pattern, w));
166 }
167 console.log(`pages walked warm (route, statements, git, clock, slowest phase):\n${table.join("\n")}`);
168 console.log(`no fixture, not walked (${unfixtured.length}):\n${unfixtured.join("\n")}`);
169 expect(findings).toEqual([]);
170 }, 300_000);
171
172 test("a page over its counted work is named with its route and slowest phase", () => {
173 const w: PageWork = { status: 200, statements: 99, git: 20, ms: 400, phases: [{ name: "git", ms: 300 }, { name: "render", ms: 5 }] };
174 expect(judge("/x", w)).toEqual([
175 "/x: 99 SQL statements, budget 60 (slowest phase git 300.0 ms)",
176 "/x: 20 git processes, budget 8 (slowest phase git 300.0 ms)",
177 ]);
178 expect(judge("/x", { ...w, statements: 3, git: 0, ms: 5 })).toEqual([]);
179 });
180
181 test("a route the fixture cannot fill is listed, not skipped silently", () => {
182 const { walked, unfixtured } = plan();
183 expect(unfixtured.length).toBeGreaterThan(0);
184 expect(unfixtured.length).toBeLessThanOrEqual(MAX_UNFIXTURED);
185 expect(unfixtured.every((p) => p.includes(":") || p.includes("*"))).toBe(true);
186 expect(walked.some(([p]) => p === "/:owner/:name/issues/:number")).toBe(true);
187 });

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs