Public: anyone can read this; the crew can change it.
Server-Timing on / names each part of readKpis: landed, live, checks, builders, spend, reach, backup #7689
Check · Review · Land · Live done — Landed and live in production.
scout/forge:scout/7626-server-timing-on-names-each-part-of-read → main 2 commits fork 1 thread · 1 unresolved
6 files
changed +49
−21
src/core/route_timing.ts +2 −2
| @@ -217,8 +217,8 @@ export interface Phase { | ||
| 217 | 217 | readonly hit?: boolean; |
| 218 | 218 | } |
| 219 | 219 | |
| 220 | /** A phase name is a header token: lowercase letters, nothing a viewer chose. */ | |
| 221 | const PHASE_NAME = /^[a-z][a-z0-9-]{0,15}$/; | |
| 220 | /** A phase name is a header token: lowercase letters, a dot for a part (`kpis.live`), nothing a viewer chose. */ | |
| 221 | const PHASE_NAME = /^[a-z][a-z0-9.-]{0,15}$/; | |
| 222 | 222 | |
| 223 | 223 | const phaseLists = new WeakMap<Request, Phase[]>(); |
| 224 | 224 |
src/flow/kpis.ts +28 −12
| @@ -7,6 +7,9 @@ | ||
| 7 | 7 | * last hour, bucket 23 the one that ended 23 hours ago. Nothing here reads |
| 8 | 8 | * the clock. One query per figure. |
| 9 | 9 | * |
| 10 | * `time`, when given, wraps each part so a caller can name what it cost | |
| 11 | * (`kpis.landed` … `kpis.backup`, #7626); left out, each part just runs. | |
| 12 | * | |
| 10 | 13 | * A landing counts when it put something on main. A pull that closed as |
| 11 | 14 | * carried (its change was already there, #2036) lands no commit: its |
| 12 | 15 | * `merged_oid` is the base it found, or a commit an earlier pull landed. |
| @@ -41,17 +44,25 @@ export interface Kpis { | ||
| 41 | 44 | readonly reach: Reach; |
| 42 | 45 | } |
| 43 | 46 | |
| 47 | /** The parts `readKpis` names to its `time` callback, in the order it runs them. */ | |
| 48 | export const KPI_PARTS = ["kpis.landed", "kpis.live", "kpis.checks", "kpis.builders", "kpis.spend", "kpis.reach", "kpis.backup"] as const; | |
| 49 | export type KpiPart = (typeof KPI_PARTS)[number]; | |
| 50 | export type KpiTimer = <T>(name: KpiPart, fn: () => T) => T; | |
| 51 | ||
| 52 | const untimed: KpiTimer = (_name, fn) => fn(); | |
| 53 | ||
| 44 | 54 | export function readKpis( |
| 45 | 55 | db: Database, |
| 46 | 56 | now: Date, |
| 47 | 57 | forge: { readonly ceilingUsd: number | null; readonly dataDir?: string } = { ceilingUsd: null }, |
| 58 | time: KpiTimer = untimed, | |
| 48 | 59 | ): Kpis { |
| 49 | 60 | const end = now.getTime(); |
| 50 | 61 | const to = now.toISOString(); |
| 51 | 62 | const since = new Date(end - HOURS * HOUR_MS).toISOString(); |
| 52 | 63 | |
| 53 | 64 | const landedHours = new Array<number>(HOURS).fill(0); |
| 54 | const landings = db | |
| 65 | const landings = time("kpis.landed", () => db | |
| 55 | 66 | .query<{ at: string }, [string, string]>( |
| 56 | 67 | `SELECT p.merged_at AS at |
| 57 | 68 | FROM pull p JOIN issue i ON i.id = p.issue_id JOIN repo r ON r.id = i.repo_id |
| @@ -63,45 +74,50 @@ export function readKpis( | ||
| 63 | 74 | WHERE j.repo_id = i.repo_id AND q.merged_oid = p.merged_oid |
| 64 | 75 | AND (q.merged_at < p.merged_at OR (q.merged_at = p.merged_at AND q.issue_id < p.issue_id)))`, |
| 65 | 76 | ) |
| 66 | .all(since, to); | |
| 77 | .all(since, to)); | |
| 67 | 78 | for (const { at } of landings) { |
| 68 | 79 | const h = Math.floor((end - Date.parse(at)) / HOUR_MS); |
| 69 | 80 | if (h >= 0 && h < HOURS) landedHours[h]! += 1; |
| 70 | 81 | } |
| 71 | 82 | |
| 72 | const live = db | |
| 83 | const live = time("kpis.live", () => db | |
| 73 | 84 | .query<{ sha: string; at: string }, [string]>( |
| 74 | 85 | `SELECT commit_oid AS sha, serving_at AS at FROM run |
| 75 | 86 | WHERE kind = 'deploy' AND env = 'production' AND serving_at IS NOT NULL AND serving_at <= ?1 |
| 76 | 87 | ORDER BY serving_at DESC LIMIT 1`, |
| 77 | 88 | ) |
| 78 | .get(to); | |
| 89 | .get(to)); | |
| 79 | 90 | |
| 80 | const spans = db | |
| 91 | const spans = time("kpis.checks", () => db | |
| 81 | 92 | .query<{ ms: number }, [string, string]>( |
| 82 | 93 | `SELECT (julianday(finished_at) - julianday(started_at)) * 86400000.0 AS ms FROM run |
| 83 | 94 | WHERE kind = 'check' AND state IN ('ok','failed') AND started_at IS NOT NULL |
| 84 | 95 | AND finished_at >= ?1 AND finished_at <= ?2`, |
| 85 | 96 | ) |
| 86 | 97 | .all(since, to) |
| 87 | .map((r) => Math.round(r.ms)); | |
| 98 | .map((r) => Math.round(r.ms))); | |
| 88 | 99 | |
| 89 | const builders = db | |
| 100 | const builders = time("kpis.builders", () => db | |
| 90 | 101 | .query<{ running: number; slots: number }, []>( |
| 91 | 102 | `SELECT (SELECT COUNT(*) FROM run WHERE kind = 'agent' AND state = 'running') AS running, |
| 92 | 103 | (SELECT COALESCE(SUM(autonomy_slots), 0) FROM repo WHERE autonomy != 'off') AS slots`, |
| 93 | 104 | ) |
| 94 | .get() ?? { running: 0, slots: 0 }; | |
| 105 | .get() ?? { running: 0, slots: 0 }); | |
| 95 | 106 | |
| 96 | const todayUsd = spentTodayEverywhere(db, now); | |
| 107 | const spend = time("kpis.spend", () => { | |
| 108 | const todayUsd = spentTodayEverywhere(db, now); | |
| 109 | return { todayUsd, ceilingUsd: forge.ceilingUsd, hitAt: ceilingReached(todayUsd, forge.ceilingUsd) ? ceilingHitAt(db, now, forge.ceilingUsd) : null }; | |
| 110 | }); | |
| 97 | 111 | |
| 98 | const backupAt = forge.dataDir === undefined ? null : lastOffBox(forge.dataDir); | |
| 112 | const reach = time("kpis.reach", () => readReach(db, now)); | |
| 113 | ||
| 114 | const backupAt = time("kpis.backup", () => (forge.dataDir === undefined ? null : lastOffBox(forge.dataDir))); | |
| 99 | 115 | |
| 100 | 116 | return { |
| 101 | 117 | backupAt, |
| 102 | 118 | builders, |
| 103 | reach: readReach(db, now), | |
| 104 | spend: { todayUsd, ceilingUsd: forge.ceilingUsd, hitAt: ceilingReached(todayUsd, forge.ceilingUsd) ? ceilingHitAt(db, now, forge.ceilingUsd) : null }, | |
| 119 | reach, | |
| 120 | spend, | |
| 105 | 121 | landedHours, |
| 106 | 122 | landed: landedHours.reduce((a, b) => a + b, 0), |
| 107 | 123 | live: live ?? null, |
src/web/studio/home.ts +4 −1
| @@ -59,6 +59,7 @@ import { feedCandidateCache } from "../../feed/feed.ts"; | ||
| 59 | 59 | import { notePhase, notePhaseRest, takeSessionTime, timePhase, timePhaseAsync } from "../../core/route_timing.ts"; |
| 60 | 60 | import { idleReason } from "../../crew/idle_reason.ts"; |
| 61 | 61 | import { kpiCache, panelCache, waitingCache } from "./home_cache.ts"; |
| 62 | import type { KpiTimer } from "../../flow/kpis.ts"; | |
| 62 | 63 | import { archivedAppCount } from "../pages/apps.ts"; |
| 63 | 64 | import { pinnedPanels } from "./pinned.ts"; |
| 64 | 65 | import { isNavigation, lastVisit, noteVisit } from "../../core/home_visit.ts"; |
| @@ -286,7 +287,9 @@ export async function studioHome( | ||
| 286 | 287 | const ask = firstSteps ?? everydayCard(ctx, user); |
| 287 | 288 | const figures = user.isAdmin && steps === undefined; |
| 288 | 289 | const ceilingUsd = forgeCeiling(ctx.app.config); |
| 289 | const kpiOpts = { idle: figures ? idleReason(ctx.app, new Date()) : null, dataDir: ctx.app.config.dataDir, ...(ceilingUsd === null ? {} : { ceilingUsd }) }; | |
| 290 | // Each part of a cold read is its own Server-Timing entry (#7626); a cache hit names none. | |
| 291 | const kpiTime: KpiTimer = (name, fn) => timePhase(ctx.request, name, fn); | |
| 292 | const kpiOpts = { idle: figures ? idleReason(ctx.app, new Date()) : null, dataDir: ctx.app.config.dataDir, time: kpiTime, ...(ceilingUsd === null ? {} : { ceilingUsd }) }; | |
| 290 | 293 | const body = html`<h1 class="sr-only">Home</h1> |
| 291 | 294 | ${ask} ${address} ${figures |
| 292 | 295 | ? timePhase(ctx.request, "kpis", () => kpiRow(ctx.app.db, kpiOpts), () => kpiCache(ctx.app.db)) |
src/web/studio/home_cache.ts +4 −3
| @@ -10,7 +10,7 @@ | ||
| 10 | 10 | import type { Database } from "bun:sqlite"; |
| 11 | 11 | import type { Answer } from "../../boards/query.ts"; |
| 12 | 12 | import { writeStamp } from "../../core/write_clock.ts"; |
| 13 | import { readKpis, type Kpis } from "../../flow/kpis.ts"; | |
| 13 | import { readKpis, type KpiTimer, type Kpis } from "../../flow/kpis.ts"; | |
| 14 | 14 | import { readVitals, type Vitals } from "../../flow/vitals.ts"; |
| 15 | 15 | import { Stamped } from "../../kernel/stamped.ts"; |
| 16 | 16 | |
| @@ -63,11 +63,12 @@ export function cachedKpis( | ||
| 63 | 63 | db: Database, |
| 64 | 64 | now: Date, |
| 65 | 65 | forge: { readonly ceilingUsd: number | null; readonly dataDir?: string }, |
| 66 | time?: KpiTimer, | |
| 66 | 67 | ): Kpis { |
| 67 | 68 | const stamp = writeStamp(db); |
| 68 | if (stamp === undefined) return readKpis(db, now, forge); | |
| 69 | if (stamp === undefined) return readKpis(db, now, forge, time); | |
| 69 | 70 | const key = `kpi:${now.toISOString().slice(0, 13)}:${forge.ceilingUsd ?? "none"}:${forge.dataDir ?? ""}`; |
| 70 | return kpiCache(db).get(key, stamp, () => readKpis(db, now, forge)); | |
| 71 | return kpiCache(db).get(key, stamp, () => readKpis(db, now, forge, time)); | |
| 71 | 72 | } |
| 72 | 73 | |
| 73 | 74 | /** |
src/web/studio/kpi_row.ts +3 −3
| @@ -10,7 +10,7 @@ | ||
| 10 | 10 | import type { Database } from "bun:sqlite"; |
| 11 | 11 | import { backupAge, backupFull, backupOverdue, buildersValue, checkTime, reactNote, speedWords, spendCeilingWords, spendFull, spendValue, usersValue, visitorsNote, visitorsValue, waitingWords } from "../../flow/kpi_words.ts"; |
| 12 | 12 | import type { IdleReason } from "../../crew/idle_reason.ts"; |
| 13 | import type { Kpis } from "../../flow/kpis.ts"; | |
| 13 | import type { KpiTimer, Kpis } from "../../flow/kpis.ts"; | |
| 14 | 14 | import { clogLines, readClog } from "../../flow/clog_read.ts"; |
| 15 | 15 | import { vitalsLine } from "../../flow/vitals.ts"; |
| 16 | 16 | import { cachedKpis, cachedVitals, cachedWaiting } from "./home_cache.ts"; |
| @@ -165,10 +165,10 @@ export function kpiRowFor(k: Kpis, live: { sha: string; at: string } | null, now | ||
| 165 | 165 | } |
| 166 | 166 | |
| 167 | 167 | /** The figures count every repository, so the caller shows this to an admin only. */ |
| 168 | export function kpiRow(db: Database, opts: { ceilingUsd?: number; dataDir?: string; idle?: IdleReason | null; now?: Date } = {}): Html { | |
| 168 | export function kpiRow(db: Database, opts: { ceilingUsd?: number; dataDir?: string; idle?: IdleReason | null; now?: Date; time?: KpiTimer } = {}): Html { | |
| 169 | 169 | const now = opts.now ?? new Date(); |
| 170 | 170 | const forge = { ceilingUsd: opts.ceilingUsd ?? null, ...(opts.dataDir === undefined ? {} : { dataDir: opts.dataDir }) }; |
| 171 | return kpiRowFor(cachedKpis(db, now, forge), liveNow(), now, opts.idle ?? null); | |
| 171 | return kpiRowFor(cachedKpis(db, now, forge, opts.time), liveNow(), now, opts.idle ?? null); | |
| 172 | 172 | } |
| 173 | 173 | |
| 174 | 174 | /** |
test/home-timing.test.ts +8
| @@ -1,6 +1,7 @@ | ||
| 1 | 1 | /** `/`'s Server-Timing names its regions, and only the ones the viewer can see. */ |
| 2 | 2 | import { afterAll, beforeAll, expect, test } from "bun:test"; |
| 3 | 3 | import { serverTiming } from "../src/core/route_timing.ts"; |
| 4 | import { KPI_PARTS } from "../src/flow/kpis.ts"; | |
| 4 | 5 | import { snappyFixture, type SnappyFixture } from "../bench/snappy.ts"; |
| 5 | 6 | |
| 6 | 7 | let f: SnappyFixture; |
| @@ -19,6 +20,12 @@ async function timing(cookie?: string): Promise<string[]> { | ||
| 19 | 20 | } |
| 20 | 21 | const names = (parts: string[]): string[] => parts.map((p) => p.split(";")[0]!); |
| 21 | 22 | |
| 23 | test("a cold look at the owner's home names each part of the kpis read", async () => { | |
| 24 | const cold = names(await timing(f.ownerCookie)); | |
| 25 | expect(KPI_PARTS).toEqual(["kpis.landed", "kpis.live", "kpis.checks", "kpis.builders", "kpis.spend", "kpis.reach", "kpis.backup"]); | |
| 26 | expect(cold).toEqual(expect.arrayContaining(["kpis", ...KPI_PARTS])); | |
| 27 | }); | |
| 28 | ||
| 22 | 29 | test("the owner's home names feed, kpis and panels; a warm look is a hit", async () => { |
| 23 | 30 | await timing(f.ownerCookie); |
| 24 | 31 | const warm = await timing(f.ownerCookie); |
| @@ -32,6 +39,7 @@ test("a signed-in non-admin gets the feed and none of the admin-only phases", as | ||
| 32 | 39 | const got = names(await timing(f.peerCookie)); |
| 33 | 40 | expect(got).toContain("feed"); |
| 34 | 41 | expect(got).not.toContain("kpis"); |
| 42 | for (const part of KPI_PARTS) expect(got).not.toContain(part); | |
| 35 | 43 | expect(got).not.toContain("panels"); |
| 36 | 44 | }); |
| 37 | 45 |
new above
offline
This test passes only because it runs before any other owner request in the file. Reset the KPI cache at the start so reordering cannot flake it.