Public: anyone can read this; the crew can change it.
Efficiency watcher: network bytes and cache hit rates by cause, filed when a cost doubles #11257
Check · Review · Land · Live done — Landed and live in production.
torque/forge:torque/7558-efficiency-watcher-network-bytes-and-cac → main 3 commits fork 2 threads · 2 unresolved
25 files
changed +848
−3
docs/features/maintain.md +11
| @@ -11,3 +11,14 @@ A finding must carry a probe: `{ kind: "query" | "measurement", what, number, at | ||
| 11 | 11 | The terminal door is the palette entry "Maintenance duty runs" (`src/tui/screens/maintainruns.ts`): the same rows through the same read, offered only to a forge admin; anyone else is offered nothing and sees no rows. |
| 12 | 12 | |
| 13 | 13 | Each run is bounded: a duty that has not answered in 30 seconds reads `failed: timed out` and the next duty runs (the late duty keeps its slot until it settles, so it never overlaps itself). A duty name must be lowercase words and dashes and unique, or the runner refuses to start. Each duty keeps its newest 200 rows; older ones are deleted after each run. A finding that says nothing reads `refused: a finding says nothing`. A non-admin's token reads 403 `forbidden`. |
| 14 | ||
| 15 | ## efficiency-watcher (#7558) | |
| 16 | ||
| 17 | Hourly, the duty records what each cost read (`efficiency_sample`, one row per cause per hour) and judges it (`src/efficiency/`): | |
| 18 | ||
| 19 | - **Causes** (`causes.ts`): npm registry bytes received, bytes from every other destination (image pulls, git fetch and clone, apps), the machine's CPU-seconds, and the install cache hit rate. Each has a floor and, for the byte causes, an absolute ceiling. The hit rate is the share of the hour's contained installs (`meteredInstall`, counted in `installs.ts`, in memory) that fetched under 1 MiB from the registry (`NPM_MISS_BYTES`); under 5 installs in the hour there is no reading. It is a *falling* cause: its floor is on the baseline (a baseline under 50% is not fallen from). Not measured by cause: per-run bytes and peak memory, which have no counter to read yet. | |
| 20 | - **Baseline** (`baseline.ts`): the median of the same hour of the day over the last 7 days; under 3 days of history there is none, so a new forge files nothing by doubling. | |
| 21 | - **Files when** (`judge.ts`) an hour is at least 2x its baseline for 2 hours running (a hit rate: at most half its baseline for 2 hours running), or at or over the ceiling. The reading is the rolling last hour of the egress tally, taken when the duty runs. | |
| 22 | - **One issue per cause** on the forge's repository (`FORGE_REPO`, as its owner): the cause, the number, the baseline and the code path. A comment each hour it still stands; closed with a note once the cost has been back under for 24 hours. If a person closes it, the next finding opens a new one. | |
| 23 | - The series is the `efficiency` board source (admin boards), so a board can chart it. | |
| 24 | - **Where an admin sees it.** The run is a row on the admin's "Maintenance duty runs" screen (terminal palette; `GET /api/v1/maintenance/runs`) under `efficiency-watcher`, with each finding's probe. The hourly series is the `efficiency` source on /boards (filter `cause`, value `value`; the hit rate is 0..1). If `FORGE_REPO` is unset or names no repository, findings still show on the run and its actions say `filed nothing: <why>`. |
src/boards/guide.ts +1
| @@ -34,6 +34,7 @@ export const GUIDE: Readonly<Record<string, Guide>> = { | ||
| 34 | 34 | tokens: { name: "API tokens", rows: "tokens", kind: "events" }, |
| 35 | 35 | adminActions: { name: "Admin actions", rows: "admin actions", kind: "events" }, |
| 36 | 36 | machine: { name: "Machine readings", rows: "15-second readings", kind: "samples", value: "cpu_cores", filter: { column: "target", op: "eq", value: "forge" } }, |
| 37 | efficiency: { name: "Efficiency by cause", rows: "hourly readings", kind: "samples", value: "value", filter: { column: "cause", op: "eq", value: "npm-registry-bytes" } }, | |
| 37 | 38 | reach: { name: "Visitors and page speed", rows: "daily figures", kind: "samples", value: "value", filter: { column: "metric", op: "eq", value: "visitors" } }, |
| 38 | 39 | app_vital: { name: "App page speed", rows: "app-days", kind: "samples", value: "load_p75" }, |
| 39 | 40 | keeperReleases: { name: "Releases", rows: "releases", kind: "events" }, |
src/boards/sources.ts +11
| @@ -191,6 +191,17 @@ export const SOURCES: Readonly<Record<string, Source>> = { | ||
| 191 | 191 | time: "created_at", |
| 192 | 192 | columns: { id: "text", kind: "text", repo_id: "text", actor_id: "text", created_at: "time" }, |
| 193 | 193 | }, |
| 194 | // The efficiency watcher's hourly readings by cause (`efficiency/`, #7558). | |
| 195 | efficiency: { | |
| 196 | table: "efficiency_sample", | |
| 197 | owner: "admin", | |
| 198 | time: "hour", | |
| 199 | columns: { cause: "text", hour: "time", value: "number" }, | |
| 200 | docs: { | |
| 201 | cause: "npm-registry-bytes, egress-other-bytes, cpu-seconds or install-cache-hit-rate (0..1)", | |
| 202 | value: "bytes received (or CPU-seconds, or share of installs that hit the cache) in the hour up to the reading", | |
| 203 | }, | |
| 204 | }, | |
| 194 | 205 | // What the machine used (`boards/sampler.ts`, kept by `boards/ring.ts`): |
| 195 | 206 | // 15-s points for the last day, 5-min points before that, never both |
| 196 | 207 | // for one moment. |
src/checks/install.ts +3 −1
| @@ -18,9 +18,10 @@ | ||
| 18 | 18 | |
| 19 | 19 | import { cpSync, existsSync, lstatSync, mkdirSync, mkdtempSync, readFileSync, rmSync, writeFileSync } from "node:fs"; |
| 20 | 20 | import { tmpdir } from "node:os"; |
| 21 | import { meterEgress } from "../apps/egress.ts"; | |
| 22 | 21 | import { dirname, join } from "node:path"; |
| 22 | import { meterEgress } from "../apps/egress.ts"; | |
| 23 | 23 | import { formatBytes } from "../core/storage.ts"; |
| 24 | import { noteInstall } from "../efficiency/installs.ts"; | |
| 24 | 25 | import { err, ok, type Result } from "../kernel/result.ts"; |
| 25 | 26 | import { fillable } from "./fillable.ts"; |
| 26 | 27 | import { lend } from "./install_evict.ts"; |
| @@ -85,6 +86,7 @@ export async function meteredInstall<T>( | ||
| 85 | 86 | if (options.fetched === true) write(installFetchedLine(fetched)); |
| 86 | 87 | const missed = npmMissLine(meter.npm()); |
| 87 | 88 | if (missed !== undefined) write(missed); |
| 89 | noteInstall(missed !== undefined); // the hit-rate counter the efficiency watcher reads (#7558) | |
| 88 | 90 | } |
| 89 | 91 | } |
| 90 | 92 |
src/core/migration-pins/20261111110000-efficiency.pin added +1
| @@ -0,0 +1,1 @@ | ||
| 1 | 23d0042136af8ee70c73f30c9b29cd3ce1e9adf1d8721b850f56d686bfaed437 |
src/core/migrations/20261111110000-efficiency.ts added +16
| @@ -0,0 +1,16 @@ | ||
| 1 | // The efficiency watcher (#7558): one reading per cause per hour, and the one | |
| 2 | // finding standing per cause. Additive. Both tables are small (a few causes, | |
| 3 | // 24 rows a day each, pruned past 9 days) and read by primary key only. | |
| 4 | export default ` | |
| 5 | CREATE TABLE efficiency_sample ( | |
| 6 | cause TEXT NOT NULL, | |
| 7 | hour TEXT NOT NULL, | |
| 8 | value REAL NOT NULL, | |
| 9 | PRIMARY KEY (cause, hour) | |
| 10 | ) WITHOUT ROWID; | |
| 11 | CREATE TABLE efficiency_finding ( | |
| 12 | cause TEXT PRIMARY KEY, | |
| 13 | issue_id TEXT NOT NULL, | |
| 14 | last_bad TEXT NOT NULL | |
| 15 | ) WITHOUT ROWID; | |
| 16 | `; |
src/efficiency/baseline.ts added +28
| @@ -0,0 +1,28 @@ | ||
| 1 | /** The baseline (#7558): the median of the same hour of the day over the last seven days. Plain data in, a number out. */ | |
| 2 | ||
| 3 | export const HOUR_MS = 3_600_000; | |
| 4 | export const BASELINE_DAYS = 7; | |
| 5 | /** Fewer days of history than this and there is no baseline: a new forge files nothing by doubling. */ | |
| 6 | export const MIN_DAYS = 3; | |
| 7 | ||
| 8 | /** hour start (ms) → value, for one cause. */ | |
| 9 | export type Series = ReadonlyMap<number, number>; | |
| 10 | ||
| 11 | export const hourStart = (ms: number): number => Math.floor(ms / HOUR_MS) * HOUR_MS; | |
| 12 | ||
| 13 | export function median(values: readonly number[]): number | undefined { | |
| 14 | if (values.length === 0) return undefined; | |
| 15 | const s = [...values].sort((a, b) => a - b); | |
| 16 | const m = s.length >> 1; | |
| 17 | return s.length % 2 === 1 ? s[m]! : (s[m - 1]! + s[m]!) / 2; | |
| 18 | } | |
| 19 | ||
| 20 | /** Median of the readings at `hour` minus 1..7 days; undefined with fewer than MIN_DAYS of them. */ | |
| 21 | export function baselineAt(series: Series, hour: number): number | undefined { | |
| 22 | const same: number[] = []; | |
| 23 | for (let d = 1; d <= BASELINE_DAYS; d++) { | |
| 24 | const v = series.get(hour - d * 24 * HOUR_MS); | |
| 25 | if (v !== undefined) same.push(v); | |
| 26 | } | |
| 27 | return same.length < MIN_DAYS ? undefined : median(same); | |
| 28 | } |
src/efficiency/causes.ts added +74
| @@ -0,0 +1,74 @@ | ||
| 1 | /** What the efficiency watcher measures (#7558): each cost by cause, its unit, its floor and ceiling, and the code path that starts it. Plain data. */ | |
| 2 | ||
| 3 | export interface Cause { | |
| 4 | /** Lowercase words and dashes; the sample's `cause`. */ | |
| 5 | readonly id: string; | |
| 6 | readonly label: string; | |
| 7 | /** "bytes", "seconds" or "ratio" (0 to 1): the unit every number of this cause is in, hourly. */ | |
| 8 | readonly unit: "bytes" | "seconds" | "ratio"; | |
| 9 | /** "rising" is bad when it doubles; "falling" (a hit rate) is bad when it halves. */ | |
| 10 | readonly direction: "rising" | "falling"; | |
| 11 | /** | |
| 12 | * Rising: an hour below this is never "doubled" (a baseline of nothing makes any byte a doubling). | |
| 13 | * Falling: a baseline below this is never "fallen from" (a cache that rarely hit has nothing to lose). | |
| 14 | */ | |
| 15 | readonly floor: number; | |
| 16 | /** An hour at or above this files at once, baseline or not. */ | |
| 17 | readonly ceiling: number | undefined; | |
| 18 | /** Where the cost starts, named in the finding. */ | |
| 19 | readonly path: string; | |
| 20 | } | |
| 21 | ||
| 22 | const MiB = 1024 ** 2; | |
| 23 | const GiB = 1024 ** 3; | |
| 24 | ||
| 25 | export const CAUSES: readonly Cause[] = [ | |
| 26 | { | |
| 27 | id: "npm-registry-bytes", | |
| 28 | label: "npm registry bytes received", | |
| 29 | unit: "bytes", | |
| 30 | direction: "rising", | |
| 31 | floor: 256 * MiB, | |
| 32 | ceiling: 4 * GiB, | |
| 33 | path: "an install step (`bun install` in `src/checks/service.ts`, an app's install in `src/apps/`) reaching registry.npmjs.org:443 through the egress proxy (`src/apps/egress.ts`, `NPM_REGISTRY`); a cold or unshared bun cache starts it", | |
| 34 | }, | |
| 35 | { | |
| 36 | id: "egress-other-bytes", | |
| 37 | label: "bytes received from every other destination (image pulls, git fetch and clone, apps)", | |
| 38 | unit: "bytes", | |
| 39 | direction: "rising", | |
| 40 | floor: 512 * MiB, | |
| 41 | ceiling: 10 * GiB, | |
| 42 | path: "a cell or app reaching a host other than the registry through the egress proxy (`src/apps/egress.ts`, `egressTotals`); the destination is in the forge's /metrics `forge_egress_received_bytes_total`", | |
| 43 | }, | |
| 44 | { | |
| 45 | id: "cpu-seconds", | |
| 46 | label: "CPU-seconds used by the forge's machine", | |
| 47 | unit: "seconds", | |
| 48 | direction: "rising", | |
| 49 | floor: 900, | |
| 50 | ceiling: undefined, | |
| 51 | path: "whatever ran hot: the 15 s sampler (`src/boards/sampler.ts`) names cpu per cell label in the `machine` source", | |
| 52 | }, | |
| 53 | { | |
| 54 | id: "install-cache-hit-rate", | |
| 55 | label: "install cache hit rate (installs that fetched under 1 MiB from the npm registry)", | |
| 56 | unit: "ratio", | |
| 57 | direction: "falling", | |
| 58 | floor: 0.5, | |
| 59 | ceiling: undefined, | |
| 60 | path: "a contained install (`meteredInstall` in `src/checks/install.ts`) fetching over 1 MiB from the registry because the shared cache (`prefillInstallCache`, `checkInstallCache`) was cold, evicted (`src/checks/install_evict.ts`) or not filled; counted in `src/efficiency/installs.ts`", | |
| 61 | }, | |
| 62 | ]; | |
| 63 | ||
| 64 | export const causeOf = (id: string): Cause | undefined => CAUSES.find((c) => c.id === id); | |
| 65 | ||
| 66 | export function show(c: Cause, n: number): string { | |
| 67 | if (c.unit === "ratio") return `${(n * 100).toFixed(1)}%`; | |
| 68 | if (c.unit === "seconds") return `${Math.round(n)} CPU-seconds`; | |
| 69 | const units = ["B", "KiB", "MiB", "GiB", "TiB"]; | |
| 70 | let v = n; | |
| 71 | let i = 0; | |
| 72 | while (v >= 1024 && i < units.length - 1) (v /= 1024), i++; | |
| 73 | return `${i === 0 ? v : v.toFixed(2)} ${units[i]}`; | |
| 74 | } |
src/efficiency/finding.ts added +32
| @@ -0,0 +1,32 @@ | ||
| 1 | /** The words of a finding and its comments (#7558): the cause, the number, the baseline, the code path. */ | |
| 2 | ||
| 3 | import { show, type Cause } from "./causes.ts"; | |
| 4 | import type { HourVerdict, Why } from "./judge.ts"; | |
| 5 | ||
| 6 | const at = (ms: number): string => `${new Date(ms).toISOString().slice(0, 13)}:00 UTC`; | |
| 7 | ||
| 8 | export const titleOf = (c: Cause): string => `Efficiency: ${c.label} is far ${c.direction === "falling" ? "below" : "above"} its usual`; | |
| 9 | ||
| 10 | export function numbers(c: Cause, v: HourVerdict, why: Why): string { | |
| 11 | const base = v.baseline === undefined ? "no baseline yet" : `baseline ${show(c, v.baseline)} (median of this hour over the last 7 days)`; | |
| 12 | const rule = | |
| 13 | why === "ceiling" | |
| 14 | ? `at or over the ceiling of ${show(c, c.ceiling ?? 0)}` | |
| 15 | : why === "fell" | |
| 16 | ? "at most half its baseline for 2 hours running" | |
| 17 | : "at least 2x its baseline for 2 hours running"; | |
| 18 | return `${show(c, v.value)} in the hour of ${at(v.hour)}; ${base}; ${rule}.`; | |
| 19 | } | |
| 20 | ||
| 21 | export function bodyOf(c: Cause, v: HourVerdict, why: Why): string { | |
| 22 | return ( | |
| 23 | `The efficiency watcher (duty \`efficiency-watcher\`) found **${c.label}**: ${numbers(c, v, why)}\n\n` + | |
| 24 | `Code path that starts the cost: ${c.path}.\n\n` + | |
| 25 | `This issue stands while the cost does: it gets a comment each hour it is still bad, and is closed with a note once it has been back under for 24 hours. ` + | |
| 26 | `The hourly series is the \`efficiency\` board source.` | |
| 27 | ); | |
| 28 | } | |
| 29 | ||
| 30 | export const commentOf = (c: Cause, v: HourVerdict, why: Why): string => `Still bad: ${numbers(c, v, why)}`; | |
| 31 | ||
| 32 | export const closingNote = (c: Cause): string => `${c.label} has been back under its baseline and ceiling for 24 hours. Closing; a new finding opens if it returns.`; |
src/efficiency/installs.ts added +37
| @@ -0,0 +1,37 @@ | ||
| 1 | /** The install cache counter (#7558): each contained install, and whether it missed the shared cache. In memory, the last hour only. */ | |
| 2 | ||
| 3 | import { HOUR_MS } from "./baseline.ts"; | |
| 4 | ||
| 5 | /** Fewer installs than this in the hour and there is no hit rate: one install is not a rate. */ | |
| 6 | export const MIN_INSTALLS = 5; | |
| 7 | ||
| 8 | const seen: { at: number; missed: boolean }[] = []; | |
| 9 | ||
| 10 | /** One contained install finished; `missed` when the registry sent more than `NPM_MISS_BYTES` (`checks/install.ts`). */ | |
| 11 | export function noteInstall(missed: boolean, now: number = Date.now()): void { | |
| 12 | seen.push({ at: now, missed }); | |
| 13 | prune(now); | |
| 14 | } | |
| 15 | ||
| 16 | function prune(now: number): void { | |
| 17 | let n = 0; | |
| 18 | while (n < seen.length && seen[n]!.at <= now - HOUR_MS) n++; | |
| 19 | if (n > 0) seen.splice(0, n); | |
| 20 | } | |
| 21 | ||
| 22 | /** Installs in the hour up to `now` and how many missed. */ | |
| 23 | export function installsLastHour(now: number): { installs: number; misses: number } { | |
| 24 | prune(now); | |
| 25 | return { installs: seen.length, misses: seen.filter((s) => s.missed).length }; | |
| 26 | } | |
| 27 | ||
| 28 | /** Share of the last hour's installs that hit the cache, 0..1; undefined under MIN_INSTALLS. */ | |
| 29 | export function hitRateLastHour(now: number): number | undefined { | |
| 30 | const { installs, misses } = installsLastHour(now); | |
| 31 | return installs < MIN_INSTALLS ? undefined : (installs - misses) / installs; | |
| 32 | } | |
| 33 | ||
| 34 | /** For tests: forget every install. */ | |
| 35 | export function resetInstalls(): void { | |
| 36 | seen.length = 0; | |
| 37 | } |
src/efficiency/judge.ts added +45
| @@ -0,0 +1,45 @@ | ||
| 1 | /** When a cost is bad (#7558): 2x its baseline for 2 hours running, a hit rate at or under half its baseline for 2 hours running, or at or over its ceiling. */ | |
| 2 | ||
| 3 | import { baselineAt, HOUR_MS, type Series } from "./baseline.ts"; | |
| 4 | import type { Cause } from "./causes.ts"; | |
| 5 | ||
| 6 | export const DOUBLE = 2; | |
| 7 | export type Why = "ceiling" | "doubled" | "fell"; | |
| 8 | ||
| 9 | export const FALL = 0.5; | |
| 10 | export const HOURS_TO_FILE = 2; | |
| 11 | ||
| 12 | export interface HourVerdict { | |
| 13 | readonly hour: number; | |
| 14 | readonly value: number; | |
| 15 | readonly baseline: number | undefined; | |
| 16 | readonly doubled: boolean; | |
| 17 | /** A falling cause (a hit rate) at or under FALL of its baseline, the baseline itself at or over the cause's floor. */ | |
| 18 | readonly fell: boolean; | |
| 19 | readonly overCeiling: boolean; | |
| 20 | } | |
| 21 | ||
| 22 | export function hourVerdict(c: Cause, series: Series, hour: number): HourVerdict | undefined { | |
| 23 | const value = series.get(hour); | |
| 24 | if (value === undefined) return undefined; | |
| 25 | const baseline = baselineAt(series, hour); | |
| 26 | const doubled = c.direction === "rising" && baseline !== undefined && value >= c.floor && value >= DOUBLE * baseline; | |
| 27 | const fell = c.direction === "falling" && baseline !== undefined && baseline >= c.floor && value <= FALL * baseline; | |
| 28 | const overCeiling = c.ceiling !== undefined && value >= c.ceiling; | |
| 29 | return { hour, value, baseline, doubled, fell, overCeiling }; | |
| 30 | } | |
| 31 | ||
| 32 | export const isBad = (v: HourVerdict | undefined): boolean => v !== undefined && (v.doubled || v.fell || v.overCeiling); | |
| 33 | ||
| 34 | /** The verdict that makes the cost stand at `hour`: the ceiling at once, or the doubling this hour and the one before (a falling cause: the fall). */ | |
| 35 | export function standing(c: Cause, series: Series, hour: number): { now: HourVerdict; why: Why } | undefined { | |
| 36 | const now = hourVerdict(c, series, hour); | |
| 37 | if (now === undefined) return undefined; | |
| 38 | if (now.overCeiling) return { now, why: "ceiling" }; | |
| 39 | let run = 0; | |
| 40 | for (let i = 0; i < HOURS_TO_FILE; i++) { | |
| 41 | const v = hourVerdict(c, series, hour - i * HOUR_MS); | |
| 42 | if (v?.doubled || v?.fell) run++; | |
| 43 | } | |
| 44 | return run === HOURS_TO_FILE ? { now, why: c.direction === "falling" ? "fell" : "doubled" } : undefined; | |
| 45 | } |
src/efficiency/readings.ts added +28
| @@ -0,0 +1,28 @@ | ||
| 1 | /** What each cause reads right now, from the figures the forge already keeps (#7546's egress tally, the 15 s machine sampler). */ | |
| 2 | ||
| 3 | import type { Database } from "bun:sqlite"; | |
| 4 | import { hitRateLastHour } from "./installs.ts"; | |
| 5 | import { egressTotals, NPM_REGISTRY } from "../apps/egress.ts"; | |
| 6 | ||
| 7 | export type Readings = Readonly<Record<string, number>>; | |
| 8 | ||
| 9 | /** CPU-seconds the machine used over the hour up to `now`: mean cores of the 15 s points times 3600. */ | |
| 10 | export function cpuSecondsLastHour(db: Database, now: number): number | undefined { | |
| 11 | const r = db | |
| 12 | .query("SELECT AVG(cpu_cores) AS cores FROM machine_sample WHERE target = 'node' AND step = 15 AND cpu_cores IS NOT NULL AND at > ?1") | |
| 13 | .get(new Date(now - 3_600_000).toISOString()) as { cores: number | null } | null; | |
| 14 | return r?.cores == null ? undefined : r.cores * 3600; | |
| 15 | } | |
| 16 | ||
| 17 | export function readNow(db: Database, now: number): Readings { | |
| 18 | const totals = egressTotals(now); | |
| 19 | const out: Record<string, number> = { | |
| 20 | "npm-registry-bytes": totals.find((t) => t.destination === NPM_REGISTRY)?.bytesInLastHour ?? 0, | |
| 21 | "egress-other-bytes": totals.filter((t) => t.destination !== NPM_REGISTRY).reduce((n, t) => n + t.bytesInLastHour, 0), | |
| 22 | }; | |
| 23 | const cpu = cpuSecondsLastHour(db, now); | |
| 24 | if (cpu !== undefined) out["cpu-seconds"] = cpu; | |
| 25 | const hit = hitRateLastHour(now); | |
| 26 | if (hit !== undefined) out["install-cache-hit-rate"] = hit; | |
| 27 | return out; | |
| 28 | } |
src/efficiency/store.ts added +54
| @@ -0,0 +1,54 @@ | ||
| 1 | /** `efficiency_sample` and `efficiency_finding`: the hourly readings and the finding standing per cause. */ | |
| 2 | ||
| 3 | import type { Database } from "bun:sqlite"; | |
| 4 | import { BASELINE_DAYS, HOUR_MS, type Series } from "./baseline.ts"; | |
| 5 | import { causeOf } from "./causes.ts"; | |
| 6 | ||
| 7 | const iso = (ms: number): string => new Date(ms).toISOString(); | |
| 8 | ||
| 9 | /** | |
| 10 | * One reading for the hour starting at `hour`. Two readings in one hour (a restart, a manual tick) | |
outdated
MAX is wrong for a falling cause: a later, higher hit-rate reading in the same hour masks the fall. Choose MIN or MAX by the cause's direction and test it. |
||
| 11 | * keep the worse: the larger for a rising cost, the smaller for a falling one (a hit rate), so a | |
| 12 | * later, kinder reading never hides a bad one. | |
| 13 | */ | |
| 14 | export function putSample(db: Database, cause: string, hour: number, value: number): void { | |
| 15 | const worse = causeOf(cause)?.direction === "falling" ? "MIN" : "MAX"; | |
| 16 | db.query( | |
| 17 | `INSERT INTO efficiency_sample (cause, hour, value) VALUES (?1, ?2, ?3) ON CONFLICT (cause, hour) DO UPDATE SET value = ${worse}(value, excluded.value)`, | |
| 18 | ).run(cause, iso(hour), value); | |
| 19 | } | |
| 20 | ||
| 21 | /** The cause's readings of the last 8 days up to `hour`. */ | |
| 22 | export function readSeries(db: Database, cause: string, hour: number): Series { | |
| 23 | const rows = db | |
| 24 | .query("SELECT hour, value FROM efficiency_sample WHERE cause = ?1 AND hour > ?2 AND hour <= ?3") | |
| 25 | .all(cause, iso(hour - (BASELINE_DAYS + 1) * 24 * HOUR_MS), iso(hour)) as { hour: string; value: number }[]; | |
| 26 | return new Map(rows.map((r) => [Date.parse(r.hour), r.value])); | |
| 27 | } | |
| 28 | ||
| 29 | export function pruneSamples(db: Database, now: number): void { | |
| 30 | db.query("DELETE FROM efficiency_sample WHERE hour < ?1").run(iso(now - (BASELINE_DAYS + 2) * 24 * HOUR_MS)); | |
| 31 | } | |
| 32 | ||
| 33 | export interface Standing { | |
| 34 | readonly cause: string; | |
| 35 | readonly issueId: string; | |
| 36 | readonly lastBad: number; | |
| 37 | } | |
| 38 | ||
| 39 | export function standingOf(db: Database, cause: string): Standing | undefined { | |
| 40 | const r = db.query("SELECT cause, issue_id, last_bad FROM efficiency_finding WHERE cause = ?1").get(cause) as | |
| 41 | | { cause: string; issue_id: string; last_bad: string } | |
| 42 | | null; | |
| 43 | return r ? { cause: r.cause, issueId: r.issue_id, lastBad: Date.parse(r.last_bad) } : undefined; | |
| 44 | } | |
| 45 | ||
| 46 | export function putStanding(db: Database, s: Standing): void { | |
| 47 | db.query( | |
| 48 | "INSERT INTO efficiency_finding (cause, issue_id, last_bad) VALUES (?1, ?2, ?3) ON CONFLICT (cause) DO UPDATE SET issue_id = excluded.issue_id, last_bad = excluded.last_bad", | |
| 49 | ).run(s.cause, s.issueId, iso(s.lastBad)); | |
| 50 | } | |
| 51 | ||
| 52 | export function dropStanding(db: Database, cause: string): void { | |
| 53 | db.query("DELETE FROM efficiency_finding WHERE cause = ?1").run(cause); | |
| 54 | } |
src/efficiency/watch.ts added +89
| @@ -0,0 +1,89 @@ | ||
| 1 | /** | |
| 2 | * The efficiency watcher's pass (#7558): record this hour's readings, judge each cause against its | |
| 3 | * baseline, and keep one issue per cause — filed when it stands, commented while it does, closed | |
| 4 | * with a note once it has been back under for 24 hours. | |
| 5 | */ | |
| 6 | ||
| 7 | import type { App } from "../app.ts"; | |
| 8 | import { addComment, openIssue, setIssueState } from "../actions/issues.ts"; | |
| 9 | import { getIssueById } from "../core/issues.ts"; | |
| 10 | import { getRepo } from "../core/repos.ts"; | |
| 11 | import { getUserById } from "../core/users.ts"; | |
| 12 | import type { DutyResult, Finding } from "../maintain/duty.ts"; | |
| 13 | import { HOUR_MS, hourStart } from "./baseline.ts"; | |
| 14 | import { CAUSES } from "./causes.ts"; | |
| 15 | import { bodyOf, closingNote, commentOf, numbers, titleOf } from "./finding.ts"; | |
| 16 | import { isBad, standing, hourVerdict } from "./judge.ts"; | |
| 17 | import { readNow, type Readings } from "./readings.ts"; | |
| 18 | import { dropStanding, pruneSamples, putSample, putStanding, readSeries, standingOf } from "./store.ts"; | |
| 19 | ||
| 20 | export const CLEAR_AFTER_MS = 24 * HOUR_MS; | |
| 21 | ||
| 22 | export function watch(app: App, now: number, readings: Readings = readNow(app.db, now)): DutyResult { | |
| 23 | const { db } = app; | |
| 24 | const hour = hourStart(now); | |
| 25 | const findings: Finding[] = []; | |
| 26 | const actions: string[] = []; | |
| 27 | const [owner = "", name = ""] = (app.config.forgeRepo ?? "").split("/"); | |
| 28 | const repo = owner && name ? getRepo(db, owner, name) : undefined; | |
| 29 | const actor = repo ? getUserById(db, repo.ownerId) : undefined; | |
| 30 | ||
| 31 | for (const c of CAUSES) { | |
| 32 | const reading = readings[c.id]; | |
| 33 | if (reading !== undefined) putSample(db, c.id, hour, reading); | |
| 34 | const series = readSeries(db, c.id, hour); | |
| 35 | const stands = standing(c, series, hour); | |
| 36 | const kept = standingOf(db, c.id); | |
| 37 | const issue = kept ? getIssueById(db, kept.issueId) : undefined; | |
| 38 | const open = issue !== undefined && issue.state === "open"; | |
| 39 | ||
| 40 | if (stands !== undefined) { | |
| 41 | findings.push({ | |
| 42 | summary: `${c.label}: ${numbers(c, stands.now, stands.why)}`, | |
| 43 | probe: { kind: "measurement", what: `${c.label} (${c.unit}) in the hour from ${new Date(hour).toISOString()}`, number: stands.now.value, at: new Date(now).toISOString() }, | |
| 44 | }); | |
| 45 | if (repo === undefined || actor === undefined) continue; | |
| 46 | if (open && kept !== undefined) { | |
| 47 | // One comment per hour: a second pass in the same hour adds nothing. | |
| 48 | if (kept.lastBad < hour) { | |
| 49 | addComment(app, actor, repo, issue, commentOf(c, stands.now, stands.why)); | |
| 50 | putStanding(db, { ...kept, lastBad: hour }); | |
| 51 | actions.push(`commented on #${issue.number} (${c.id})`); | |
| 52 | } | |
| 53 | continue; | |
| 54 | } | |
| 55 | const filed = openIssue(app, actor, repo, { title: titleOf(c), body: bodyOf(c, stands.now, stands.why) }); | |
| 56 | if (filed.ok) { | |
| 57 | putStanding(db, { cause: c.id, issueId: filed.value.id, lastBad: hour }); | |
| 58 | actions.push(`filed #${filed.value.number} (${c.id})`); | |
| 59 | } | |
| 60 | continue; | |
| 61 | } | |
| 62 | ||
| 63 | if (kept === undefined) continue; | |
| 64 | if (!open) { | |
| 65 | dropStanding(db, c.id); // someone closed it: the next standing cost files anew | |
| 66 | continue; | |
| 67 | } | |
| 68 | const lastBad = isBad(hourVerdict(c, series, hour)) ? hour : kept.lastBad; | |
| 69 | if (lastBad !== kept.lastBad) putStanding(db, { ...kept, lastBad }); | |
| 70 | if (repo !== undefined && actor !== undefined && now - lastBad >= CLEAR_AFTER_MS) { | |
| 71 | addComment(app, actor, repo, issue, closingNote(c)); | |
| 72 | setIssueState(app, actor, repo, issue, "closed"); | |
| 73 | dropStanding(db, c.id); | |
| 74 | actions.push(`closed #${issue.number} (${c.id}) after 24 hours clear`); | |
| 75 | } | |
| 76 | } | |
| 77 | pruneSamples(db, now); | |
| 78 | if (findings.length > 0 && (repo === undefined || actor === undefined)) { | |
| 79 | const why = !app.config.forgeRepo | |
| 80 | ? "FORGE_REPO is not set" | |
| 81 | : !owner || !name | |
| 82 | ? `FORGE_REPO "${app.config.forgeRepo}" is not owner/name` | |
| 83 | : repo === undefined | |
| 84 | ? `FORGE_REPO "${app.config.forgeRepo}" names no repository on this forge` | |
| 85 | : "the repository's owner is not a user"; | |
| 86 | actions.push(`filed nothing: ${why}, so there is no repository to file ${findings.length} finding(s) in`); | |
| 87 | } | |
| 88 | return { findings, actions }; | |
| 89 | } |
src/maintain/duties/efficiency_watcher.ts added +12
| @@ -0,0 +1,12 @@ | ||
| 1 | /** The efficiency watcher (#7558): hourly cost by cause against a 7-day baseline; see `src/efficiency/`. */ | |
| 2 | ||
| 3 | import type { Duty } from "../duty.ts"; | |
| 4 | import { watch } from "../../efficiency/watch.ts"; | |
| 5 | ||
| 6 | export const duty: Duty = { | |
| 7 | name: "efficiency-watcher", | |
| 8 | intervalMs: 3_600_000, | |
| 9 | run({ app, now }) { | |
| 10 | return app === undefined ? { findings: [], actions: [] } : watch(app, now.getTime()); | |
| 11 | }, | |
| 12 | }; |
src/maintain/duty.ts +3
| @@ -1,6 +1,7 @@ | ||
| 1 | 1 | /** What a maintenance duty is (#11204): a name, an interval and a handler; plain data in, plain data out. */ |
| 2 | 2 | |
| 3 | 3 | import type { Database } from "bun:sqlite"; |
| 4 | import type { App } from "../app.ts"; | |
| 4 | 5 | |
| 5 | 6 | /** The number a finding rests on and when it was read: a query's result or a measurement. */ |
| 6 | 7 | export interface Probe { |
| @@ -26,6 +27,8 @@ export interface DutyResult { | ||
| 26 | 27 | export interface DutyContext { |
| 27 | 28 | readonly db: Database; |
| 28 | 29 | readonly now: Date; |
| 30 | /** The running app, for a duty that files or comments through the same actions a person uses. */ | |
| 31 | readonly app?: App | undefined; | |
| 29 | 32 | } |
| 30 | 33 | |
| 31 | 34 | export interface Duty { |
src/maintain/registry.ts +2 −1
| @@ -2,5 +2,6 @@ | ||
| 2 | 2 | |
| 3 | 3 | import type { Duty } from "./duty.ts"; |
| 4 | 4 | import { duty as pullsWaiting } from "./duties/stale_pulls.ts"; |
| 5 | import { duty as efficiencyWatcher } from "./duties/efficiency_watcher.ts"; | |
| 5 | 6 | |
| 6 | export const duties: readonly Duty[] = [pullsWaiting]; | |
| 7 | export const duties: readonly Duty[] = [pullsWaiting, efficiencyWatcher]; |
src/maintain/runner.ts +1 −1
| @@ -43,7 +43,7 @@ export function startMaintain(app: App, options: { duties?: readonly Duty[]; eve | ||
| 43 | 43 | let outcome = "ok"; |
| 44 | 44 | try { |
| 45 | 45 | // The duty keeps its `running` slot until it really settles, so a timed-out duty never overlaps itself. |
| 46 | const work = Promise.resolve().then(() => duty.run({ db: app.db, now })); | |
| 46 | const work = Promise.resolve().then(() => duty.run({ db: app.db, now, app })); | |
| 47 | 47 | work.then(() => running.delete(duty.name), () => running.delete(duty.name)); |
| 48 | 48 | let timer: ReturnType<typeof setTimeout> | undefined; |
| 49 | 49 | const deadline = new Promise<never>((_, reject) => { |
test/efficiency-baseline.test.ts added +32
| @@ -0,0 +1,32 @@ | ||
| 1 | /** The baseline (#7558): the median of the same hour over the last seven days, by hand. */ | |
| 2 | import { expect, test } from "bun:test"; | |
| 3 | import { baselineAt, median, MIN_DAYS } from "../src/efficiency/baseline.ts"; | |
| 4 | import { DAY, T0 } from "./helpers/efficiency.ts"; | |
| 5 | ||
| 6 | test("the median of an odd and an even count, by hand", () => { | |
| 7 | expect(median([5, 1, 3])).toBe(3); | |
| 8 | expect(median([4, 1, 3, 100])).toBe(3.5); | |
| 9 | expect(median([])).toBeUndefined(); | |
| 10 | }); | |
| 11 | ||
| 12 | test("the baseline is the median of this hour of the day over the last 7 days, and nothing else", () => { | |
| 13 | const s = new Map<number, number>(); | |
| 14 | [10, 20, 30, 40, 50, 60, 70].forEach((v, i) => s.set(T0 - (i + 1) * DAY, v)); // same hour, 1..7 days ago | |
| 15 | s.set(T0 - 3_600_000, 9999); // another hour: not the same hour of the day | |
| 16 | s.set(T0 - 8 * DAY, 9999); // eight days ago: outside the window | |
| 17 | expect(baselineAt(s, T0)).toBe(40); | |
| 18 | }); | |
| 19 | ||
| 20 | test("a spike is a median's outlier: one bad day does not move the baseline", () => { | |
| 21 | const s = new Map<number, number>(); | |
| 22 | [10, 10, 10, 10, 10, 10, 1000].forEach((v, i) => s.set(T0 - (i + 1) * DAY, v)); | |
| 23 | expect(baselineAt(s, T0)).toBe(10); | |
| 24 | }); | |
| 25 | ||
| 26 | test("under three days of history there is no baseline", () => { | |
| 27 | const s = new Map<number, number>(); | |
| 28 | for (let d = 1; d < MIN_DAYS; d++) s.set(T0 - d * DAY, 10); | |
| 29 | expect(baselineAt(s, T0)).toBeUndefined(); | |
| 30 | s.set(T0 - MIN_DAYS * DAY, 10); | |
| 31 | expect(baselineAt(s, T0)).toBe(10); | |
| 32 | }); |
test/efficiency-close-when-clear.test.ts added +45
| @@ -0,0 +1,45 @@ | ||
| 1 | /** Closing (#7558): back under for 24 hours closes the issue with a note; sooner does not. */ | |
| 2 | import { afterAll, beforeAll, expect, test } from "bun:test"; | |
| 3 | import { HOUR_MS } from "../src/efficiency/baseline.ts"; | |
| 4 | import { quietLogs } from "./helpers/globals.ts"; | |
| 5 | import { commentsOf, forge, flat, issuesOf, MiB, NPM, T0, watch } from "./helpers/efficiency.ts"; | |
| 6 | ||
| 7 | quietLogs(); | |
| 8 | let f: Awaited<ReturnType<typeof forge>>; | |
| 9 | beforeAll(async () => { f = await forge(); }); | |
| 10 | afterAll(() => f.done()); | |
| 11 | ||
| 12 | test("closed with a note after 24 hours back under, not before; a relapse resets the clock", () => { | |
| 13 | flat(f.app, T0); | |
| 14 | const bad = { [NPM]: 600 * MiB }; | |
| 15 | const ok = { [NPM]: 50 * MiB }; | |
| 16 | watch(f.app, T0 + 600_000, bad); | |
| 17 | watch(f.app, T0 + HOUR_MS + 600_000, bad); // files; last bad hour is T0+1h | |
| 18 | const [issue] = issuesOf(f.app, f.repoId); | |
| 19 | expect(issue!.state).toBe("open"); | |
| 20 | watch(f.app, T0 + 2 * HOUR_MS + 600_000, ok); | |
| 21 | watch(f.app, T0 + 20 * HOUR_MS + 600_000, ok); | |
| 22 | expect(issuesOf(f.app, f.repoId)[0]!.state).toBe("open"); | |
| 23 | watch(f.app, T0 + 25 * HOUR_MS + 300_000, ok); // 24 h after the last bad hour | |
| 24 | const after = issuesOf(f.app, f.repoId)[0]!; | |
| 25 | expect(after.state).toBe("closed"); | |
| 26 | expect(commentsOf(f.app, issue!.id).at(-1)).toContain("back under"); | |
| 27 | expect(commentsOf(f.app, issue!.id).at(-1)).toContain("24 hours"); | |
| 28 | }); | |
| 29 | ||
| 30 | test("a single bad hour inside the 24 resets the wait: closing comes 24 hours after it, not before", () => { | |
| 31 | f.app.db.exec("DELETE FROM efficiency_sample; DELETE FROM efficiency_finding; DELETE FROM comment; DELETE FROM issue"); | |
| 32 | const base = T0 + 40 * HOUR_MS; | |
| 33 | flat(f.app, base); | |
| 34 | const bad = { [NPM]: 600 * MiB }; | |
| 35 | const ok = { [NPM]: 50 * MiB }; | |
| 36 | watch(f.app, base + 600_000, bad); | |
| 37 | watch(f.app, base + HOUR_MS + 600_000, bad); // files; last bad hour is base+1h | |
| 38 | watch(f.app, base + 10 * HOUR_MS + 600_000, bad); // a stray bad hour, alone: last bad hour is base+10h | |
| 39 | watch(f.app, base + 26 * HOUR_MS + 600_000, ok); // 25 h after base+1h: would close had the stray done nothing | |
| 40 | expect(issuesOf(f.app, f.repoId)[0]!.state).toBe("open"); | |
| 41 | watch(f.app, base + 33 * HOUR_MS + 600_000, ok); // 23 h 10 min after the stray hour | |
| 42 | expect(issuesOf(f.app, f.repoId)[0]!.state).toBe("open"); | |
| 43 | watch(f.app, base + 34 * HOUR_MS + 300_000, ok); // 24 h 5 min after the stray hour | |
| 44 | expect(issuesOf(f.app, f.repoId)[0]!.state).toBe("closed"); | |
| 45 | }); |
test/efficiency-dedupe.test.ts added +43
| @@ -0,0 +1,43 @@ | ||
| 1 | /** One issue per cause (#7558): a comment while it stands, never a second issue. */ | |
| 2 | import { afterAll, beforeAll, expect, test } from "bun:test"; | |
| 3 | import { HOUR_MS } from "../src/efficiency/baseline.ts"; | |
| 4 | import { quietLogs } from "./helpers/globals.ts"; | |
| 5 | import { commentsOf, forge, flat, issuesOf, MiB, NPM, seed, T0, watch } from "./helpers/efficiency.ts"; | |
| 6 | ||
| 7 | quietLogs(); | |
| 8 | let f: Awaited<ReturnType<typeof forge>>; | |
| 9 | beforeAll(async () => { f = await forge(); }); | |
| 10 | afterAll(() => f.done()); | |
| 11 | ||
| 12 | test("a cost that stays bad gets one issue and one comment per hour", () => { | |
| 13 | flat(f.app, T0); | |
| 14 | const bad = { [NPM]: 600 * MiB }; | |
| 15 | watch(f.app, T0 + 600_000, bad); | |
| 16 | watch(f.app, T0 + HOUR_MS + 600_000, bad); // files | |
| 17 | watch(f.app, T0 + HOUR_MS + 1_200_000, bad); // same hour again: nothing more | |
| 18 | watch(f.app, T0 + 2 * HOUR_MS + 600_000, bad); | |
| 19 | watch(f.app, T0 + 3 * HOUR_MS + 600_000, bad); | |
| 20 | const issues = issuesOf(f.app, f.repoId); | |
| 21 | expect(issues).toHaveLength(1); | |
| 22 | const notes = commentsOf(f.app, issues[0]!.id); | |
| 23 | expect(notes).toHaveLength(2); | |
| 24 | expect(notes[0]).toContain("Still bad"); | |
| 25 | expect(notes[0]).toContain("600.00 MiB"); | |
| 26 | }); | |
| 27 | ||
| 28 | test("another cause files its own issue; a person's close makes the next finding a new issue", () => { | |
| 29 | f.app.db.exec("DELETE FROM efficiency_sample; DELETE FROM efficiency_finding; DELETE FROM comment; DELETE FROM issue"); | |
| 30 | const OTHER = "egress-other-bytes"; | |
| 31 | flat(f.app, T0); | |
| 32 | seed(f.app, OTHER, T0, 8 * 24, () => 100 * MiB); | |
| 33 | const second = { [NPM]: 600 * MiB, [OTHER]: 5 * 1024 * MiB }; | |
| 34 | for (let h = 0; h <= 1; h++) watch(f.app, T0 + h * HOUR_MS + 600_000, second); | |
| 35 | const issues = issuesOf(f.app, f.repoId); | |
| 36 | expect(issues).toHaveLength(2); | |
| 37 | expect(issues.filter((i) => i.title.includes("npm registry bytes"))).toHaveLength(1); | |
| 38 | expect(issues.filter((i) => i.title.includes("every other destination"))).toHaveLength(1); | |
| 39 | f.app.db.exec("UPDATE issue SET state = 'closed' WHERE title LIKE '%npm registry bytes%'"); | |
| 40 | watch(f.app, T0 + 2 * HOUR_MS + 600_000, second); | |
| 41 | expect(issuesOf(f.app, f.repoId).filter((i) => i.title.includes("npm registry bytes"))).toHaveLength(2); | |
| 42 | expect(issuesOf(f.app, f.repoId).filter((i) => i.title.includes("every other destination") && i.state === "open")).toHaveLength(1); | |
| 43 | }); |
test/efficiency-double.test.ts added +76
| @@ -0,0 +1,76 @@ | ||
| 1 | /** When a cost is bad (#7558): 2x for 2 hours, or a ceiling; flat files nothing; the #7541 series files within 3 hours. */ | |
| 2 | import { afterAll, beforeAll, expect, test } from "bun:test"; | |
| 3 | import { HOUR_MS } from "../src/efficiency/baseline.ts"; | |
| 4 | import { causeOf } from "../src/efficiency/causes.ts"; | |
| 5 | import { putSample } from "../src/efficiency/store.ts"; | |
| 6 | import { quietLogs } from "./helpers/globals.ts"; | |
| 7 | import { forge, flat, issuesOf, MiB, NPM, T0, watch } from "./helpers/efficiency.ts"; | |
| 8 | ||
| 9 | quietLogs(); | |
| 10 | let f: Awaited<ReturnType<typeof forge>>; | |
| 11 | beforeAll(async () => { f = await forge(); }); | |
| 12 | afterAll(() => f.done()); | |
| 13 | const reset = () => { f.app.db.exec("DELETE FROM efficiency_sample; DELETE FROM efficiency_finding; DELETE FROM comment; DELETE FROM issue"); }; | |
| 14 | ||
| 15 | test("a flat series files nothing", () => { | |
| 16 | reset(); | |
| 17 | flat(f.app, T0); | |
| 18 | for (let h = 0; h < 6; h++) { | |
| 19 | const r = watch(f.app, T0 + h * HOUR_MS + 600_000, { [NPM]: 50 * MiB }); | |
| 20 | expect(r.findings).toEqual([]); | |
| 21 | } | |
| 22 | expect(issuesOf(f.app, f.repoId)).toEqual([]); | |
| 23 | }); | |
| 24 | ||
| 25 | test("npm bytes jump 10x for 2 hours: one issue with cause, numbers and baseline", () => { | |
| 26 | reset(); | |
| 27 | flat(f.app, T0); | |
| 28 | expect(watch(f.app, T0 + 600_000, { [NPM]: 500 * MiB }).findings).toEqual([]); // one hour is not yet two | |
| 29 | expect(issuesOf(f.app, f.repoId)).toEqual([]); | |
| 30 | const r = watch(f.app, T0 + HOUR_MS + 600_000, { [NPM]: 500 * MiB }); | |
| 31 | expect(r.findings).toHaveLength(1); | |
| 32 | expect(r.findings[0]!.probe?.number).toBe(500 * MiB); | |
| 33 | const issues = issuesOf(f.app, f.repoId); | |
| 34 | expect(issues).toHaveLength(1); | |
| 35 | expect(issues[0]!.title).toContain("npm registry bytes"); | |
| 36 | expect(issues[0]!.body).toContain("500.00 MiB"); | |
| 37 | expect(issues[0]!.body).toContain("baseline 50.00 MiB"); | |
| 38 | expect(issues[0]!.body).toContain("registry.npmjs.org:443"); | |
| 39 | expect(issues[0]!.body).toContain("2x"); | |
| 40 | }); | |
| 41 | ||
| 42 | test("an hour over the ceiling files at once", () => { | |
| 43 | reset(); | |
| 44 | flat(f.app, T0); | |
| 45 | watch(f.app, T0 + 600_000, { [NPM]: causeOf(NPM)!.ceiling! }); | |
| 46 | expect(issuesOf(f.app, f.repoId)[0]!.body).toContain("ceiling"); | |
| 47 | }); | |
| 48 | ||
| 49 | test("a doubling under the floor is noise and files nothing", () => { | |
| 50 | reset(); | |
| 51 | flat(f.app, T0, 1 * MiB); | |
| 52 | watch(f.app, T0 + 600_000, { [NPM]: 10 * MiB }); | |
| 53 | watch(f.app, T0 + HOUR_MS + 600_000, { [NPM]: 10 * MiB }); | |
| 54 | expect(issuesOf(f.app, f.repoId)).toEqual([]); | |
| 55 | }); | |
| 56 | ||
| 57 | test("replaying #7541 (~1.25 GiB an hour over a quiet week) files within 3 hours of the first bad hour", () => { | |
| 58 | reset(); | |
| 59 | flat(f.app, T0, 40 * MiB); | |
| 60 | const bad = 1.25 * 1024 * MiB; | |
| 61 | let filedAfter = -1; | |
| 62 | for (let h = 0; h < 6 && filedAfter < 0; h++) { | |
| 63 | watch(f.app, T0 + h * HOUR_MS + 3_500_000, { [NPM]: bad }); | |
| 64 | if (issuesOf(f.app, f.repoId).length > 0) filedAfter = h + 1; | |
| 65 | } | |
| 66 | expect(filedAfter).toBeGreaterThan(0); | |
| 67 | expect(filedAfter).toBeLessThanOrEqual(3); | |
| 68 | }); | |
| 69 | ||
| 70 | test("a forge with under three days of history files nothing by doubling", () => { | |
| 71 | reset(); | |
| 72 | for (let h = 1; h <= 30; h++) putSample(f.app.db, NPM, T0 - h * HOUR_MS, 50 * MiB); | |
| 73 | watch(f.app, T0 + 600_000, { [NPM]: 900 * MiB }); | |
| 74 | watch(f.app, T0 + HOUR_MS + 600_000, { [NPM]: 900 * MiB }); | |
| 75 | expect(issuesOf(f.app, f.repoId)).toEqual([]); | |
| 76 | }); |
test/efficiency-hit-rate.test.ts added +84
| @@ -0,0 +1,84 @@ | ||
| 1 | /** The install cache hit rate (#7558): counted per contained install, and bad when it falls to half its baseline for 2 hours. */ | |
| 2 | import { afterAll, beforeAll, beforeEach, expect, test } from "bun:test"; | |
| 3 | import { HOUR_MS } from "../src/efficiency/baseline.ts"; | |
| 4 | import { hitRateLastHour, MIN_INSTALLS, noteInstall, resetInstalls } from "../src/efficiency/installs.ts"; | |
| 5 | import { hourVerdict } from "../src/efficiency/judge.ts"; | |
| 6 | import { causeOf, show } from "../src/efficiency/causes.ts"; | |
| 7 | import { meteredInstall } from "../src/checks/install.ts"; | |
| 8 | import { resetEgressTotals } from "../src/apps/egress.ts"; | |
| 9 | import { quietLogs } from "./helpers/globals.ts"; | |
| 10 | import { putSample, readSeries } from "../src/efficiency/store.ts"; | |
| 11 | import { forge, issuesOf, seed, T0, watch } from "./helpers/efficiency.ts"; | |
| 12 | ||
| 13 | quietLogs(); | |
| 14 | const HIT = "install-cache-hit-rate"; | |
| 15 | let f: Awaited<ReturnType<typeof forge>>; | |
| 16 | beforeAll(async () => { f = await forge(); }); | |
| 17 | afterAll(() => f.done()); | |
| 18 | beforeEach(() => { | |
| 19 | resetInstalls(); | |
| 20 | f.app.db.exec("DELETE FROM efficiency_sample; DELETE FROM efficiency_finding; DELETE FROM comment; DELETE FROM issue"); | |
| 21 | }); | |
| 22 | ||
| 23 | test("the counter gives the share of the last hour's installs that missed no cache, and none under 5 installs", () => { | |
| 24 | const t = T0 + 600_000; | |
| 25 | for (let i = 0; i < MIN_INSTALLS - 1; i++) noteInstall(false, t); | |
| 26 | expect(hitRateLastHour(t)).toBeUndefined(); | |
| 27 | noteInstall(true, t); // 4 hits, 1 miss | |
| 28 | expect(hitRateLastHour(t)).toBe(0.8); | |
| 29 | expect(hitRateLastHour(t + HOUR_MS + 1)).toBeUndefined(); // aged out | |
| 30 | }); | |
| 31 | ||
| 32 | test("a contained install over 1 MiB from the registry is counted as a miss", async () => { | |
| 33 | resetEgressTotals(); | |
| 34 | await meteredInstall("app:t/preview", "r1", async () => 1, () => {}); | |
| 35 | const { installsLastHour } = await import("../src/efficiency/installs.ts"); | |
| 36 | expect(installsLastHour(Date.now())).toEqual({ installs: 1, misses: 0 }); | |
| 37 | await meteredInstall(undefined, undefined, async () => 1, () => {}); // uncontained: not counted | |
| 38 | expect(installsLastHour(Date.now()).installs).toBe(1); | |
| 39 | }); | |
| 40 | ||
| 41 | test("a hit rate at or under half its baseline is a fall; above half, or a baseline under the floor, is not", () => { | |
| 42 | const c = causeOf(HIT)!; | |
| 43 | const hour = T0; | |
| 44 | const base = (v: number) => new Map(Array.from({ length: 7 }, (_, d) => [hour - (d + 1) * 24 * HOUR_MS, v] as const).concat([[hour, 0]])); | |
| 45 | expect(hourVerdict(c, new Map(base(0.9)).set(hour, 0.45), hour)?.fell).toBe(true); | |
| 46 | expect(hourVerdict(c, new Map(base(0.9)).set(hour, 0.46), hour)?.fell).toBe(false); | |
| 47 | expect(hourVerdict(c, new Map(base(0.4)).set(hour, 0), hour)?.fell).toBe(false); // baseline under the 50% floor | |
| 48 | expect(hourVerdict(c, new Map(base(0.9)).set(hour, 1), hour)?.doubled).toBe(false); // a rise is never bad here | |
| 49 | expect(show(c, 0.456)).toBe("45.6%"); | |
| 50 | }); | |
| 51 | ||
| 52 | test("a hit rate that falls for 2 hours files one issue naming the rate, its baseline and the install path", () => { | |
| 53 | seed(f.app, HIT, T0, 8 * 24, () => 0.95); | |
| 54 | expect(watch(f.app, T0 + 600_000, { [HIT]: 0.2 }).findings).toEqual([]); // one hour is not two | |
| 55 | const r = watch(f.app, T0 + HOUR_MS + 600_000, { [HIT]: 0.2 }); | |
| 56 | expect(r.findings).toHaveLength(1); | |
| 57 | const issues = issuesOf(f.app, f.repoId); | |
| 58 | expect(issues).toHaveLength(1); | |
| 59 | expect(issues[0]!.title).toContain("install cache hit rate"); | |
| 60 | expect(issues[0]!.title).toContain("below"); | |
| 61 | expect(issues[0]!.body).toContain("20.0%"); | |
| 62 | expect(issues[0]!.body).toContain("baseline 95.0%"); | |
| 63 | expect(issues[0]!.body).toContain("at most half"); | |
| 64 | expect(issues[0]!.body).toContain("meteredInstall"); | |
| 65 | }); | |
| 66 | ||
| 67 | test("a steady hit rate files nothing", () => { | |
| 68 | seed(f.app, HIT, T0, 8 * 24, () => 0.95); | |
| 69 | for (let h = 0; h < 4; h++) expect(watch(f.app, T0 + h * HOUR_MS + 600_000, { [HIT]: 0.9 }).findings).toEqual([]); | |
| 70 | expect(issuesOf(f.app, f.repoId)).toEqual([]); | |
| 71 | }); | |
| 72 | ||
| 73 | test("a second, higher hit rate in the same hour does not hide a fall: the lower reading stands", () => { | |
| 74 | seed(f.app, HIT, T0, 8 * 24, () => 0.95); | |
| 75 | watch(f.app, T0 + 600_000, { [HIT]: 0.2 }); | |
| 76 | watch(f.app, T0 + HOUR_MS + 600_000, { [HIT]: 0.2 }); | |
| 77 | watch(f.app, T0 + HOUR_MS + 1_800_000, { [HIT]: 0.9 }); // a restart's pass in the same hour, kinder | |
| 78 | expect(readSeries(f.app.db, HIT, T0 + HOUR_MS).get(T0 + HOUR_MS)).toBe(0.2); | |
| 79 | expect(issuesOf(f.app, f.repoId)).toHaveLength(1); | |
| 80 | // A rising cost keeps the larger of two readings in one hour. | |
| 81 | putSample(f.app.db, "npm-registry-bytes", T0, 10); | |
| 82 | putSample(f.app.db, "npm-registry-bytes", T0, 5); | |
| 83 | expect(readSeries(f.app.db, "npm-registry-bytes", T0).get(T0)).toBe(10); | |
| 84 | }); |
test/efficiency-runner.test.ts added +78
| @@ -0,0 +1,78 @@ | ||
| 1 | /** The duty through the runner (#7558): `app` reaches it, so findings stand and a missing FORGE_REPO says why nothing was filed. */ | |
| 2 | import { afterAll, beforeAll, beforeEach, expect, test } from "bun:test"; | |
| 3 | import { mkdtempSync, rmSync } from "node:fs"; | |
| 4 | import { tmpdir } from "node:os"; | |
| 5 | import { join } from "node:path"; | |
| 6 | import { createApp, type App } from "../src/app.ts"; | |
| 7 | import { HOUR_MS, hourStart } from "../src/efficiency/baseline.ts"; | |
| 8 | import { noteInstall, resetInstalls } from "../src/efficiency/installs.ts"; | |
| 9 | import { putSample } from "../src/efficiency/store.ts"; | |
| 10 | import { watch } from "../src/efficiency/watch.ts"; | |
| 11 | import { duty } from "../src/maintain/duties/efficiency_watcher.ts"; | |
| 12 | import { duties } from "../src/maintain/registry.ts"; | |
| 13 | import { startMaintain } from "../src/maintain/runner.ts"; | |
| 14 | import { latest } from "../src/maintain/runs.ts"; | |
| 15 | import { runLines } from "../src/tui/screens/maintainruns.ts"; | |
| 16 | import { quietLogs } from "./helpers/globals.ts"; | |
| 17 | ||
| 18 | quietLogs(); | |
| 19 | const HIT = "install-cache-hit-rate"; | |
| 20 | let root = ""; | |
| 21 | let app: App; | |
| 22 | beforeAll(() => { | |
| 23 | root = mkdtempSync(join(tmpdir(), "forge-efficiency-run-")); | |
| 24 | app = createApp({ dataDir: root, port: 0 }); // no FORGE_REPO | |
| 25 | }); | |
| 26 | afterAll(() => rmSync(root, { recursive: true, force: true })); | |
| 27 | beforeEach(() => { | |
| 28 | resetInstalls(); | |
| 29 | app.db.exec("DELETE FROM efficiency_sample; DELETE FROM maintenance_run"); | |
| 30 | }); | |
| 31 | ||
| 32 | /** A week of 95% hit rates, a bad hour before `now`, and this hour's installs all missing. */ | |
| 33 | function falling(now: number): void { | |
| 34 | const hour = hourStart(now); | |
| 35 | for (let h = 2; h <= 8 * 24; h++) putSample(app.db, HIT, hour - h * HOUR_MS, 0.95); | |
| 36 | putSample(app.db, HIT, hour - HOUR_MS, 0.1); | |
| 37 | for (let i = 0; i < 6; i++) noteInstall(true, now - 1000); | |
| 38 | } | |
| 39 | ||
| 40 | test("run by the runner with the app, the duty finds the fall; the admin screen lists it", async () => { | |
| 41 | expect(duties.map((d) => d.name)).toContain("efficiency-watcher"); | |
| 42 | const now = Date.now(); | |
| 43 | falling(now); | |
| 44 | const m = startMaintain(app, { duties: [duty], everyMs: 1e9 }); | |
| 45 | m.stop(); | |
| 46 | await m.tick(new Date(now)); | |
| 47 | const [row] = latest(app.db, 1); | |
| 48 | expect(row!.duty).toBe("efficiency-watcher"); | |
| 49 | expect(row!.outcome).toBe("ok"); | |
| 50 | expect(row!.findings.length).toBeGreaterThanOrEqual(1); | |
| 51 | expect(JSON.stringify(row!.findings)).toContain("install cache hit rate"); | |
| 52 | expect(row!.probes.length).toBe(row!.findings.length); | |
| 53 | const as = (isAdmin: boolean) => ({ user: { isAdmin }, db: app.db }) as never; | |
| 54 | expect(runLines(as(true)).some((l) => l.startsWith("efficiency-watcher"))).toBe(true); | |
| 55 | expect(runLines(as(false))).toEqual([]); | |
| 56 | }); | |
| 57 | ||
| 58 | test("without FORGE_REPO the findings stand but the run says why nothing was filed", async () => { | |
| 59 | const now = Date.now(); | |
| 60 | falling(now); | |
| 61 | const m = startMaintain(app, { duties: [duty], everyMs: 1e9 }); | |
| 62 | m.stop(); | |
| 63 | await m.tick(new Date(now)); | |
| 64 | const [row] = latest(app.db, 1); | |
| 65 | expect(row!.actions.join("\n")).toContain("filed nothing: FORGE_REPO is not set"); | |
| 66 | expect(app.db.query("SELECT COUNT(*) AS n FROM issue").get()).toEqual({ n: 0 }); | |
| 67 | }); | |
| 68 | ||
| 69 | test("a FORGE_REPO that names no repository says so", () => { | |
| 70 | const now = Date.now(); | |
| 71 | falling(now); | |
| 72 | const other = createApp({ dataDir: mkdtempSync(join(tmpdir(), "forge-efficiency-run2-")), port: 0, forgeRepo: "ghost/forge" }); | |
| 73 | const hour = hourStart(now); | |
| 74 | for (let h = 2; h <= 8 * 24; h++) putSample(other.db, HIT, hour - h * HOUR_MS, 0.95); | |
| 75 | putSample(other.db, HIT, hour - HOUR_MS, 0.1); | |
| 76 | const r = watch(other, now, { [HIT]: 0.1 }); | |
| 77 | expect(r.actions.join("\n")).toContain('names no repository on this forge'); | |
| 78 | }); |
test/helpers/efficiency.ts added +42
| @@ -0,0 +1,42 @@ | ||
| 1 | /** A forge with a repository, and hourly series seeded for the efficiency watcher (#7558). */ | |
| 2 | import { mkdtempSync, rmSync } from "node:fs"; | |
| 3 | import { tmpdir } from "node:os"; | |
| 4 | import { join } from "node:path"; | |
| 5 | import { createApp, type App } from "../../src/app.ts"; | |
| 6 | import { createRepo } from "../../src/core/repos.ts"; | |
| 7 | import { createUser } from "../../src/core/users.ts"; | |
| 8 | import { HOUR_MS } from "../../src/efficiency/baseline.ts"; | |
| 9 | import { putSample } from "../../src/efficiency/store.ts"; | |
| 10 | import { watch } from "../../src/efficiency/watch.ts"; | |
| 11 | ||
| 12 | export const MiB = 1024 ** 2; | |
| 13 | export const DAY = 24 * HOUR_MS; | |
| 14 | /** 2026-11-20T00:00Z: an hour boundary. */ | |
| 15 | export const T0 = Date.parse("2026-11-20T00:00:00Z"); | |
| 16 | export const NPM = "npm-registry-bytes"; | |
| 17 | ||
| 18 | export async function forge(): Promise<{ app: App; repoId: string; done(): void }> { | |
| 19 | const root = mkdtempSync(join(tmpdir(), "forge-efficiency-")); | |
| 20 | const app = createApp({ dataDir: root, port: 0, forgeRepo: "alice/forge" }); | |
| 21 | const u = await createUser(app.db, { origin: "seed", trusted: true, username: "alice", email: "[email protected]", password: "a-good-passphrase", adminIfFirst: true }); | |
| 22 | if (!u.ok) throw new Error("user"); | |
| 23 | const r = await createRepo(app.db, app.reposRoot, { ownerId: u.value.id, name: "forge", visibility: "public", description: "" }); | |
| 24 | if (!r.ok) throw new Error("repo"); | |
| 25 | return { app, repoId: r.value.id, done: () => rmSync(root, { recursive: true, force: true }) }; | |
| 26 | } | |
| 27 | ||
| 28 | /** `hours` readings ending the hour before `end`, each `value(i)` with i counting from the first. */ | |
| 29 | export function seed(app: App, cause: string, end: number, hours: number, value: (i: number) => number): void { | |
| 30 | for (let i = 0; i < hours; i++) putSample(app.db, cause, end - (hours - i) * HOUR_MS, value(i)); | |
| 31 | } | |
| 32 | ||
| 33 | export const flat = (app: App, end: number, v = 50 * MiB): void => seed(app, NPM, end, 8 * 24, () => v); | |
| 34 | ||
| 35 | export function issuesOf(app: App, repoId: string): { id: string; number: number; title: string; state: string; body: string }[] { | |
| 36 | return app.db.query("SELECT id, number, title, state, body FROM issue WHERE repo_id = ?1 ORDER BY number").all(repoId) as never; | |
| 37 | } | |
| 38 | ||
| 39 | export const commentsOf = (app: App, issueId: string): string[] => | |
| 40 | (app.db.query("SELECT body FROM comment WHERE issue_id = ?1 ORDER BY rowid").all(issueId) as { body: string }[]).map((c) => c.body); | |
| 41 | ||
| 42 | export { watch }; |
new above
offline
Comment says bytes or seconds; the type also has "ratio". Update.