trevato/forge

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

More
Forks1g fMapg aRuns12g rEventsFlows

A stranger reading an app sees only the app's own Server-Timing; the forge's entries (forge-lag, forge-route and the rest) go to the app's writers #11113

Merged masoncrew opened this

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

ConversationFiles
Merged

mason/forge:mason/11112-a-stranger-reading-an-app-sees-only-the → main 3 commits fork

  • Merged. mason/11112-a-stranger-reading-an-app-sees-only-the was merged into main as a503e14.

Review

Sign in to review this change.
7 files changed +133 −24
src/apps/proxy.ts +43 −8
@@ -424,8 +424,8 @@ function sealedPull(runtime: AppsRuntime, target: AppTarget): Issue | undefined
424424
425425 /**
426426 * The response with the phases the request named, as `Server-Timing`: the
427 * one writer for the proxy, on the forge's own `/__forge/*` pages and on a
428 * relayed app answer alike. It appends, so an app's own entries stay first;
427 * one writer for the proxy, on the forge's own `/__forge/*` pages and, for
428 * a reader who may see them (`relayAnswer`), on a relayed app answer. It appends, so an app's own entries stay first;
429429 * on an app answer the forge's phases are `forge-` named (`relayPhase`) so
430430 * none can collide with the app's or with the server's `route`.
431431 */
@@ -447,6 +447,40 @@ function withPhases(request: Request, res: Response): Response {
447447 return res;
448448 }
449449
450 /**
451 * A relayed app answer, with the forge's phases only for a reader who may
452 * see them (#11112): someone who may write the app's repository, or a forge
453 * admin. Everyone else gets the app's own Server-Timing exactly as it came;
454 * how loaded the forge is and how long its lookups take are not a
455 * stranger's to read. The app's speed card and /system read the same
456 * numbers on the server side (`noteRelayWait`, the loop watch), never here.
457 */
458 function relayAnswer(request: Request, res: Response): Response {
459 if (forgeReaders.has(request)) return withPhases(request, res);
460 takePhases(request);
461 stallFor.delete(request);
462 return res;
463 }
464
465 /** The requests whose reader is told the forge's phases (`relayAnswer`). */
466 const forgeReaders = new WeakSet<Request>();
467
468 /**
469 * Whether the grant names someone told the forge's phases on this app: an
470 * active person or agent who may write its repository, or a forge admin.
471 * A visitor with no grant is never asked about, so a stranger costs no read.
472 */
473 function readsForgeTiming(runtime: AppsRuntime, target: AppTarget, who: GrantWho | undefined): boolean {
474 if (who === undefined) return false;
475 const db = runtime.app.db;
476 const viewer = getUserById(db, who.id);
477 if (viewer === undefined || !isActive(viewer)) return false;
478 // A forge admin, as `forgeAdmin` reads one: an agent never is.
479 if (viewer.isAdmin && viewer.kind !== "agent") return true;
480 const repo = getRepoById(db, target.app.repoId);
481 return repo !== undefined && canWrite(db, repo, viewer);
482 }
483
450484 /**
451485 * The forge's phases of relaying an app answer, `forge-` named. Durations
452486 * only, under these fixed names: `route` is `lookup` + `state` + `session`.
@@ -1179,6 +1213,7 @@ export async function proxyApp(
11791213 : admitted.error;
11801214 const { status, port, grant: vouched } = admitted.value;
11811215 runtime.touch(target.app, target.env);
1216 if (readsForgeTiming(runtime, target, vouched?.who)) forgeReaders.add(request);
11821217 const began = performance.now();
11831218 // `route` split where it goes: the server finding the app (`lookup`), the
11841219 // doors and the environment's state (`state`), the grant read (`session`).
@@ -1259,7 +1294,7 @@ export async function proxyApp(
12591294 } catch {
12601295 answered();
12611296 relayUpstream(runtime, request, target, performance.now() - sent, vouched?.who);
1262 return withPhases(request, unavailable(runtime, target, status, "the app stopped answering"));
1297 return relayAnswer(request, unavailable(runtime, target, status, "the app stopped answering"));
12631298 }
12641299 relayUpstream(runtime, request, target, performance.now() - sent, vouched?.who);
12651300 const out = new Headers(response.headers);
@@ -1302,7 +1337,7 @@ export async function proxyApp(
13021337 // past that it goes on as it came, what was read first.
13031338 const read = await readPage(response.body);
13041339 if (!read.whole)
1305 return withPhases(
1340 return relayAnswer(
13061341 request,
13071342 new Response(read.rest, {
13081343 status: response.status,
@@ -1314,7 +1349,7 @@ export async function proxyApp(
13141349 }
13151350 relayPhase(request, "body", performance.now() - rewriting);
13161351 } catch {
1317 return withPhases(request, unavailable(runtime, target, status, "the app stopped answering"));
1352 return relayAnswer(request, unavailable(runtime, target, status, "the app stopped answering"));
13181353 }
13191354 // A signed-in person's page load gets the panel's one-use proof, and so
13201355 // is theirs alone: never stored or shared. A page the app's own script
@@ -1369,11 +1404,11 @@ export async function proxyApp(
13691404 out.delete("content-length");
13701405 out.delete("content-encoding");
13711406 relayPhase(request, "rewrite", performance.now() - rewriting);
1372 return withPhases(request, new Response(null, { status: 304, headers: out }));
1407 return relayAnswer(request, new Response(null, { status: 304, headers: out }));
13731408 }
13741409 }
13751410 relayPhase(request, "rewrite", performance.now() - rewriting);
1376 return withPhases(
1411 return relayAnswer(
13771412 request,
13781413 new Response(sent, {
13791414 status: response.status,
@@ -1382,7 +1417,7 @@ export async function proxyApp(
13821417 }),
13831418 );
13841419 }
1385 return withPhases(
1420 return relayAnswer(
13861421 request,
13871422 new Response(body, {
13881423 status: response.status,
src/apps/relay_wait.ts +4
@@ -14,6 +14,10 @@
1414 * owners, on the speed card and the terminal line; a signed-in forge admin
1515 * also gets them on the relayed answer as `forge-stall` (`stallTiming`).
1616 *
17 * Every reading here is taken on the server side, whoever asked: the
18 * relayed answer's `forge-*` entries go only to the app's writers and the
19 * forge's admins (#11112), and nothing here reads them back from a header.
20 *
1721 * Process memory, not the database: one O(1) compare per relay, at most
1822 * `KEEP_APPS` apps (the oldest reading goes first), gone on restart. The
1923 * stalls are read only when the forge waited, and at most `HELD_NAMES` kept.
src/http/server.ts +4 −2
@@ -2456,8 +2456,10 @@ export async function serve(app: App): Promise<Servers> {
24562456 finishedStrangerDeep(owner, request);
24572457 try {
24582458 const header = serverTiming(ms, takeDbTime(request), takePhases(request));
2459 // `lag` is the loop's, not this request's: kept out of the record's phases.
2460 response.headers.set("server-timing", withLag(header, currentLoopLag()));
2459 // `lag` is the loop's, not this request's: kept out of the record's
2460 // phases, and told only to an admin (#11112): how loaded the forge is
2461 // is not a stranger's to read. /system reads it server-side.
2462 response.headers.set("server-timing", tag.role === "admin" ? withLag(header, currentLoopLag()) : header);
24612463 const end = performance.now();
24622464 const family = familyOf(request.headers.get("user-agent") ?? "");
24632465 perfRecord.add(
test/apps-proxy-timing.test.ts +51 −4
@@ -1,6 +1,8 @@
11 /**
2 * A proxied answer keeps the app's Server-Timing and appends the forge's own
3 * phases, `forge-` named: where a slow request spent its time.
2 * A proxied answer keeps the app's Server-Timing and, for a reader who may
3 * write the app's repository, appends the forge's own phases, `forge-`
4 * named: where a slow request spent its time. Anyone else gets the app's
5 * own entries untouched (#11112).
46 */
57 import { afterAll, beforeAll, describe, expect, test } from "bun:test";
68 import { mkdtemp, rm } from "node:fs/promises";
@@ -9,6 +11,8 @@ import { join } from "node:path";
911 import { createApp, type App } from "../src/app.ts";
1012 import { AppsRuntime, type EnvStatus } from "../src/apps/runtime.ts";
1113 import { appVisitors, newApp } from "../src/actions/apps.ts";
14 import { signGrant } from "../src/apps/proxy.ts";
15 import { getAppByRepo } from "../src/core/apps.ts";
1216 import { clearRelayWaits } from "../src/apps/relay_wait.ts";
1317 import { visitorsLine } from "../src/apps/vitals.ts";
1418 import { commitToBranch } from "../src/actions/repos.ts";
@@ -59,10 +63,25 @@ describe("a proxied answer's Server-Timing", () => {
5963 let servers: Servers;
6064 let runtime: AppsRuntime;
6165 let alice: User;
66 let bob: User;
6267 let repo: Repo;
6368
64 const viaHost = (path = "/") =>
65 fetch(`${servers.url}${path}`, { headers: { host: `hello.${DOMAIN}`, accept: "text/html" }, redirect: "manual" });
69 /** A request to the app as `who` (a grant cookie), or as a visitor with none. */
70 const asViewer = (who: User | undefined, path = "/") => {
71 const headers: Record<string, string> = { host: `hello.${DOMAIN}`, accept: "text/html" };
72 if (who !== undefined) {
73 const record = getAppByRepo(app.db, repo.id)!;
74 const grant = signGrant(app.config.dataDir, { app: record, env: "production" }, 60_000, Date.now(), {
75 id: who.id,
76 name: who.username,
77 role: who.isAdmin ? "admin" : "user",
78 });
79 headers.cookie = `forge_grant_${record.id.slice(-8)}=${grant}`;
80 }
81 return fetch(`${servers.url}${path}`, { headers, redirect: "manual" });
82 };
83 /** The app's owner reading it: the one who is told the forge's phases. */
84 const viaHost = (path = "/") => asViewer(alice, path);
6685
6786 beforeAll(async () => {
6887 dataDir = await mkdtemp(join(tmpdir(), "forge-ptiming-"));
@@ -83,6 +102,13 @@ describe("a proxied answer's Server-Timing", () => {
83102 });
84103 if (!created.ok) throw new Error(created.error);
85104 alice = created.value;
105 const other = await createUser(app.db, { origin: "seed", trusted: true,
106 username: "bob",
107 email: "[email protected]",
108 password: "a-good-passphrase",
109 });
110 if (!other.ok) throw new Error(other.error);
111 bob = other.value;
86112 const made = await newApp(app, alice, { name: "hello", description: "d", visibility: "public" });
87113 if (!made.ok) throw new Error(String(made.error));
88114 repo = made.value.repo;
@@ -125,6 +151,27 @@ describe("a proxied answer's Server-Timing", () => {
125151 expect(header).not.toContain("hello");
126152 });
127153
154 test("a visitor and a signed-in reader who may not write get the app's entries untouched", async () => {
155 for (const who of [undefined, bob]) {
156 for (const path of ["/healthz", "/"]) {
157 const res = await asViewer(who, path);
158 expect(res.status).toBe(200);
159 await res.text();
160 const header = res.headers.get("server-timing");
161 // Exactly what the app wrote: no forge- entry, and none of the forge's unnamed ones.
162 expect(header).toBe(path === "/healthz" ? "db;dur=0.1, app;dur=1.1" : null);
163 }
164 }
165 });
166
167 test("the writer's copy keeps the app's entries first, as the app wrote them", async () => {
168 const header = (await viaHost("/healthz")).headers.get("server-timing")!;
169 expect(header.split(", ").slice(0, 2)).toEqual(["db;dur=0.1", "app;dur=1.1"]);
170 expect(header.split(", ").slice(2).every((e) => e.startsWith("forge-"))).toBe(true);
171 for (const name of ["forge-route", "forge-lookup", "forge-session", "forge-lag", "forge-ttfb"])
172 expect(dur(header, name)).toBeDefined();
173 });
174
128175 test("an app slow to its headers shows in forge-ttfb, which is forge-upstream", async () => {
129176 const res = await viaHost("/ttfb");
130177 expect(res.status).toBe(200);
test/loop-worst.test.ts +24 −4
@@ -1,7 +1,8 @@
11 /**
22 * The worst event-loop lag of the last 10 s (#10288): the window by hand,
3 * then a real 150 ms block seen as `lag;dur` on the next response and as
4 * `loopLagMs` on `/healthz`, and gone once the injected clock steps 10 s.
3 * then a real 150 ms block seen as `lag;dur` on an admin's next response and
4 * as `loopLagMs` on `/healthz`, and gone once the injected clock steps 10 s.
5 * A stranger's response and a signed-in non-admin's carry no `lag` (#11112).
56 */
67
78 import { afterAll, beforeAll, describe, expect, test } from "bun:test";
@@ -11,6 +12,9 @@ import { join } from "node:path";
1112 import { createApp, type App } from "../src/app.ts";
1213 import { withLag } from "../src/core/route_timing.ts";
1314 import { serve, type Servers } from "../src/http/server.ts";
15 import { createSession } from "../src/core/sessions.ts";
16 import { createUser } from "../src/core/users.ts";
17 import { adminCookie } from "./helpers/admin.ts";
1418 import { createLoopWorst, startLoopWorst, stopLoopWorst } from "../src/perf/loop_worst.ts";
1519
1620 function blockFor(ms: number): void {
@@ -82,6 +86,11 @@ describe("on every response", () => {
8286 let app: App;
8387 let servers: Servers;
8488 let skew = 0;
89 let admin: string;
90 let member: string;
91 /** A matched route (the session is read there), as the cookie's holder. */
92 const page = (cookie?: string) =>
93 fetch(`${servers.url}/nobody/nothing`, cookie === undefined ? {} : { headers: { cookie } });
8594
8695 beforeAll(async () => {
8796 dataDir = await mkdtemp(join(tmpdir(), "forge-loop-worst-"));
@@ -91,6 +100,10 @@ describe("on every response", () => {
91100 stopLoopWorst();
92101 startLoopWorst({ clock: () => performance.now() + skew, everyMs: 5 });
93102 servers = await serve(app);
103 admin = await adminCookie(app, { username: "alice", email: "[email protected]" });
104 const made = await createUser(app.db, { origin: "seed", trusted: true, username: "carol", email: "[email protected]", password: "a-good-passphrase" });
105 if (!made.ok) throw new Error(made.error);
106 member = `forge_session=${createSession(app.db, made.value.id).token}`;
94107 });
95108
96109 afterAll(async () => {
@@ -104,11 +117,18 @@ describe("on every response", () => {
104117 blockFor(150);
105118 // The overdue wake runs before this one: timers fire in due order.
106119 await new Promise((r) => setTimeout(r, 0));
107 const res = await fetch(`${servers.url}/nope`);
120 const res = await page(admin);
108121 await res.text();
109122 const header = res.headers.get("server-timing");
110123 expect(header).toContain("app;dur=");
111124 expect(lagOf(header)).toBeGreaterThanOrEqual(140);
125 // The same lag, untold to a stranger and to a signed-in non-admin.
126 for (const cookie of [undefined, member]) {
127 const other = await page(cookie);
128 await other.text();
129 expect(other.headers.get("server-timing")).toContain("app;dur=");
130 expect(lagOf(other.headers.get("server-timing"))).toBeNull();
131 }
112132
113133 const health = await fetch(`${servers.url}/healthz`, { headers: { accept: "application/json" } });
114134 const body = (await health.json()) as { ok: boolean; loopLagMs: number };
@@ -121,7 +141,7 @@ describe("on every response", () => {
121141 stopLoopWorst();
122142 startLoopWorst({ clock: () => performance.now() + skew, everyMs: 60_000 });
123143 skew += 10_000;
124 const later = await fetch(`${servers.url}/nope`);
144 const later = await page(admin);
125145 await later.text();
126146 expect(lagOf(later.headers.get("server-timing"))).toBe(0);
127147 });
test/relay-stall-name.test.ts +4 −4
@@ -2,7 +2,8 @@
22 * A relayed wait the forge held says what held it (#11000): the stall's
33 * route pattern or `job:<name>`, the longest first, on the app's speed card
44 * and terminal line; a signed-in forge admin also gets `forge-stall` on the
5 * relayed answer, and nobody else does.
5 * relayed answer, and nobody else does: a visitor and a reader who may not
6 * write the app get no `forge-` entry at all (#11112).
67 */
78 import { afterAll, beforeAll, beforeEach, describe, expect, test } from "bun:test";
89 import { mkdtemp, rm } from "node:fs/promises";
@@ -199,9 +200,8 @@ describe("forge-stall on the relayed answer", () => {
199200 const res = await asViewer(who);
200201 expect(res.status).toBe(200);
201202 const header = res.headers.get("server-timing") ?? "";
202 // The wait was the forge's (forge-lag is there) but the stall is not told.
203 expect(header).toContain("forge-lag;dur=");
204 expect(header).not.toContain("forge-stall");
203 // The wait was the forge's, but neither it nor the stall is told (#11112).
204 expect(header).not.toContain("forge-");
205205 expect(header).not.toContain("job:");
206206 }
207207 }
test/route-timing.test.ts +3 −2
@@ -46,8 +46,9 @@ test("a response carries Server-Timing, and /alice/x and /bob/y share one route
4646 const a = await fetch(`${servers.url}/alice/x`);
4747 await fetch(`${servers.url}/bob/y`);
4848 const health = await fetch(`${servers.url}/healthz`);
49 expect(a.headers.get("server-timing")).toMatch(/^app;dur=\d+\.\d, lag;dur=\d+\.\d$/);
50 expect(health.headers.get("server-timing")).toMatch(/^db;dur=\d+\.\d, app;dur=\d+\.\d, lag;dur=\d+\.\d$/);
49 // A stranger reads no `lag`: how loaded the forge is is an admin's to know (#11112).
50 expect(a.headers.get("server-timing")).toMatch(/^app;dur=\d+\.\d$/);
51 expect(health.headers.get("server-timing")).toMatch(/^db;dur=\d+\.\d, app;dur=\d+\.\d$/);
5152 servers.stop();
5253
5354 const rows = readTiming(app.db, "");

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs