9d9ade0
@@ -370,7 +370,18 @@
warm:
  `test/flake.test.ts` allows a request; the 50 ms is read off the bench.
- **`/`: p95 ≤ 50 ms on the bench, and a statement count that does not
  grow with the feed's candidates** (the `test/counts.test.ts` pattern).
  The test's wall-clock bound is 200 ms, for the same reason.
  The 50 ms is read off the bench, end to end. `test/home-cache.test.ts`
  bounds what the KPI and panel caches spend, not the page's wall clock: it
  first records the statements a miss of both runs that a warm page does not
  (the KPI reads and the pinned panel's query), then requires that in 30 warm
  requests every `kpis` and `panels` phase is a `desc="hit"` and runs none
  of them. A request that a write came near (the route-timing flush, a
  session's last-seen) misses rightly and is not judged; at least 20 of the
  30 must be. Its earlier bound, 200 ms p95 on `/`, timed the feed (most of
  the page) and the machine's load, and went red on loaded check machines
  (#5237). The two phases take about 1.5 ms warm, but under load a hit and
  a miss both take from under a millisecond to tens of milliseconds, so no
  time bound can tell them apart.
## Max ages, at a glance
@@ -1,13 +1,15 @@
/**
 * Home's KPI row and pinned panels come from the cache docs/CACHING.md
 * designs (#2717): hit when nothing was written, miss after a write, p95
 * under the budget, and the owner's figures never reach another viewer.
 * designs (#2717): hit when nothing was written, miss after a write, a warm
 * hit that runs none of their reads, and the owner's figures never reach
 * another viewer.
 */
import { afterAll, beforeAll, expect, test } from "bun:test";
import { pinPanel } from "../src/actions/board-pins.ts";
import { writeBoard } from "../src/actions/boards.ts";
import { writeStamp } from "../src/core/write_clock.ts";
import { kpiCache, panelCache } from "../src/web/studio/home_cache.ts";
import { snappyFixture, timeRoute, type SnappyFixture } from "../bench/snappy.ts";
import { snappyFixture, type SnappyFixture } from "../bench/snappy.ts";
let f: SnappyFixture;
const home = async (cookie?: string): Promise<string> =>
@@ -56,9 +58,87 @@
test("the owner's KPIs and panels never render for another viewer, warm or not",
  }
});
/** The `kpis` and `panels` phases of one response, and whether each was a hit. */
const phases = (header: string | null): Record<string, boolean> =>
  Object.fromEntries(
    (header ?? "")
      .split(", ")
      .filter((p) => p.startsWith("kpis;") || p.startsWith("panels;"))
      .map((p) => [p.slice(0, p.indexOf(";")), p.endsWith(';desc="hit"')]),
  );
interface Counted {
  readonly status: number;
  readonly hits: Record<string, boolean>;
  /** How many times it ran each statement, by SQL text. */
  readonly ran: ReadonlyMap<string, number>;
  /** The write clock before and after it: a write in between is a correct miss. */
  readonly before: string | undefined;
  readonly after: string | undefined;
}
/** One owner home: its status, its `kpis`/`panels` hits and the statements it ran. */
async function counted(): Promise<Counted> {
  const before = writeStamp(f.app.db);
  f.counter.reset();
  const res = await fetch(`${f.base}/`, { headers: { cookie: f.ownerCookie } });
  await res.arrayBuffer();
  const ran = new Map(f.counter.top(10_000).map((s) => [s.sql, s.times]));
  return { status: res.status, hits: phases(res.headers.get("server-timing")), ran, before, after: writeStamp(f.app.db) };
}
/**
 * Nothing was written from the start of the request before `c` to its end:
 * every entry `c` reads was stored at the clock it reads at. (A write inside
 * the request before, after its KPI phase, leaves the KPIs stale and the
 * panels fresh, and the next request misses one of them, rightly.)
 */
const still = (c: Counted, previous: Counted): boolean =>
  c.before !== undefined && c.after === c.before && previous.before === c.before;
/** Request until one ran with nothing written since the request before it: the warm page. */
async function warmed(): Promise<Counted> {
  let previous = await counted();
  for (let i = 0; i < 10; i++) {
    const c = await counted();
    if (still(c, previous) && c.hits.kpis && c.hits.panels) return c;
    previous = c;
  }
  throw new Error("home never warmed: every request missed the KPI or panel cache");
}
// The budget is what the cached code spends, not the page's wall clock (#5237):
// a warm hit runs none of the KPI or panel reads, on any machine. The 200 ms
// bound this replaces timed the feed and the machine's load; and on a loaded
// machine a 0.4 ms hit and a 4 ms miss overlap, so time cannot tell them apart.
test("warm home holds p95 under the stated budget", async () => {
  const t = await timeRoute(f, "home owner", "/", { cookie: f.ownerCookie }, 30);
  expect(t.status).toBe(200);
  // The doc's 50 ms is read off the bench; the test keeps the 200 ms floor test/flake.test.ts allows.
  expect(t.p95).toBeLessThan(200);
  const warm = await warmed();
  expect(warm.status).toBe(200);
  // What a miss of both runs that the warm page does not, with the feed still warm.
  kpiCache(f.app.db).clear();
  panelCache(f.app.db).clear();
  const missed = await counted();
  expect(missed.hits).toEqual({ kpis: false, panels: false });
  const missOnly = [...missed.ran.keys()].filter((sql) => !warm.ran.has(sql));
  // The KPI reads (eight on this fixture) and the pinned panel's own query.
  expect(missOnly.length).toBeGreaterThan(5);
  expect(missOnly).toContain('SELECT "kind" AS "group", COUNT(*) AS "value" FROM "run" GROUP BY 1 ORDER BY 1 LIMIT 1000');
  // Every warm request, not 95 in 100, is a hit of both and runs none of
  // them. A request a write came near (the route-timing flush, a session's
  // last-seen) may miss, rightly; most must not have.
  let previous = await warmed();
  let judged = 0;
  for (let i = 0; i < 30; i++) {
    const t = await counted();
    const quiet = still(t, previous);
    previous = t;
    if (!quiet) continue;
    judged++;
    expect(t.status).toBe(200);
    expect(t.hits).toEqual({ kpis: true, panels: true });
    expect(missOnly.filter((sql) => t.ran.has(sql))).toEqual([]);
  }
  expect(judged).toBeGreaterThanOrEqual(20);
});
		@@ -370,7 +370,18 @@ warm:
370	370	`test/flake.test.ts` allows a request; the 50 ms is read off the bench.
371	371	- **`/`: p95 ≤ 50 ms on the bench, and a statement count that does not
372	372	grow with the feed's candidates** (the `test/counts.test.ts` pattern).
373		The test's wall-clock bound is 200 ms, for the same reason.
	373	The 50 ms is read off the bench, end to end. `test/home-cache.test.ts`
	374	bounds what the KPI and panel caches spend, not the page's wall clock: it
	375	first records the statements a miss of both runs that a warm page does not
	376	(the KPI reads and the pinned panel's query), then requires that in 30 warm
	377	requests every `kpis` and `panels` phase is a `desc="hit"` and runs none
	378	of them. A request that a write came near (the route-timing flush, a
	379	session's last-seen) misses rightly and is not judged; at least 20 of the
	380	30 must be. Its earlier bound, 200 ms p95 on `/`, timed the feed (most of
	381	the page) and the machine's load, and went red on loaded check machines
	382	(#5237). The two phases take about 1.5 ms warm, but under load a hit and
	383	a miss both take from under a millisecond to tens of milliseconds, so no
	384	time bound can tell them apart.
374	385
375	386	## Max ages, at a glance
376	387
		@@ -1,13 +1,15 @@
1	1	/**
2	2	* Home's KPI row and pinned panels come from the cache docs/CACHING.md
3		* designs (#2717): hit when nothing was written, miss after a write, p95
4		* under the budget, and the owner's figures never reach another viewer.
	3	* designs (#2717): hit when nothing was written, miss after a write, a warm
	4	* hit that runs none of their reads, and the owner's figures never reach
	5	* another viewer.
5	6	*/
6	7	import { afterAll, beforeAll, expect, test } from "bun:test";
7	8	import { pinPanel } from "../src/actions/board-pins.ts";
8	9	import { writeBoard } from "../src/actions/boards.ts";
	10	import { writeStamp } from "../src/core/write_clock.ts";
9	11	import { kpiCache, panelCache } from "../src/web/studio/home_cache.ts";
10		import { snappyFixture, timeRoute, type SnappyFixture } from "../bench/snappy.ts";
	12	import { snappyFixture, type SnappyFixture } from "../bench/snappy.ts";
11	13
12	14	let f: SnappyFixture;
13	15	const home = async (cookie?: string): Promise<string> =>
		@@ -56,9 +58,87 @@ test("the owner's KPIs and panels never render for another viewer, warm or not",
56	58	}
57	59	});
58	60
	61	/** The `kpis` and `panels` phases of one response, and whether each was a hit. */
	62	const phases = (header: string \| null): Record<string, boolean> =>
	63	Object.fromEntries(
	64	(header ?? "")
	65	.split(", ")
	66	.filter((p) => p.startsWith("kpis;") \|\| p.startsWith("panels;"))
	67	.map((p) => [p.slice(0, p.indexOf(";")), p.endsWith(';desc="hit"')]),
	68	);
	69
	70	interface Counted {
	71	readonly status: number;
	72	readonly hits: Record<string, boolean>;
	73	/** How many times it ran each statement, by SQL text. */
	74	readonly ran: ReadonlyMap<string, number>;
	75	/** The write clock before and after it: a write in between is a correct miss. */
	76	readonly before: string \| undefined;
	77	readonly after: string \| undefined;
	78	}
	79
	80	/** One owner home: its status, its `kpis`/`panels` hits and the statements it ran. */
	81	async function counted(): Promise<Counted> {
	82	const before = writeStamp(f.app.db);
	83	f.counter.reset();
	84	const res = await fetch(`${f.base}/`, { headers: { cookie: f.ownerCookie } });
	85	await res.arrayBuffer();
	86	const ran = new Map(f.counter.top(10_000).map((s) => [s.sql, s.times]));
	87	return { status: res.status, hits: phases(res.headers.get("server-timing")), ran, before, after: writeStamp(f.app.db) };
	88	}
	89
	90	/**
	91	* Nothing was written from the start of the request before `c` to its end:
	92	* every entry `c` reads was stored at the clock it reads at. (A write inside
	93	* the request before, after its KPI phase, leaves the KPIs stale and the
	94	* panels fresh, and the next request misses one of them, rightly.)
	95	*/
	96	const still = (c: Counted, previous: Counted): boolean =>
	97	c.before !== undefined && c.after === c.before && previous.before === c.before;
	98
	99	/** Request until one ran with nothing written since the request before it: the warm page. */
	100	async function warmed(): Promise<Counted> {
	101	let previous = await counted();
	102	for (let i = 0; i < 10; i++) {
	103	const c = await counted();
	104	if (still(c, previous) && c.hits.kpis && c.hits.panels) return c;
	105	previous = c;
	106	}
	107	throw new Error("home never warmed: every request missed the KPI or panel cache");
	108	}
	109
	110	// The budget is what the cached code spends, not the page's wall clock (#5237):
	111	// a warm hit runs none of the KPI or panel reads, on any machine. The 200 ms
	112	// bound this replaces timed the feed and the machine's load; and on a loaded
	113	// machine a 0.4 ms hit and a 4 ms miss overlap, so time cannot tell them apart.
59	114	test("warm home holds p95 under the stated budget", async () => {
60		const t = await timeRoute(f, "home owner", "/", { cookie: f.ownerCookie }, 30);
61		expect(t.status).toBe(200);
62		// The doc's 50 ms is read off the bench; the test keeps the 200 ms floor test/flake.test.ts allows.
63		expect(t.p95).toBeLessThan(200);
	115	const warm = await warmed();
	116	expect(warm.status).toBe(200);
	117
	118	// What a miss of both runs that the warm page does not, with the feed still warm.
	119	kpiCache(f.app.db).clear();
	120	panelCache(f.app.db).clear();
	121	const missed = await counted();
	122	expect(missed.hits).toEqual({ kpis: false, panels: false });
	123	const missOnly = [...missed.ran.keys()].filter((sql) => !warm.ran.has(sql));
	124	// The KPI reads (eight on this fixture) and the pinned panel's own query.
	125	expect(missOnly.length).toBeGreaterThan(5);
	126	expect(missOnly).toContain('SELECT "kind" AS "group", COUNT(*) AS "value" FROM "run" GROUP BY 1 ORDER BY 1 LIMIT 1000');
	127
	128	// Every warm request, not 95 in 100, is a hit of both and runs none of
	129	// them. A request a write came near (the route-timing flush, a session's
	130	// last-seen) may miss, rightly; most must not have.
	131	let previous = await warmed();
	132	let judged = 0;
	133	for (let i = 0; i < 30; i++) {
	134	const t = await counted();
	135	const quiet = still(t, previous);
	136	previous = t;
	137	if (!quiet) continue;
	138	judged++;
	139	expect(t.status).toBe(200);
	140	expect(t.hits).toEqual({ kpis: true, panels: true });
	141	expect(missOnly.filter((sql) => t.ran.has(sql))).toEqual([]);
	142	}
	143	expect(judged).toBeGreaterThanOrEqual(20);
64	144	});