trevato/forge

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

More
Forks1g fMapg aRunsg rEventsFlows

A red Server-Timing sweep names the route that failed and why, so a one-off failure in the full suite can be diagnosed from its log #9502

Merged masoncrew opened this

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

ConversationFiles
Merged

mason/forge:mason/9500-a-red-server-timing-sweep-names-the-rout → main 1 commit fork

  • Merged. mason/9500-a-red-server-timing-sweep-names-the-rout was merged into main as cd085ec.

Review

Sign in to review this change.
2 files changed +114 −25
test/helpers/timing-sweep.ts added +72
@@ -0,0 +1,72 @@
1 /**
2 * The Server-Timing sweep's collection, as a plain function over a fetch
3 * (#9500). A worker that throws takes the whole test down with one stack and
4 * no route; this one records every page that throws, answers 5xx or leaves
5 * out `app`, so a red sweep's log names each route and why.
6 */
7
8 export type SweepFetch = (path: string, signal: AbortSignal) => Promise<Response>;
9
10 export type SweepFailure = { path: string; status: number } | { path: string; error: string };
11
12 export interface SweepResult {
13 /** HTML pages naming `session` and `render`. */
14 named: string[];
15 /** HTML pages that answer without `session` or `render`. */
16 bare: string[];
17 /** Pages that answered 3xx. */
18 redirected: string[];
19 /** Pages that threw (abort, reset) or answered 5xx. */
20 failures: SweepFailure[];
21 /** HTML pages whose Server-Timing leaves out `app`, with the header they sent. */
22 missingApp: Array<{ path: string; serverTiming: string }>;
23 }
24
25 export interface SweepOptions {
26 /** Fetches in flight at once. */
27 concurrency?: number;
28 /** Abort for one request, so a slow page fails by name, not as a test timeout. */
29 perRequestMs?: number;
30 }
31
32 export async function collectTimings(
33 paths: readonly string[],
34 fetchPage: SweepFetch,
35 { concurrency = 4, perRequestMs = 20_000 }: SweepOptions = {},
36 ): Promise<SweepResult> {
37 const result: SweepResult = { named: [], bare: [], redirected: [], failures: [], missingApp: [] };
38 const queue = [...paths];
39 const worker = async () => {
40 for (let path = queue.shift(); path !== undefined; path = queue.shift()) {
41 let res: Response;
42 try {
43 res = await fetchPage(path, AbortSignal.timeout(perRequestMs));
44 await res.arrayBuffer();
45 } catch (e) {
46 result.failures.push({ path, error: e instanceof Error ? `${e.name}: ${e.message}` : String(e) });
47 continue;
48 }
49 if (res.status >= 500) {
50 result.failures.push({ path, status: res.status });
51 continue;
52 }
53 if (res.status >= 300 && res.status < 400) {
54 result.redirected.push(path);
55 continue;
56 }
57 if (!(res.headers.get("content-type") ?? "").startsWith("text/html")) continue;
58 const serverTiming = res.headers.get("server-timing") ?? "";
59 const names = serverTiming.split(",").map((p) => p.trim().split(";")[0]);
60 if (!names.includes("app")) {
61 result.missingApp.push({ path, serverTiming });
62 continue;
63 }
64 (names.includes("session") && names.includes("render") ? result.named : result.bare).push(path);
65 }
66 };
67 await Promise.all(Array.from({ length: concurrency }, worker));
68 const byPath = (a: { path: string }, b: { path: string }) => a.path.localeCompare(b.path);
69 result.failures.sort(byPath);
70 result.missingApp.sort(byPath);
71 return result;
72 }
test/server-timing-sweep.test.ts +42 −25
@@ -15,6 +15,7 @@ import { createApp, type App } from "../src/app.ts";
1515 import { createUser } from "../src/core/users.ts";
1616 import { buildApiRouter, buildRouter, serve, type Servers } from "../src/http/server.ts";
1717 import { proveAll } from "./helpers/verified.ts";
18 import { collectTimings } from "./helpers/timing-sweep.ts";
1819 import { quietLogs } from "./helpers/globals.ts";
1920
2021 quietLogs();
@@ -110,31 +111,16 @@ test("every GET page names session and render in Server-Timing, bar the listed d
110111 const paths = sweptPatterns().map((p) => p.replace(":owner", "alice").replace(":name", "forge"));
111112 expect(paths.length).toBeGreaterThan(20);
112113
113 const named: string[] = [];
114 const bare: string[] = [];
115 const redirected: string[] = [];
116 // A few at a time with a generous abort: the verdict is about headers, not
117 // about how fast a loaded check machine answers every page at once.
118 const queue = [...paths];
119 const worker = async () => {
120 for (let path = queue.shift(); path !== undefined; path = queue.shift()) {
121 const res = await fetch(`${servers.url}${path}`, {
122 headers: { cookie },
123 redirect: "manual",
124 signal: AbortSignal.timeout(60_000),
125 });
126 await res.arrayBuffer();
127 if (res.status >= 300 && res.status < 400) {
128 redirected.push(path);
129 continue;
130 }
131 if (!(res.headers.get("content-type") ?? "").startsWith("text/html")) continue;
132 const names = (res.headers.get("server-timing") ?? "").split(",").map((p) => p.trim().split(";")[0]);
133 expect(names).toContain("app");
134 (names.includes("session") && names.includes("render") ? named : bare).push(path);
135 }
136 };
137 await Promise.all(Array.from({ length: 4 }, worker));
114 // Four at a time. Each request aborts after 20 s, well under the test's
115 // 120 s cap: a slow page then fails as a named entry in `failures` rather
116 // than as a whole-test timeout that says nothing about which route (#9500).
117 const { named, bare, redirected, failures, missingApp } = await collectTimings(
118 paths,
119 (path, signal) => fetch(`${servers.url}${path}`, { headers: { cookie }, redirect: "manual", signal }),
120 { concurrency: 4, perRequestMs: 20_000 },
121 );
122 expect(failures).toEqual([]);
123 expect(missingApp).toEqual([]);
138124
139125 const started = redirected.filter((p) => !REDIRECTS.has(p)).sort();
140126 const stopped = [...REDIRECTS].filter((p) => !redirected.includes(p)).sort();
@@ -153,3 +139,34 @@ test("the sweep reads wrapped router.add registrations, so a reformat cannot shr
153139 const registered = new Set([...buildRouter().patterns(), ...buildApiRouter().patterns()]);
154140 expect([...found].filter((p) => !registered.has(p))).toEqual([]);
155141 });
142
143 test("the sweep's collection names each page that throws, answers 5xx or leaves out app", async () => {
144 const html = (serverTiming: string) =>
145 new Response("<p>", { headers: { "content-type": "text/html", "server-timing": serverTiming } });
146 const pages: Record<string, () => Promise<Response>> = {
147 "/throws": () => Promise.reject(new Error("connection reset")),
148 "/broken": async () => new Response("no", { status: 500 }),
149 "/no-app": async () => html("session;dur=1, render;dur=2"),
150 "/named": async () => html("app;dur=3, session;dur=1, render;dur=2"),
151 "/bare": async () => html("app;dur=3"),
152 "/moved": async () => new Response(null, { status: 303, headers: { location: "/" } }),
153 };
154 const r = await collectTimings(Object.keys(pages), (path) => pages[path]!());
155 expect(r.failures).toEqual([
156 { path: "/broken", status: 500 },
157 { path: "/throws", error: "Error: connection reset" },
158 ]);
159 expect(r.missingApp).toEqual([{ path: "/no-app", serverTiming: "session;dur=1, render;dur=2" }]);
160 expect(r.named).toEqual(["/named"]);
161 expect(r.bare).toEqual(["/bare"]);
162 expect(r.redirected).toEqual(["/moved"]);
163 });
164
165 test("a page slower than the per-request abort fails by name, not as a test timeout", async () => {
166 const hang = (signal: AbortSignal) =>
167 new Promise<Response>((_, reject) => signal.addEventListener("abort", () => reject(signal.reason)));
168 const r = await collectTimings(["/slow"], (_path, signal) => hang(signal), { perRequestMs: 20 });
169 expect(r.failures).toHaveLength(1);
170 expect(r.failures[0]!.path).toBe("/slow");
171 expect("error" in r.failures[0]! && r.failures[0].error).toMatch(/Timeout/);
172 });

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs