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

Real-user page timings roll up per page on the ops view, one line per page over budget #10580

Merged opened this

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

Merged

scout/forge:scout/10536-real-user-page-timings-roll-up-per-page → main 3 commits fork 2 threads · 2 unresolved

  • Merged. scout/10536-real-user-page-timings-roll-up-per-page was merged into main as 6719f51.

Review

Sign in to review this change.
10 files changed +286 −3
docs/features/slow-pages.md added +5
@@ -0,0 +1,5 @@
1 # Pages over budget (real visitors)
2
3 The page beacon's reports (`page_vital`) roll up per route pattern over the last hour: p95 time to first byte (server) and p95 largest paint. A page with at least 10 reports that misses `PAGE_BUDGET` (`src/perf/budgets.ts`: server 150 ms, first paint 1 s) gets one line on `/system` ("Pages over budget, last hour") and in the terminal's "Pages over budget" screen, naming the slowest part: the server, or the browser drawing it (first byte to first paint). When every page is fast nothing is shown: no section, no palette entry. Code: `slowPages` in `src/perf/watch.ts`.
4
5 The look is bounded: at most 50 routes, the newest 500 reports of each, and `/system` keeps the result 5 seconds. The section is not live; it changes on reload.
src/perf/budgets.ts +3
@@ -42,3 +42,6 @@ export const HEAVY_GIT_BUDGET: Budget = { pattern: "git *", words: "a pack-movin
4242 export function gitBudgetFor(key: string): Budget {
4343 return HEAVY_GIT.has(key.slice(4)) ? HEAVY_GIT_BUDGET : GIT_BUDGET;
4444 }
45
46 /** What a real visitor's page is held to (#10536): the browser's time to first byte at p95, and its largest paint at p95. */
47 export const PAGE_BUDGET = { serverP95Ms: 150, paintP95Ms: 1000 } as const;
src/perf/day.ts added +2
@@ -0,0 +1,2 @@
1 /** The UTC day key (`YYYY-MM-DD`) that timing rows are filed under; shared by the web and perf layers. */
2 export const dayOf = (at: number): string => new Date(at).toISOString().slice(0, 10);
src/perf/watch.ts +64 −2
@@ -6,8 +6,10 @@
66 */
77
88 import { found, type Finding } from "../hunt/finding.ts";
9 import { budgetFor, gitBudgetFor } from "./budgets.ts";
10 import { summarize, WINDOW_MS, type PerfRecord } from "./record.ts";
9 import type { Database } from "bun:sqlite";
10 import { dayOf } from "./day.ts";
outdated

perf importing from web/measure.ts inverts the layering; move dayOf somewhere shared.

11 import { budgetFor, gitBudgetFor, PAGE_BUDGET } from "./budgets.ts";
12 import { percentile, summarize, WINDOW_MS, type PerfRecord } from "./record.ts";
1113
1214 export { WINDOW_MS };
1315 export const MIN_REQUESTS = 20;
@@ -88,3 +90,63 @@ export function fresh(findings: readonly Finding[], filed: Set<string>): Finding
8890 for (const f of out) filed.add(f.key);
8991 return out;
9092 }
93
94 /** The window real-user timings roll up over, and the fewest reports a page needs to be judged. */
95 export const PAGE_WINDOW_MS = 60 * 60 * 1000;
96 export const PAGE_MIN_REPORTS = 10;
97 /** The most routes judged, and the newest reports read for each: the cost of a look is bounded. */
98 export const PAGE_ROUTES = 50;
99 export const PAGE_SAMPLE = 500;
100
101 export interface SlowPage {
102 readonly route: string;
103 readonly reports: number;
104 readonly serverP95: number;
105 readonly paintP95: number | null;
106 /** `server` when time to first byte is most of the wait, else `render` (first byte to first paint). */
107 readonly phase: "server" | "render";
108 }
109
110 /**
111 * The page timings browsers reported in the last hour, rolled up per route
112 * pattern: p95 server time (TTFB) and p95 first paint (LCP). Only routes that
113 * miss `PAGE_BUDGET` come back, the worst first; every page fast is `[]`.
114 */
115 export function slowPages(db: Database, now: number): SlowPage[] {
116 const since = now - PAGE_WINDOW_MS;
117 const day = dayOf(since);
118 // Bounded work: count per route in SQL, judge only the busiest routes, and read
119 // at most the newest PAGE_SAMPLE reports of each, never the whole hour.
120 const routes = db
121 .query<{ route: string; n: number }, [string, number, number, number]>(
122 "SELECT route, COUNT(*) AS n FROM page_vital WHERE day >= ?1 AND at >= ?2 GROUP BY route HAVING n >= ?3 ORDER BY n DESC LIMIT ?4",
123 )
124 .all(day, since, PAGE_MIN_REPORTS, PAGE_ROUTES);
125 const sample = db.query<{ ttfb: number | null; lcp: number | null }, [string, number, string, number]>(
126 "SELECT ttfb, lcp FROM page_vital WHERE day >= ?1 AND at >= ?2 AND route = ?3 ORDER BY at DESC LIMIT ?4",
127 );
128 const byRoute = new Map<string, { ttfb: number[]; lcp: number[]; n: number }>();
129 for (const { route, n } of routes) {
130 const e = { ttfb: [] as number[], lcp: [] as number[], n };
131 for (const r of sample.all(day, since, route, PAGE_SAMPLE)) {
132 if (r.ttfb !== null) e.ttfb.push(r.ttfb);
133 if (r.lcp !== null) e.lcp.push(r.lcp);
134 }
135 byRoute.set(route, e);
136 }
137 const out: SlowPage[] = [];
138 for (const [route, e] of byRoute) {
139 if (e.n < PAGE_MIN_REPORTS) continue;
140 const server = percentile(e.ttfb, 95) ?? 0;
141 const paint = percentile(e.lcp, 95);
142 if (server <= PAGE_BUDGET.serverP95Ms && (paint === null || paint <= PAGE_BUDGET.paintP95Ms)) continue;
143 out.push({ route, reports: e.n, serverP95: server, paintP95: paint, phase: paint !== null && paint - server > server ? "render" : "server" });
144 }
145 return out.sort((a, b) => b.serverP95 + (b.paintP95 ?? 0) - (a.serverP95 + (a.paintP95 ?? 0)));
146 }
147
148 /** One line per slow page, in the words both the page and the terminal use. */
149 export function slowPageLine(p: SlowPage): string {
150 const paint = p.paintP95 === null ? "" : `, first paint ${Math.round(p.paintP95)} ms (budget ${PAGE_BUDGET.paintP95Ms})`;
151 return `${p.route}: server ${Math.round(p.serverP95)} ms (budget ${PAGE_BUDGET.serverP95Ms})${paint}; slowest part: ${p.phase === "server" ? "the server" : "the browser drawing it"}`;
152 }
src/tui/screens/entries.ts +2
@@ -38,6 +38,7 @@ import { entry as invites } from "./invites.ts";
3838 import { entry as limits } from "./limits.ts";
3939 import { entry as economics } from "./economics.ts";
4040 import { entry as loopStalls } from "./loopstalls.ts";
41 import { entry as slowPagesEntry } from "./slowpages.ts";
4142 import { entry as maintenance } from "./maintenance.ts";
4243 import { modelCeilingEntry, modelGrantEntry } from "./model.ts";
4344 import { entry as orgGrants } from "./orggrants.ts";
@@ -87,6 +88,7 @@ export const ENTRIES: readonly PaletteEntry[] = [
8788 homePins,
8889 system,
8990 loopStalls,
91 slowPagesEntry,
9092 telemetry,
9193 resilience,
9294 maintenance,
src/tui/screens/slowpages.ts added +54
@@ -0,0 +1,54 @@
1 /**
2 * Pages over their real-visitor budget, the owner's (#10536): one line per
3 * page whose p95 server time or first paint, as browsers reported them in the
4 * last hour, misses `PAGE_BUDGET` — the lines `/system` shows. Gate is
5 * `/system`'s: a forge admin who is a person. The palette offers it only when
6 * a page is over, so a fast forge has nothing here. Read-only.
7 */
8
9 import type { Database } from "bun:sqlite";
10 import { slowPageLine, slowPages } from "../../perf/watch.ts";
11 import type { Ctx, Screen } from "../app/app.ts";
12 import { binding } from "../app/keys.ts";
13 import type { Session } from "../session.ts";
14 import { style } from "../term/style.ts";
15 import { Scroll, drawLines, hitScroll } from "./common.ts";
16 import type { PaletteEntry } from "./entries.ts";
17
18 const mayRead = (session: Session): boolean => session.user?.isAdmin === true && session.user.kind !== "agent";
19
20 /** A line per slow page; empty for anyone the gate refuses and when every page is fast. */
21 export function slowPageLines(session: Session, db: Database = session.app.db, now = Date.now()): string[] {
22 return mayRead(session) ? slowPages(db, now).map(slowPageLine) : [];
23 }
24
25 export function slowPagesScreen(session: Session, ctx: Ctx): Screen {
26 const scroll = new Scroll();
27 return {
28 title: "Pages over budget",
29 keys: [binding(["j", "k"], "scroll"), binding(["esc", "q"], "back")],
30 render(area, s) {
31 const c = ctx.theme.c;
32 const lines = slowPageLines(session);
33 drawLines(s, area, c, scroll, lines.map((text) => [{ text, style: style(c.fg, c.bg) }]));
34 hitScroll(ctx, area, scroll, lines.length);
35 },
36 key(e) {
37 if (scroll.key(e, slowPageLines(session).length)) return true;
38 if (e.key === "esc" || e.key === "q") {
39 ctx.pop();
40 return true;
41 }
42 return false;
43 },
44 };
45 }
46
47 export const entry: PaletteEntry = {
48 id: "slow-pages",
49 title: "Pages over budget",
50 hint: "real visitors' slow pages, last hour",
51 after: ["stalls", "system"],

offered and the screen are untested; add a test that fails without them.

52 offered: (session) => slowPageLines(session).length > 0,
53 run: (session, ctx) => ctx.push(slowPagesScreen(session, ctx)),
54 };
src/web/measure.ts +2 −1
@@ -15,6 +15,7 @@
1515 import type { Database } from "bun:sqlite";
1616 import { quietly } from "../core/write_clock.ts";
1717 import { sha256 } from "../kernel/hash.ts";
18 import { dayOf } from "../perf/day.ts";
1819
1920 /** A report is a few dozen bytes; this is already generous. */
2021 export const REPORT_MAX = 512;
@@ -108,7 +109,7 @@ export function optedOut(request: Request): boolean {
108109 return cookie.split(";").some((pair) => pair.trim() === "forge_measure=off");
109110 }
110111
111 export const dayOf = (at: number): string => new Date(at).toISOString().slice(0, 10);
112 export { dayOf };
112113
113114 /** Today's salt, made on first use; every other day's is deleted. */
114115 export function saltFor(db: Database, at: number): string {
src/web/pages/system.ts +19
@@ -25,6 +25,7 @@ import { eventStream } from "../../http/sse.ts";
2525 import type { SystemView } from "../../system/view.ts";
2626 import { live } from "../../system/live.ts";
2727 import { readerPaces, type ReaderPace } from "../../system/telemetry_reads.ts";
28 import { slowPageLine, slowPages, type SlowPage } from "../../perf/watch.ts";
2829 import { stallHour } from "../../metrics/stalls.ts";
2930 import type { RouteStall } from "../../perf/loop.ts";
3031 import { loopWatch } from "../../perf/live.ts";
@@ -162,6 +163,23 @@ export function stallSection(rows: readonly RouteStall[]): Html {
162163 </table></div>`}</section>`;
163164 }
164165
166 const SLOW_TTL_MS = 5000;
167 let slowKept: { db: object; at: number; rows: SlowPage[] } | undefined;
168 /** `slowPages`, kept a few seconds so a busy /system never repeats the query; changes show on reload. */
169 function slowPagesCached(db: Parameters<typeof slowPages>[0]): SlowPage[] {
170 const now = Date.now();
171 if (slowKept === undefined || slowKept.db !== db || now - slowKept.at > SLOW_TTL_MS)
172 slowKept = { db, at: now, rows: slowPages(db, now) };
173 return slowKept.rows;
174 }
175
176 /** Real visitors' pages over budget (#10536): one line each, and nothing at all when every page is fast. */
177 export function slowPagesSection(rows: readonly SlowPage[]): Html {
178 if (rows.length === 0) return html``;
179 return html`<section class="settings-block" id="slow-pages"><h2>Pages over budget, last hour</h2>
180 <ul class="list" aria-label="Pages over their budget for real visitors">${rows.map((p) => html`<li data-route="${p.route}" data-phase="${p.phase}">${slowPageLine(p)}</li>`)}</ul></section>`;
181 }
182
165183 /** Who read the telemetry routes in the last 10 minutes and how fast (#9069); `readerPaces`' rows. */
166184 export function readersSection(rows: readonly ReaderPace[]): Html {
167185 const secs = (ms: number | null): string => (ms === null ? "—" : `${(ms / 1000).toFixed(1)} s`);
@@ -273,6 +291,7 @@ export function systemPage(ctx: Ctx): Response {
273291 <div id="sys-procs">${at("sys-procs")}</div></section>
274292 ${featuresSection(timePhase(ctx.request, "features", () => featureHealth(ctx.app, reader)))}
275293 <div id="sys-stalls">${stallSection(stalls)}</div>
294 <div id="sys-slow-pages">${slowPagesSection(timePhase(ctx.request, "slowpages", () => slowPagesCached(ctx.app.db)))}</div>
276295 <div id="sys-readers">${readersSection(readerPaces())}</div>
277296 <div id="sys-caches">${cachesSection(pageCaches())}</div>
278297 ${memory}`;
test/slow-pages-tui.test.ts added +62
@@ -0,0 +1,62 @@
1 /** The terminal's "Pages over budget": palette entry offered only to an admin when a page is slow, and the screen shows the lines (#10536). */
2 import { afterAll, beforeAll, expect, test } from "bun:test";
3 import { mkdtemp, rm } from "node:fs/promises";
4 import { tmpdir } from "node:os";
5 import { join } from "node:path";
6 import { createApp, type App } from "../src/app.ts";
7 import { createUser, type User } from "../src/core/users.ts";
8 import { Session } from "../src/tui/forge.ts";
9 import type { Ctx, Screen } from "../src/tui/app/app.ts";
10 import { entry } from "../src/tui/screens/slowpages.ts";
11 import { Screen as Surface } from "../src/tui/term/screen.ts";
12 import { theme } from "../src/tui/ui/theme.ts";
13 import { recordVital } from "../src/web/measure.ts";
14 import { quietLogs } from "./helpers/globals.ts";
15
16 quietLogs();
17
18 let dir: string;
19 let app: App;
20 let alice: User;
21 let bob: User;
22 const id = (user?: User) => ({ sshUsername: user?.username ?? "git", remoteAddress: "127.0.0.1", fingerprint: "SHA256:test", user });
23
24 beforeAll(async () => {
25 dir = await mkdtemp(join(tmpdir(), "slow-pages-tui-"));
26 app = createApp({ dataDir: dir, port: 0 });
27 const a = await createUser(app.db, { origin: "seed", trusted: true, username: "alice", email: "[email protected]", password: "a-good-passphrase", adminIfFirst: true });
28 const b = await createUser(app.db, { origin: "seed", trusted: true, username: "bob", email: "[email protected]", password: "a-good-passphrase" });
29 if (!a.ok || !b.ok) throw new Error("users");
30 alice = a.value;
31 bob = b.value;
32 });
33 afterAll(async () => {
34 app.close();
35 await rm(dir, { recursive: true, force: true });
36 });
37
38 const feed = (route: string, ttfb: number) => {
39 for (let i = 0; i < 12; i++) recordVital(app.db, { path: "/", ttfb, load: null, lcp: 500, inp: null, cls: 0 }, route, `c${i}`, "ua", Date.now() - 1000);
40 };
41
42 test("no palette entry on a fast forge; offered to an admin once a page is slow, never to others", async () => {
43 feed("/fast", 40);
44 expect(entry.offered(new Session(app, id(alice)))).toBe(false);
45 feed("/slow-one", 500);
46 expect(entry.offered(new Session(app, id(alice)))).toBe(true);
47 expect(entry.offered(new Session(app, id(bob)))).toBe(false);
48 expect(entry.offered(new Session(app, id()))).toBe(false);
49 });
50
51 test("running the entry pushes a screen that draws the slow page's line", () => {
52 const pushed: Screen[] = [];
53 const ctx = { theme: theme("dark"), invalidate() {}, toast() {}, push: (s: Screen) => pushed.push(s), pop() {}, copy() {}, hit() {} } as unknown as Ctx;
54 entry.run(new Session(app, id(alice)), ctx);
55 expect(pushed).toHaveLength(1);
56 const s = new Surface(110, 20);
57 pushed[0]!.render({ x: 0, y: 0, w: 110, h: 20 }, s);
58 const text = s.toText();
59 expect(text).toContain("/slow-one: server 500 ms");
60 expect(text).toContain("slowest part: the server");
61 expect(text).not.toContain("/fast");
62 });
test/slow-pages.test.ts added +73
@@ -0,0 +1,73 @@
1 /** Real-user timings roll up per page; one line per page over budget, nothing when all are fast (#10536). */
2
3 import { afterAll, beforeAll, expect, test } from "bun:test";
4 import { mkdtemp, rm } from "node:fs/promises";
5 import { tmpdir } from "node:os";
6 import { join } from "node:path";
7 import { createApp, type App } from "../src/app.ts";
8 import { createUser, type User } from "../src/core/users.ts";
9 import { slowPageLine, slowPages } from "../src/perf/watch.ts";
10 import { Session } from "../src/tui/forge.ts";
11 import { slowPageLines } from "../src/tui/screens/slowpages.ts";
12 import { slowPagesSection } from "../src/web/pages/system.ts";
13 import { recordVital } from "../src/web/measure.ts";
14 import { quietLogs } from "./helpers/globals.ts";
15
16 quietLogs();
17
18 let dir: string;
19 let app: App;
20 let alice: User;
21 let bob: User;
22 const NOW = Date.parse("2026-11-10T12:00:00Z");
23
24 beforeAll(async () => {
25 dir = await mkdtemp(join(tmpdir(), "slow-pages-"));
26 app = createApp({ dataDir: dir, port: 0 });
27 const a = await createUser(app.db, { origin: "seed", trusted: true, username: "alice", email: "[email protected]", password: "a-good-passphrase", adminIfFirst: true });
28 const b = await createUser(app.db, { origin: "seed", trusted: true, username: "bob", email: "[email protected]", password: "a-good-passphrase" });
29 if (!a.ok || !b.ok) throw new Error("users");
30 alice = a.value;
31 bob = b.value;
32 });
33 afterAll(async () => {
34 app.close();
35 await rm(dir, { recursive: true, force: true });
36 });
37
38 const report = (ttfb: number, lcp: number) => ({ path: "/", ttfb, load: null, lcp, inp: null, cls: 0 });
39 const feed = (route: string, n: number, ttfb: number, lcp: number, at = NOW - 60_000) => {
40 for (let i = 0; i < n; i++) recordVital(app.db, report(ttfb, lcp), route, `c${i}`, "ua", at);
41 };
42 const identity = (user?: User) => ({ sshUsername: user?.username ?? "git", remoteAddress: "127.0.0.1", fingerprint: "SHA256:test", user });
43
44 test("quiet: every page fast means no rows, no section, no terminal lines", () => {
45 feed("/fast", 12, 40, 500);
46 expect(slowPages(app.db, NOW)).toEqual([]);
47 expect(slowPagesSection([]).text).toBe("");
48 expect(slowPageLines(new Session(app, identity(alice)), app.db, NOW)).toEqual([]);
49 });
50
51 test("one line per page over budget, naming the slowest phase", () => {
52 feed("/slow-server", 12, 400, 700);
53 feed("/slow-paint", 12, 50, 3000);
54 feed("/few", 3, 900, 9000); // too few reports to judge
55 feed("/old", 12, 900, 9000, NOW - 2 * 3600_000); // outside the window
56 const rows = slowPages(app.db, NOW);
57 expect(rows.map((r) => [r.route, r.phase])).toEqual([["/slow-paint", "render"], ["/slow-server", "server"]]);
58 expect(slowPageLine(rows[1]!)).toBe("/slow-server: server 400 ms (budget 150), first paint 700 ms (budget 1000); slowest part: the server");
59 const html = slowPagesSection(rows).text;
60 expect(html.match(/<li /g)?.length).toBe(2);
61 expect(html).toContain('data-phase="render"');
62 });
63
64 test("the terminal gives an admin person the lines, nobody else", () => {
65 expect(slowPageLines(new Session(app, identity(alice)), app.db, NOW)).toHaveLength(2);
66 expect(slowPageLines(new Session(app, identity(bob)), app.db, NOW)).toEqual([]);
67 expect(slowPageLines(new Session(app, identity()), app.db, NOW)).toEqual([]);
68 });
69
70 test("a route with markup in it is escaped", () => {
71 const text = slowPagesSection([{ route: "/<b>", reports: 10, serverP95: 500, paintP95: null, phase: "server" }]).text;
72 expect(text).not.toContain("<b>");
73 });

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs