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

The owner's `/` answers under 300 ms warm on a forge with 200 repositories and 100 open asks, every phase named #5811

Merged opened this

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

Merged

scout/forge:scout/5806-the-owner-s-answers-under-300-ms-warm-on → main 3 commits fork

  • Merged. scout/5806-the-owner-s-answers-under-300-ms-warm-on was merged into main as 11ced34.

Review

Sign in to review this change.
6 files changed +111 −8
docs/CACHING.md +15
@@ -267,6 +267,21 @@ fixture; all three caches hit):
267267 | `panels` | 0.1 | 0.1 |
268268 | `feed` | 7.1 | 10.0 |
269269
270 ### 6. The waiting line: per viewer (#5806)
271
272 - **What:** how many asks wait on the viewer and the oldest's time (the
273 `waitingOn` scan over up to 200 repositories); the words are made fresh
274 for each request.
275 - **Key:** `waiting:{viewerId}`, read for the signed-in viewer only, so no
276 one reads another's count. `waiting` in `Server-Timing` carries `desc="hit"`.
277 - **Invalidated by:** every write, through the write clock (dismissals,
278 assignments, pulls, holds), as the KPI row is.
279 - **Max age:** 30 seconds.
280 - **Measured** (`test/home-200.test.ts`: 200 repositories, 100 assigned asks,
281 owner, second look): the miss cost `waiting` 7.5 ms, the largest read after
282 `feed`; a hit is under 0.1 ms. Every phase over 20 ms is named in the
283 test's output; none is over 20 ms in the sandbox.
284
270285 ### Not cached on home
271286
272287 The anonymous door (1.5 ms, 10 statements), the app shelf, and the
src/web/studio/home.ts +2 −2
@@ -54,7 +54,7 @@ import { composer, feedJs, feedNote, feedRegion } from "./feed.ts";
5454 import { kpiRow, waitingLine } from "./kpi_row.ts";
5555 import { feedCandidateCache } from "../../feed/feed.ts";
5656 import { notePhase, notePhaseRest, takeSessionTime, timePhase, timePhaseAsync } from "../../core/route_timing.ts";
57 import { kpiCache, panelCache } from "./home_cache.ts";
57 import { kpiCache, panelCache, waitingCache } from "./home_cache.ts";
5858 import { pinnedPanels } from "./pinned.ts";
5959 import { homeTabs } from "./home_tabs.ts";
6060 import { crewKeyNote } from "./crew.ts";
@@ -259,7 +259,7 @@ export async function studioHome(
259259 ${ask} ${address} ${figures
260260 ? timePhase(ctx.request, "kpis", () => kpiRow(ctx.app.db, kpiOpts), () => kpiCache(ctx.app.db))
261261 : liveLine(ctx)}
262 ${timePhase(ctx.request, "waiting", () => waitingLine(ctx.app.db, user))}
262 ${timePhase(ctx.request, "waiting", () => waitingLine(ctx.app.db, user), () => waitingCache(ctx.app.db))}
263263 ${figures
264264 ? await timePhaseAsync(ctx.request, "panels", () => pinnedPanels(ctx.app, user), () => panelCache(ctx.app.db))
265265 : null}
src/web/studio/home_cache.ts +20
@@ -17,6 +17,13 @@ export const HOME_MAX_AGE_MS = 30_000;
1717
1818 const kpiCaches = new WeakMap<Database, Stamped<Kpis>>();
1919 const panelCaches = new WeakMap<Database, Stamped<Answer>>();
20 const waitingCaches = new WeakMap<Database, Stamped<Waiting>>();
21
22 /** What the waiting line keeps of the viewer's asks: how many, and the oldest's time. */
23 export interface Waiting {
24 readonly count: number;
25 readonly oldest: string | null;
26 }
2027
2128 function cacheOf<V>(into: WeakMap<Database, Stamped<V>>, db: Database, maxEntries: number): Stamped<V> {
2229 let cache = into.get(db);
@@ -32,6 +39,19 @@ export const kpiCache = (db: Database): Stamped<Kpis> => cacheOf(kpiCaches, db,
3239 /** The pinned-panel cache of `db`: for tests, which count its hits. */
3340 export const panelCache = (db: Database): Stamped<Answer> => cacheOf(panelCaches, db, 64);
3441
42 /** The waiting-line cache of `db`: for tests, which count its hits. */
43 export const waitingCache = (db: Database): Stamped<Waiting> => cacheOf(waitingCaches, db, 64);
44
45 /**
46 * The viewer's own asks, counted: keyed by viewer id, so no one reads another's.
47 * Valid while the write clock holds, 30 seconds at most (asks also change with time).
48 */
49 export function cachedWaiting(db: Database, viewerId: string, compute: () => Waiting): Waiting {
50 const stamp = writeStamp(db);
51 if (stamp === undefined) return compute();
52 return waitingCache(db).get(`waiting:${viewerId}`, stamp, compute);
53 }
54
3555 /** Admin only: the caller has checked. Keyed by UTC hour, ceiling and data directory. */
3656 export function cachedKpis(
3757 db: Database,
src/web/studio/kpi_row.ts +10 −5
@@ -10,7 +10,7 @@
1010 import type { Database } from "bun:sqlite";
1111 import { backupAge, backupFull, backupOverdue, buildersValue, checkTime, reactNote, speedWords, spendFull, spendValue, usersValue, visitorsNote, visitorsValue, waitingWords } from "../../flow/kpi_words.ts";
1212 import type { Kpis } from "../../flow/kpis.ts";
13 import { cachedKpis } from "./home_cache.ts";
13 import { cachedKpis, cachedWaiting } from "./home_cache.ts";
1414 import { escapeHtml, html, raw, type Html } from "../html.ts";
1515 import { BOOTED } from "../../release/gate.ts";
1616 import { running } from "../../kernel/version.ts";
@@ -169,9 +169,14 @@ export function kpiRow(db: Database, opts: { ceilingUsd?: number; dataDir?: stri
169169 * (the very rows /review lists) and how long the oldest has. Empty at zero.
170170 */
171171 export function waitingLine(db: Database, user: User, now: Date = new Date()): Html {
172 const repos = listReposVisibleTo(db, user, { limit: 200, withoutArchived: true });
173 const asks = waitingOn(db, user, repos);
174 const oldest = asks.reduce<string | null>((o, a) => (o === null || Date.parse(a.since) < Date.parse(o) ? a.since : o), null);
175 const words = waitingWords(asks.length, oldest, now);
172 const { count, oldest } = cachedWaiting(db, user.id, () => {
173 const repos = listReposVisibleTo(db, user, { limit: 200, withoutArchived: true });
174 const asks = waitingOn(db, user, repos);
175 return {
176 count: asks.length,
177 oldest: asks.reduce<string | null>((o, a) => (o === null || Date.parse(a.since) < Date.parse(o) ? a.since : o), null),
178 };
179 });
180 const words = waitingWords(count, oldest, now);
176181 return words === null ? html`` : html`<p class="small muted"><a href="/review">${words}</a></p>`;
177182 }
test/caching-doc.test.ts +1 −1
@@ -107,7 +107,7 @@ describe("docs/CACHING.md", () => {
107107
108108 test("each cache says what, key, invalidated by and max age", () => {
109109 const caches = doc.split(/^### \d\. /m).slice(1);
110 expect(caches.length).toBe(5);
110 expect(caches.length).toBe(6);
111111 for (const cache of caches)
112112 for (const part of ["**What:**", "**Key:**", "**Invalidated by:**", "**Max age:**"])
113113 expect(cache).toContain(part);
test/home-200.test.ts added +63
@@ -0,0 +1,63 @@
1 /** #5806: the owner's home on a forge of 200 repositories and 100 open asks answers warm in within 300 ms, every slow phase named. */
2 import { afterAll, beforeAll, expect, test } from "bun:test";
3 import { assignIssue, openIssue } from "../src/actions/issues.ts";
4 import { waitingCache } from "../src/web/studio/home_cache.ts";
5 import { baselineMs, expectBudget } from "./helpers/budget.ts";
6 import { snappyFixture, type SnappyFixture } from "../bench/snappy.ts";
7
8 let f: SnappyFixture;
9
10 beforeAll(async () => {
11 f = await snappyFixture({ repos: 200, issuesPerRepo: 1 });
12 // An ask is something assigned to the owner; half the repositories hold one.
13 for (const repo of f.repos.slice(0, 100)) {
14 const issue = openIssue(f.app, f.owner, repo, { title: "Yours to decide" });
15 if (!issue.ok) throw new Error(String(issue.error));
16 const done = assignIssue(f.app, f.owner, repo, issue.value, f.owner);
17 if (!done.ok) throw new Error(String(done.error));
18 }
19 }, 600_000);
20 afterAll(async () => {
21 await f.close();
22 });
23
24 async function look(): Promise<{ ms: number; phases: { name: string; ms: number }[] }> {
25 const t = performance.now();
26 const res = await fetch(`${f.base}/`, { headers: { cookie: f.ownerCookie } });
27 await res.arrayBuffer();
28 const ms = performance.now() - t;
29 const phases = (res.headers.get("server-timing") ?? "")
30 .split(", ")
31 .map((p) => ({ name: p.split(";")[0]!, ms: Number(/dur=([\d.]+)/.exec(p)?.[1] ?? 0) }));
32 return { ms, phases };
33 }
34
35 test("the second look at home as the owner is within its budget, and every phase over 20 ms is named", async () => {
36 await look();
37 const warm = await look();
38 const slow = warm.phases.filter((p) => p.name !== "app" && p.ms > 20);
39 console.log(`home warm ${warm.ms.toFixed(0)} ms:`, warm.phases.map((p) => `${p.name} ${p.ms}`).join(", "));
40 expectBudget(warm.ms, { ms: 300, against: await baselineMs(f.base) });
41 // The page's own total is the sum of named phases: nothing over 20 ms hides in "app" alone.
42 const known = new Set(["app", "spawned", "steps", "session", "repos", "kpis", "waiting", "panels", "feed", "render"]);
43 for (const p of slow) expect(known.has(p.name)).toBe(true);
44 const total = warm.phases.find((p) => p.name === "app")!.ms;
45 const named = warm.phases.filter((p) => p.name !== "app").reduce((s, p) => s + p.ms, 0);
46 expectBudget(total - named, { ms: 20, against: await baselineMs(f.base) });
47 });
48
49 const waiting = async (): Promise<number> => {
50 const text = await (await fetch(`${f.base}/`, { headers: { cookie: f.ownerCookie } })).text();
51 return Number(/(\d+) waiting on you/.exec(text)?.[1] ?? 0);
52 };
53
54 test("the waiting line is a hit on the second look and a write puts it back", async () => {
55 const first = await waiting();
56 expect(first).toBeGreaterThan(0);
57 const before = waitingCache(f.app.db).hits;
58 expect(await waiting()).toBe(first);
59 expect(waitingCache(f.app.db).hits).toBeGreaterThan(before);
60 // Every ask is put down in one write: the line is gone at once, not in 30 seconds.
61 f.app.db.query("UPDATE issue SET assignee_id = NULL").run();
62 expect(await waiting()).toBe(0);
63 });

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs