dd9d4ed · 8069cf2 · 8ec0c12 · 9b71753
@@ -2,4 +2,6 @@
`src/perf/` keeps a capped in-memory record of real requests per route pattern (total, each Server-Timing phase, signed in or out; no paths, ids or queries). `budgets.ts` holds the budgets in words with the number beside them. Once a minute `duty.ts` files one issue per route and phase in the forge's repo when p95 has been over budget for 15 min with 20+ real requests; the finding names the slowest phase, its share and the cache hit rate. `git.ts` keeps the same record for every git process the forge spawns (`git/env.ts`, `git/local.ts`), keyed `git <subcommand>` from a fixed list (never an argument, path or ref; anything else is `git other`), timed from before the spawn gate so a queue counts; a subcommand whose p95 passes its budget the same way (250 ms; 10 s for the pack-moving ones: clone, fetch, push, gc, repack, pack-objects and the like) files one issue naming it, its count, p50 and p95. `loop.ts` names the routes running across an event-loop stall in the `loop` log line; nothing is kept beyond that line. `loop_worst.ts` keeps the worst event-loop lag of the last 10 s (ten one-second slots fed by the 50 ms sampler) and every response's Server-Timing names it as `lag;dur`; `/healthz` answers it as `loopLagMs` to `Accept: application/json`, so a slow time to first byte with a small `app;dur` reads as a stall outside the handler.
Not yet: a synthetic probe for routes with no traffic (a client-written label would let anyone hide requests; it needs an admin-only door first), live route stats in the terminal and MCP (findings reach both doors as issues), browser timings, 24 h/7 d history, the board page, release before/after.
`history.ts` (#11477): every tick the duty folds the record's new samples into an in-memory ledger under the hour each sample happened in (so 10:50 traffic is never stamped 11:00) and upserts one row per route pattern (route, hour, n, p50, p95) into `route_hour`, so a row is the hour's p50 and p95, not the last 15 minutes'. At most 5,000 samples per route and hour are kept (past it the row stands on the first), at most 200 routes (the busiest) and 168 hours; older rows go in the same write. A restart starts an empty ledger: an empty record writes nothing, and a row is never replaced by one with fewer requests, so the hours before the restart keep the fuller row. Admins read them at `GET /api/v1/telemetry/routes?hours=N` (1 to 168, default 24; else 400).
Not yet: a synthetic probe for routes with no traffic (a client-written label would let anyone hide requests; it needs an admin-only door first), route-hour stats in the terminal and MCP (findings reach it as issues), browser timings, the board page, release before/after.
@@ -0,0 +1,11 @@
import type { Route } from "../shared.ts";
export const route: Route = {
  method: "get",
  path: "/api/v1/telemetry/routes",
  summary: "Route p50 and p95 by the hour, kept 7 days (a forge admin's, read scope): { hours, rows: [{ route, hour, n, p50, p95 }] }, hour is hours since the epoch, ms; hours 1 to 168 (default 24), a bad value is a 400",
  auth: true,
  role: "admin",
  query: { hours: { type: "integer", min: 1, max: 168 } },
  refusals: { unauthorized: "no valid credentials were sent", forbidden: "the caller is not a forge admin" },
};
@@ -190,6 +190,7 @@
export { route as getApiV1SecretsScope } from "./getApiV1SecretsScope.ts";
export { route as getApiV1TelemetryFlow } from "./getApiV1TelemetryFlow.ts";
export { route as getApiV1TelemetryHistory } from "./getApiV1TelemetryHistory.ts";
export { route as getApiV1TelemetryHome } from "./getApiV1TelemetryHome.ts";
export { route as getApiV1TelemetryRoutes } from "./getApiV1TelemetryRoutes.ts";
export { route as getApiV1TelemetrySources } from "./getApiV1TelemetrySources.ts";
export { route as getApiV1TelemetrySystem } from "./getApiV1TelemetrySystem.ts";
export { route as getApiV1Tokens } from "./getApiV1Tokens.ts";
@@ -0,0 +1,1 @@
8f9e39fd2e6e41bd2b4f2524fa63c5bef9d2f223b5bcb8a7ac43297daa3a3efc
@@ -0,0 +1,13 @@
// `route_hour` (#11477): per route pattern and hour, how many requests and their p50 and p95
// in ms, written once an hour by the performance watcher, kept 7 days. New table only. Additive.
export default `
  CREATE TABLE route_hour (
    route TEXT    NOT NULL,
    hour  INTEGER NOT NULL,
    n     INTEGER NOT NULL,
    p50   REAL    NOT NULL,
    p95   REAL    NOT NULL,
    PRIMARY KEY (route, hour)
  ) WITHOUT ROWID;
  CREATE INDEX route_hour_hour ON route_hour (hour);
  `;
@@ -63,6 +63,7 @@
import { receiveBeat, SIGNATURE_HEADER } from "../spawn/heartbeat.ts";
import { takeOrTell } from "../actions/follow.ts";
import { noteRead, telemetryReader, type Reader } from "../actions/telemetry.ts";
import { flowCopy, flowEtag, flowMaxAge } from "../system/flow_cache.ts";
import { readHours, routeHours } from "../perf/history.ts";
import { countRead } from "../system/telemetry_reads.ts";
import { historyFor, sourcesOut, systemWithReaders, welcome } from "../system/telemetry.ts";
import { weekCard, WEEK_DAYS } from "../crew/week_card.ts";
@@ -1353,6 +1354,19 @@
export function apiRoutes(router: Router<Handler>): void {
    return timePhase(ctx.request, "render", () => json(card));
  });
  // Route p50/p95 by the hour, kept 7 days (`perf/history.ts`); admin.
  router.add("GET", "/api/v1/telemetry/routes", (ctx) => {
    notePhase(ctx.request, "session", takeSessionTime(ctx.request));
    const denied = requireScope(ctx, "ro");
    if (denied) return denied;
    if (!ctx.auth.user) return unauthorized();
    if (ctx.auth.user.isAdmin !== true) return forbidden();
    const hours = readHours(ctx.url.searchParams.get("hours"));
    if (hours === null) return apiError("invalid_hours", 400, "hours is a whole number from 1 to 168");
    const rows = timePhase(ctx.request, "read", () => routeHours(ctx.app.db, hours));
    return timePhase(ctx.request, "render", () => json({ hours, rows }));
  });
  // The week's line per crew member (`crew/week_card.ts`); as MCP `crew` with kind "week".
  router.add("GET", "/api/v1/crew/week", (ctx) => {
    notePhase(ctx.request, "session", takeSessionTime(ctx.request));
@@ -4,7 +4,8 @@
 * issue in the forge's own repository, opened by its owner. A title already
 * open is not filed twice, and neither is a key this process has filed. A
 * slow route or subcommand is a defect: filed with its kind's labels, a `bug`
 * on its clock (#8856).
 * on its clock (#8856). Each tick it also folds the new samples into the hour's p50 and p95
 * per route in `route_hour` (`history.ts`, #11477).
 */
import type { App } from "../app.ts";
@@ -17,6 +18,7 @@
import { createGitRecord } from "./git.ts";
import type { PerfRecord } from "./record.ts";
import { evaluate, evaluateGit, fresh } from "./watch.ts";
import { during } from "./jobs.ts";
import { createHourLedger } from "./history.ts";
export const TICK_MS = 60_000;
@@ -26,9 +28,17 @@
export function startPerfWatcher(
  now: () => number = Date.now,
  everyMs = TICK_MS,
  gitRecord: PerfRecord = createGitRecord(),
): () => void {
): (() => void) & { tick: () => void } {
  const ledger = createHourLedger();
  const filed = new Set<string>();
  const tick = (): void => {
    try {
      // Each tick folds the new samples into their own hour's row, off the request path (#11477).
      ledger.note(record, now());
      
        sentinelcrew
        3h ago
        outdated
      
      Hour is taken from now, but the window summarised is the 15 minutes before now; at the first tick of an hour that traffic belongs to the previous hour. Also wrote=-1 lets a restart write an empty/near-empty hour and skip the real write.
    
      ledger.write(app.db, now());
    } catch (error) {
      app.log.warn("route history write failed", { error: String(error) });
    }
    try {
      const slug = app.config.forgeRepo;
      if (slug === undefined) return;
@@ -49,5 +59,5 @@
export function startPerfWatcher(
  };
  const timer = setInterval(() => during("perf-watcher", tick), everyMs);
  timer.unref();
  return () => clearInterval(timer);
  return Object.assign(() => clearInterval(timer), { tick });
}
@@ -0,0 +1,106 @@
/**
 * Route p95 by the hour, kept 7 days (#11477): every watcher tick folds the
 * record's new samples into the hour they happened in and upserts one row per
 * route pattern (n, p50, p95) for it into `route_hour`, at most `MAX_ROUTES`
 * routes, and deletes rows older than `MAX_HOURS` in the same write. Route patterns only, as in `record.ts`.
 */
import type { Database } from "bun:sqlite";
import { percentile, type PerfRecord } from "./record.ts";
export const HOUR_MS = 3_600_000;
export const MAX_HOURS = 168;
export const MAX_ROUTES = 200;
export interface RouteHour {
  readonly route: string;
  readonly hour: number;
  readonly n: number;
  readonly p50: number;
  readonly p95: number;
}
/** Samples kept per route and hour; past it an hour's row stands on its first `MAX_HOUR_SAMPLES`. */
export const MAX_HOUR_SAMPLES = 5_000;
/**
 * The hour's samples per route, filled from the record's window every tick, so a row is the hour's
 * p50 and p95 and not the last 15 minutes'. Each sample is filed under the hour of its own `at`, so
      
        sentinelcrew
        3h ago
        outdated
      
      Stamping hour from now mislabels the window (since = now - WINDOW_MS). Use the hour the window ended in, and test at minute 0.
    
 * traffic at 10:50 is never stamped 11:00. In memory only; `write` keeps the rows of the hours it
 * touched current in `route_hour`.
 */
export interface HourLedger {
  /** Take the record's samples newer than the last call and at or before `now`. */
  note(record: PerfRecord, now: number): void;
  /** Upsert the rows of the hours that took samples since the last write; returns rows written. */
  write(db: Database, now: number): number;
}
export function createHourLedger(): HourLedger {
  const hours = new Map<number, Map<string, number[]>>();
  const touched = new Set<number>();
  let last = 0;
  return {
    note(record, now) {
      for (const route of record.patterns()) {
        for (const s of record.traffic(route, last + 1)) {
          if (s.at > now) continue;
          const hour = Math.floor(s.at / HOUR_MS);
          let routes = hours.get(hour);
          if (!routes) hours.set(hour, (routes = new Map()));
          let ms = routes.get(route);
          if (!ms) routes.set(route, (ms = []));
          if (ms.length < MAX_HOUR_SAMPLES) ms.push(s.ms);
          touched.add(hour);
        }
      }
      last = Math.max(last, now);
    },
    write(db, now) {
      const current = Math.floor(now / HOUR_MS);
      let written = 0;
      db.transaction(() => {
        // A restart starts with an empty ledger: a row never shrinks to a thinner sample of its hour.
        const put = db.query(
          `INSERT INTO route_hour (route, hour, n, p50, p95) VALUES (?1, ?2, ?3, ?4, ?5)
           ON CONFLICT (route, hour) DO UPDATE SET n = excluded.n, p50 = excluded.p50, p95 = excluded.p95
           WHERE excluded.n >= route_hour.n`,
        );
        for (const hour of touched) {
          const rows: RouteHour[] = [];
          for (const [route, ms] of hours.get(hour) ?? [])
            rows.push({ route, hour, n: ms.length, p50: percentile(ms, 50)!, p95: percentile(ms, 95)! });
          // The busiest routes survive the cap.
          rows.sort((x, y) => y.n - x.n);
          for (const r of rows.slice(0, MAX_ROUTES)) {
            put.run(r.route, r.hour, r.n, r.p50, r.p95);
            written++;
          }
        }
        db.query("DELETE FROM route_hour WHERE hour <= ?1").run(current - MAX_HOURS);
      })();
      touched.clear();
      // An hour two behind can take no more samples (the window is 15 minutes).
      for (const hour of hours.keys()) if (hour < current - 1) hours.delete(hour);
      return written;
    },
  };
}
/** The last `hours` hours (1 to 168) up to `now`, oldest first. */
export function routeHours(db: Database, hours: number, now: number = Date.now()): RouteHour[] {
  const last = Math.floor(now / HOUR_MS);
  return db
    .query<RouteHour, [number, number]>(
      "SELECT route, hour, n, p50, p95 FROM route_hour WHERE hour > ?1 AND hour <= ?2 ORDER BY hour, route",
    )
    .all(last - hours, last);
}
/** `?hours=` as a whole number 1 to 168 (default 24), or null. */
export function readHours(raw: string | null): number | null {
  if (raw === null) return 24;
  if (!/^[0-9]{1,3}$/.test(raw)) return null;
  const n = Number(raw);
  return n >= 1 && n <= MAX_HOURS ? n : null;
}
@@ -90,3 +90,19 @@
test("a slow route is filed as a bug, so its clock runs from the filing (#8856)"
  const issue = listIssues(app.db, repo.id, { state: "open" }).find((i) => i.title === "/ is over its budget: kpis")!;
  expect(labelsFor(app.db, issue.id).map((l) => l.name)).toEqual(["bug"]);
});
test("the watcher folds each tick into its hour's row, driven without timers (#11477)", () => {
  app.db.query("DELETE FROM route_hour").run();
  let t = now;
  const rec = slow();
  const stop = startPerfWatcher(app, rec, () => t, 3_600_000);
  const rows = () => app.db.query<{ hour: number; n: number }, []>("SELECT hour, n FROM route_hour ORDER BY hour").all();
  stop.tick();
  expect(rows().length).toBe(1);
  const first = rows()[0]!;
  t += 60_000;
  rec.add("/", { at: t - 1000, ms: 9, signedIn: false, phases: [] });
  stop.tick();
  expect(rows()).toEqual([{ hour: first.hour, n: first.n + 1 }]); // same hour: the row grows
  stop();
});
@@ -0,0 +1,147 @@
/** Route p95 by the hour (#11477): the write, the cap, the purge, and the admin read. */
import { afterAll, beforeAll, expect, test } from "bun:test";
import { mkdtemp, rm } from "node:fs/promises";
import { tmpdir } from "node:os";
import { join } from "node:path";
import { createApp, type App } from "../src/app.ts";
import { createToken } from "../src/core/tokens.ts";
import { createUser } from "../src/core/users.ts";
import { serve, type Servers } from "../src/http/server.ts";
import { createHourLedger, HOUR_MS, MAX_HOURS, MAX_ROUTES, readHours, routeHours, type HourLedger } from "../src/perf/history.ts";
import { createPerfRecord } from "../src/perf/record.ts";
import { seedAdmin } from "./helpers/admin.ts";
import { quietLogs } from "./helpers/globals.ts";
quietLogs();
let dir: string;
let app: App;
let servers: Servers;
let adminToken: string;
let plainToken: string;
const now = 500 * HOUR_MS + 30 * 60_000;
const hour = 500;
const recordWith = (routes: number, each = 10) => {
  const r = createPerfRecord();
  for (let i = 0; i < routes; i++)
    for (let k = 1; k <= each; k++) r.add(`/r${i}`, { at: now - k * 1000, ms: k * 10 + i, signedIn: false, phases: [] });
  return r;
};
beforeAll(async () => {
  dir = await mkdtemp(join(tmpdir(), "forge-perf-history-"));
  app = createApp({ dataDir: dir, port: 0 });
  servers = await serve(app);
  const a = await seedAdmin(app, { username: "ada", email: "[email protected]" });
  if (!a.ok) throw new Error(a.error);
  adminToken = createToken(app.db, a.value.id, "t", "ro").token;
  const b = await createUser(app.db, { origin: "seed", trusted: true, username: "bob", email: "[email protected]", password: "a-good-passphrase" });
  if (!b.ok) throw new Error(String(b.error));
  plainToken = createToken(app.db, b.value.id, "t", "ro").token;
});
afterAll(async () => {
  await servers.stop();
  app.close();
  await rm(dir, { recursive: true, force: true });
});
const count = () => app.db.query<{ n: number }, []>("SELECT COUNT(*) AS n FROM route_hour").get()!.n;
const feed = (r: ReturnType<typeof createPerfRecord>, at: number, ms: number, route = "/r0") =>
  r.add(route, { at, ms, signedIn: false, phases: [] });
const step = (ledger: HourLedger, r: ReturnType<typeof createPerfRecord>, t: number) => {
  ledger.note(r, t);
  return ledger.write(app.db, t);
};
test("a write keeps one row per route with n, p50 and p95, replaced never duplicated", () => {
  app.db.query("DELETE FROM route_hour").run();
  const ledger = createHourLedger();
  expect(step(ledger, recordWith(2), now)).toBe(2);
  expect(routeHours(app.db, 1, now)).toEqual([
    { route: "/r0", hour, n: 10, p50: 50, p95: 100 },
    { route: "/r1", hour, n: 10, p50: 51, p95: 101 },
  ]);
  step(createHourLedger(), recordWith(2), now);
  expect(count()).toBe(2);
});
test("traffic at 10:50 is filed under 10, though the tick that sees it runs at 11:00", () => {
  app.db.query("DELETE FROM route_hour").run();
  const r = createPerfRecord();
  const ledger = createHourLedger();
  const at = 499 * HOUR_MS + 50 * 60_000;
  feed(r, at, 900);
  step(ledger, r, 500 * HOUR_MS); // minute 0 of the next hour
  expect(app.db.query("SELECT route, hour, n FROM route_hour").all()).toEqual([{ route: "/r0", hour: 499, n: 1 }]);
});
test("a row is the whole hour's p95, not the last 15 minutes'", () => {
  app.db.query("DELETE FROM route_hour").run();
  const r = createPerfRecord();
  const ledger = createHourLedger();
  const start = 500 * HOUR_MS;
  feed(r, start + 60_000, 5000); // slow, early
  step(ledger, r, start + 2 * 60_000);
  for (let m = 20; m <= 50; m += 5) {
    feed(r, start + m * 60_000, 10);
    step(ledger, r, start + m * 60_000);
  }
  const [row] = routeHours(app.db, 1, start + 55 * 60_000);
  expect(row!.n).toBe(8);
  expect(row!.p95).toBe(5000); // the early slow request is long out of the 15-minute window
});
test("an empty record writes nothing, and a restart never thins an hour's row", () => {
  app.db.query("DELETE FROM route_hour").run();
  expect(step(createHourLedger(), createPerfRecord(), now)).toBe(0);
  expect(count()).toBe(0);
  step(createHourLedger(), recordWith(1, 10), now);
  const r = createPerfRecord();
  feed(r, now - 1000, 1);
  step(createHourLedger(), r, now); // a restarted process saw one request
  expect(routeHours(app.db, 1, now)[0]!.n).toBe(10);
});
test("at most 200 routes are written, the busiest first", () => {
  app.db.query("DELETE FROM route_hour").run();
  const r = recordWith(MAX_ROUTES);
  feed(r, now - 500, 5, "/extra");
  expect(step(createHourLedger(), r, now)).toBe(MAX_ROUTES);
  expect(count()).toBe(MAX_ROUTES);
  expect(routeHours(app.db, 1, now).some((x) => x.route === "/extra")).toBe(false);
});
test("a row older than 168 hours is deleted in the same write", () => {
  app.db.query("DELETE FROM route_hour").run();
  const put = app.db.query("INSERT INTO route_hour (route, hour, n, p50, p95) VALUES (?1, ?2, 1, 1, 1)");
  put.run("/old", hour - 8 * 24);
  put.run("/edge", hour - MAX_HOURS);
  put.run("/kept", hour - MAX_HOURS + 1);
  step(createHourLedger(), recordWith(1), now);
  const left = app.db.query<{ route: string }, []>("SELECT route FROM route_hour ORDER BY route").all().map((x) => x.route);
  expect(left).toEqual(["/kept", "/r0"]);
});
test("hours is a whole number 1 to 168", () => {
  expect([readHours(null), readHours("1"), readHours("168"), readHours("0"), readHours("169"), readHours("x"), readHours("-1"), readHours("1.5")]).toEqual([24, 1, 168, null, null, null, null, null]);
});
test("the API answers an admin, and refuses hours=0 with 400, a non-admin with 403 and no one with 401", async () => {
  const url = `${servers.url}/api/v1/telemetry/routes`;
  const h = (t: string) => ({ headers: { authorization: `Bearer ${t}` } });
  const bad = await fetch(`${url}?hours=0`, h(adminToken));
  expect(bad.status).toBe(400);
  expect(((await bad.json()) as any).error).toBe("invalid_hours");
  expect((await fetch(`${url}?hours=169`, h(adminToken))).status).toBe(400);
  expect((await fetch(url, h(plainToken))).status).toBe(403);
  expect((await fetch(url)).status).toBe(401);
  app.db.query("DELETE FROM route_hour").run();
  app.db.query("INSERT INTO route_hour (route, hour, n, p50, p95) VALUES ('/x', ?1, 3, 1, 2)").run(Math.floor(Date.now() / HOUR_MS));
  const ok = await fetch(`${url}?hours=2`, h(adminToken));
  expect(ok.status).toBe(200);
  const body = (await ok.json()) as any;
  expect(body.hours).toBe(2);
  expect(body.rows).toEqual([{ route: "/x", hour: Math.floor(Date.now() / HOUR_MS), n: 3, p50: 1, p95: 2 }]);
});
		@@ -2,4 +2,6 @@
2	2
3	3	`src/perf/` keeps a capped in-memory record of real requests per route pattern (total, each Server-Timing phase, signed in or out; no paths, ids or queries). `budgets.ts` holds the budgets in words with the number beside them. Once a minute `duty.ts` files one issue per route and phase in the forge's repo when p95 has been over budget for 15 min with 20+ real requests; the finding names the slowest phase, its share and the cache hit rate. `git.ts` keeps the same record for every git process the forge spawns (`git/env.ts`, `git/local.ts`), keyed `git <subcommand>` from a fixed list (never an argument, path or ref; anything else is `git other`), timed from before the spawn gate so a queue counts; a subcommand whose p95 passes its budget the same way (250 ms; 10 s for the pack-moving ones: clone, fetch, push, gc, repack, pack-objects and the like) files one issue naming it, its count, p50 and p95. `loop.ts` names the routes running across an event-loop stall in the `loop` log line; nothing is kept beyond that line. `loop_worst.ts` keeps the worst event-loop lag of the last 10 s (ten one-second slots fed by the 50 ms sampler) and every response's Server-Timing names it as `lag;dur`; `/healthz` answers it as `loopLagMs` to `Accept: application/json`, so a slow time to first byte with a small `app;dur` reads as a stall outside the handler.
4	4
5		Not yet: a synthetic probe for routes with no traffic (a client-written label would let anyone hide requests; it needs an admin-only door first), live route stats in the terminal and MCP (findings reach both doors as issues), browser timings, 24 h/7 d history, the board page, release before/after.
	5	`history.ts` (#11477): every tick the duty folds the record's new samples into an in-memory ledger under the hour each sample happened in (so 10:50 traffic is never stamped 11:00) and upserts one row per route pattern (route, hour, n, p50, p95) into `route_hour`, so a row is the hour's p50 and p95, not the last 15 minutes'. At most 5,000 samples per route and hour are kept (past it the row stands on the first), at most 200 routes (the busiest) and 168 hours; older rows go in the same write. A restart starts an empty ledger: an empty record writes nothing, and a row is never replaced by one with fewer requests, so the hours before the restart keep the fuller row. Admins read them at `GET /api/v1/telemetry/routes?hours=N` (1 to 168, default 24; else 400).
	6
	7	Not yet: a synthetic probe for routes with no traffic (a client-written label would let anyone hide requests; it needs an admin-only door first), route-hour stats in the terminal and MCP (findings reach it as issues), browser timings, the board page, release before/after.
		@@ -0,0 +1,11 @@
	1	import type { Route } from "../shared.ts";
	2
	3	export const route: Route = {
	4	method: "get",
	5	path: "/api/v1/telemetry/routes",
	6	summary: "Route p50 and p95 by the hour, kept 7 days (a forge admin's, read scope): { hours, rows: [{ route, hour, n, p50, p95 }] }, hour is hours since the epoch, ms; hours 1 to 168 (default 24), a bad value is a 400",
	7	auth: true,
	8	role: "admin",
	9	query: { hours: { type: "integer", min: 1, max: 168 } },
	10	refusals: { unauthorized: "no valid credentials were sent", forbidden: "the caller is not a forge admin" },
	11	};
		@@ -190,6 +190,7 @@ export { route as getApiV1SecretsScope } from "./getApiV1SecretsScope.ts";
190	190	export { route as getApiV1TelemetryFlow } from "./getApiV1TelemetryFlow.ts";
191	191	export { route as getApiV1TelemetryHistory } from "./getApiV1TelemetryHistory.ts";
192	192	export { route as getApiV1TelemetryHome } from "./getApiV1TelemetryHome.ts";
	193	export { route as getApiV1TelemetryRoutes } from "./getApiV1TelemetryRoutes.ts";
193	194	export { route as getApiV1TelemetrySources } from "./getApiV1TelemetrySources.ts";
194	195	export { route as getApiV1TelemetrySystem } from "./getApiV1TelemetrySystem.ts";
195	196	export { route as getApiV1Tokens } from "./getApiV1Tokens.ts";
		@@ -0,0 +1,1 @@
	1	8f9e39fd2e6e41bd2b4f2524fa63c5bef9d2f223b5bcb8a7ac43297daa3a3efc
		@@ -0,0 +1,13 @@
	1	// `route_hour` (#11477): per route pattern and hour, how many requests and their p50 and p95
	2	// in ms, written once an hour by the performance watcher, kept 7 days. New table only. Additive.
	3	export default `
	4	CREATE TABLE route_hour (
	5	route TEXT NOT NULL,
	6	hour INTEGER NOT NULL,
	7	n INTEGER NOT NULL,
	8	p50 REAL NOT NULL,
	9	p95 REAL NOT NULL,
	10	PRIMARY KEY (route, hour)
	11	) WITHOUT ROWID;
	12	CREATE INDEX route_hour_hour ON route_hour (hour);
	13	`;
		@@ -63,6 +63,7 @@ import { receiveBeat, SIGNATURE_HEADER } from "../spawn/heartbeat.ts";
63	63	import { takeOrTell } from "../actions/follow.ts";
64	64	import { noteRead, telemetryReader, type Reader } from "../actions/telemetry.ts";
65	65	import { flowCopy, flowEtag, flowMaxAge } from "../system/flow_cache.ts";
	66	import { readHours, routeHours } from "../perf/history.ts";
66	67	import { countRead } from "../system/telemetry_reads.ts";
67	68	import { historyFor, sourcesOut, systemWithReaders, welcome } from "../system/telemetry.ts";
68	69	import { weekCard, WEEK_DAYS } from "../crew/week_card.ts";
		@@ -1353,6 +1354,19 @@ export function apiRoutes(router: Router<Handler>): void {
1353	1354	return timePhase(ctx.request, "render", () => json(card));
1354	1355	});
1355	1356
	1357	// Route p50/p95 by the hour, kept 7 days (`perf/history.ts`); admin.
	1358	router.add("GET", "/api/v1/telemetry/routes", (ctx) => {
	1359	notePhase(ctx.request, "session", takeSessionTime(ctx.request));
	1360	const denied = requireScope(ctx, "ro");
	1361	if (denied) return denied;
	1362	if (!ctx.auth.user) return unauthorized();
	1363	if (ctx.auth.user.isAdmin !== true) return forbidden();
	1364	const hours = readHours(ctx.url.searchParams.get("hours"));
	1365	if (hours === null) return apiError("invalid_hours", 400, "hours is a whole number from 1 to 168");
	1366	const rows = timePhase(ctx.request, "read", () => routeHours(ctx.app.db, hours));
	1367	return timePhase(ctx.request, "render", () => json({ hours, rows }));
	1368	});
	1369
1356	1370	// The week's line per crew member (`crew/week_card.ts`); as MCP `crew` with kind "week".
1357	1371	router.add("GET", "/api/v1/crew/week", (ctx) => {
1358	1372	notePhase(ctx.request, "session", takeSessionTime(ctx.request));
		@@ -4,7 +4,8 @@
4	4	* issue in the forge's own repository, opened by its owner. A title already
5	5	* open is not filed twice, and neither is a key this process has filed. A
6	6	* slow route or subcommand is a defect: filed with its kind's labels, a `bug`
7		* on its clock (#8856).
	7	* on its clock (#8856). Each tick it also folds the new samples into the hour's p50 and p95
	8	* per route in `route_hour` (`history.ts`, #11477).
8	9	*/
9	10
10	11	import type { App } from "../app.ts";
		@@ -17,6 +18,7 @@ import { createGitRecord } from "./git.ts";
17	18	import type { PerfRecord } from "./record.ts";
18	19	import { evaluate, evaluateGit, fresh } from "./watch.ts";
19	20	import { during } from "./jobs.ts";
	21	import { createHourLedger } from "./history.ts";
20	22
21	23	export const TICK_MS = 60_000;
22	24
		@@ -26,9 +28,17 @@ export function startPerfWatcher(
26	28	now: () => number = Date.now,
27	29	everyMs = TICK_MS,
28	30	gitRecord: PerfRecord = createGitRecord(),
29		): () => void {
	31	): (() => void) & { tick: () => void } {
	32	const ledger = createHourLedger();
30	33	const filed = new Set<string>();
31	34	const tick = (): void => {
	35	try {
	36	// Each tick folds the new samples into their own hour's row, off the request path (#11477).
	37	ledger.note(record, now());
		sentinelcrew 3h ago outdated Hour is taken from now, but the window summarised is the 15 minutes before now; at the first tick of an hour that traffic belongs to the previous hour. Also wrote=-1 lets a restart write an empty/near-empty hour and skip the real write.
	38	ledger.write(app.db, now());
	39	} catch (error) {
	40	app.log.warn("route history write failed", { error: String(error) });
	41	}
32	42	try {
33	43	const slug = app.config.forgeRepo;
34	44	if (slug === undefined) return;
		@@ -49,5 +59,5 @@ export function startPerfWatcher(
49	59	};
50	60	const timer = setInterval(() => during("perf-watcher", tick), everyMs);
51	61	timer.unref();
52		return () => clearInterval(timer);
	62	return Object.assign(() => clearInterval(timer), { tick });
53	63	}
		@@ -0,0 +1,106 @@
	1	/**
	2	* Route p95 by the hour, kept 7 days (#11477): every watcher tick folds the
	3	* record's new samples into the hour they happened in and upserts one row per
	4	* route pattern (n, p50, p95) for it into `route_hour`, at most `MAX_ROUTES`
	5	* routes, and deletes rows older than `MAX_HOURS` in the same write. Route patterns only, as in `record.ts`.
	6	*/
	7
	8	import type { Database } from "bun:sqlite";
	9	import { percentile, type PerfRecord } from "./record.ts";
	10
	11	export const HOUR_MS = 3_600_000;
	12	export const MAX_HOURS = 168;
	13	export const MAX_ROUTES = 200;
	14
	15	export interface RouteHour {
	16	readonly route: string;
	17	readonly hour: number;
	18	readonly n: number;
	19	readonly p50: number;
	20	readonly p95: number;
	21	}
	22
	23	/** Samples kept per route and hour; past it an hour's row stands on its first `MAX_HOUR_SAMPLES`. */
	24	export const MAX_HOUR_SAMPLES = 5_000;
	25
	26	/**
	27	* The hour's samples per route, filled from the record's window every tick, so a row is the hour's
	28	* p50 and p95 and not the last 15 minutes'. Each sample is filed under the hour of its own `at`, so
		sentinelcrew 3h ago outdated Stamping `hour` from `now` mislabels the window (since = now - WINDOW_MS). Use the hour the window ended in, and test at minute 0.
	29	* traffic at 10:50 is never stamped 11:00. In memory only; `write` keeps the rows of the hours it
	30	* touched current in `route_hour`.
	31	*/
	32	export interface HourLedger {
	33	/** Take the record's samples newer than the last call and at or before `now`. */
	34	note(record: PerfRecord, now: number): void;
	35	/** Upsert the rows of the hours that took samples since the last write; returns rows written. */
	36	write(db: Database, now: number): number;
	37	}
	38
	39	export function createHourLedger(): HourLedger {
	40	const hours = new Map<number, Map<string, number[]>>();
	41	const touched = new Set<number>();
	42	let last = 0;
	43	return {
	44	note(record, now) {
	45	for (const route of record.patterns()) {
	46	for (const s of record.traffic(route, last + 1)) {
	47	if (s.at > now) continue;
	48	const hour = Math.floor(s.at / HOUR_MS);
	49	let routes = hours.get(hour);
	50	if (!routes) hours.set(hour, (routes = new Map()));
	51	let ms = routes.get(route);
	52	if (!ms) routes.set(route, (ms = []));
	53	if (ms.length < MAX_HOUR_SAMPLES) ms.push(s.ms);
	54	touched.add(hour);
	55	}
	56	}
	57	last = Math.max(last, now);
	58	},
	59	write(db, now) {
	60	const current = Math.floor(now / HOUR_MS);
	61	let written = 0;
	62	db.transaction(() => {
	63	// A restart starts with an empty ledger: a row never shrinks to a thinner sample of its hour.
	64	const put = db.query(
	65	`INSERT INTO route_hour (route, hour, n, p50, p95) VALUES (?1, ?2, ?3, ?4, ?5)
	66	ON CONFLICT (route, hour) DO UPDATE SET n = excluded.n, p50 = excluded.p50, p95 = excluded.p95
	67	WHERE excluded.n >= route_hour.n`,
	68	);
	69	for (const hour of touched) {
	70	const rows: RouteHour[] = [];
	71	for (const [route, ms] of hours.get(hour) ?? [])
	72	rows.push({ route, hour, n: ms.length, p50: percentile(ms, 50)!, p95: percentile(ms, 95)! });
	73	// The busiest routes survive the cap.
	74	rows.sort((x, y) => y.n - x.n);
	75	for (const r of rows.slice(0, MAX_ROUTES)) {
	76	put.run(r.route, r.hour, r.n, r.p50, r.p95);
	77	written++;
	78	}
	79	}
	80	db.query("DELETE FROM route_hour WHERE hour <= ?1").run(current - MAX_HOURS);
	81	})();
	82	touched.clear();
	83	// An hour two behind can take no more samples (the window is 15 minutes).
	84	for (const hour of hours.keys()) if (hour < current - 1) hours.delete(hour);
	85	return written;
	86	},
	87	};
	88	}
	89
	90	/** The last `hours` hours (1 to 168) up to `now`, oldest first. */
	91	export function routeHours(db: Database, hours: number, now: number = Date.now()): RouteHour[] {
	92	const last = Math.floor(now / HOUR_MS);
	93	return db
	94	.query<RouteHour, [number, number]>(
	95	"SELECT route, hour, n, p50, p95 FROM route_hour WHERE hour > ?1 AND hour <= ?2 ORDER BY hour, route",
	96	)
	97	.all(last - hours, last);
	98	}
	99
	100	/** `?hours=` as a whole number 1 to 168 (default 24), or null. */
	101	export function readHours(raw: string \| null): number \| null {
	102	if (raw === null) return 24;
	103	if (!/^[0-9]{1,3}$/.test(raw)) return null;
	104	const n = Number(raw);
	105	return n >= 1 && n <= MAX_HOURS ? n : null;
	106	}
		@@ -90,3 +90,19 @@ test("a slow route is filed as a bug, so its clock runs from the filing (#8856)"
90	90	const issue = listIssues(app.db, repo.id, { state: "open" }).find((i) => i.title === "/ is over its budget: kpis")!;
91	91	expect(labelsFor(app.db, issue.id).map((l) => l.name)).toEqual(["bug"]);
92	92	});
	93
	94	test("the watcher folds each tick into its hour's row, driven without timers (#11477)", () => {
	95	app.db.query("DELETE FROM route_hour").run();
	96	let t = now;
	97	const rec = slow();
	98	const stop = startPerfWatcher(app, rec, () => t, 3_600_000);
	99	const rows = () => app.db.query<{ hour: number; n: number }, []>("SELECT hour, n FROM route_hour ORDER BY hour").all();
	100	stop.tick();
	101	expect(rows().length).toBe(1);
	102	const first = rows()[0]!;
	103	t += 60_000;
	104	rec.add("/", { at: t - 1000, ms: 9, signedIn: false, phases: [] });
	105	stop.tick();
	106	expect(rows()).toEqual([{ hour: first.hour, n: first.n + 1 }]); // same hour: the row grows
	107	stop();
	108	});
		@@ -0,0 +1,147 @@
	1	/** Route p95 by the hour (#11477): the write, the cap, the purge, and the admin read. */
	2	import { afterAll, beforeAll, expect, test } from "bun:test";
	3	import { mkdtemp, rm } from "node:fs/promises";
	4	import { tmpdir } from "node:os";
	5	import { join } from "node:path";
	6	import { createApp, type App } from "../src/app.ts";
	7	import { createToken } from "../src/core/tokens.ts";
	8	import { createUser } from "../src/core/users.ts";
	9	import { serve, type Servers } from "../src/http/server.ts";
	10	import { createHourLedger, HOUR_MS, MAX_HOURS, MAX_ROUTES, readHours, routeHours, type HourLedger } from "../src/perf/history.ts";
	11	import { createPerfRecord } from "../src/perf/record.ts";
	12	import { seedAdmin } from "./helpers/admin.ts";
	13	import { quietLogs } from "./helpers/globals.ts";
	14
	15	quietLogs();
	16
	17	let dir: string;
	18	let app: App;
	19	let servers: Servers;
	20	let adminToken: string;
	21	let plainToken: string;
	22	const now = 500 * HOUR_MS + 30 * 60_000;
	23	const hour = 500;
	24
	25	const recordWith = (routes: number, each = 10) => {
	26	const r = createPerfRecord();
	27	for (let i = 0; i < routes; i++)
	28	for (let k = 1; k <= each; k++) r.add(`/r${i}`, { at: now - k * 1000, ms: k * 10 + i, signedIn: false, phases: [] });
	29	return r;
	30	};
	31
	32	beforeAll(async () => {
	33	dir = await mkdtemp(join(tmpdir(), "forge-perf-history-"));
	34	app = createApp({ dataDir: dir, port: 0 });
	35	servers = await serve(app);
	36	const a = await seedAdmin(app, { username: "ada", email: "[email protected]" });
	37	if (!a.ok) throw new Error(a.error);
	38	adminToken = createToken(app.db, a.value.id, "t", "ro").token;
	39	const b = await createUser(app.db, { origin: "seed", trusted: true, username: "bob", email: "[email protected]", password: "a-good-passphrase" });
	40	if (!b.ok) throw new Error(String(b.error));
	41	plainToken = createToken(app.db, b.value.id, "t", "ro").token;
	42	});
	43	afterAll(async () => {
	44	await servers.stop();
	45	app.close();
	46	await rm(dir, { recursive: true, force: true });
	47	});
	48
	49	const count = () => app.db.query<{ n: number }, []>("SELECT COUNT(*) AS n FROM route_hour").get()!.n;
	50
	51	const feed = (r: ReturnType<typeof createPerfRecord>, at: number, ms: number, route = "/r0") =>
	52	r.add(route, { at, ms, signedIn: false, phases: [] });
	53	const step = (ledger: HourLedger, r: ReturnType<typeof createPerfRecord>, t: number) => {
	54	ledger.note(r, t);
	55	return ledger.write(app.db, t);
	56	};
	57
	58	test("a write keeps one row per route with n, p50 and p95, replaced never duplicated", () => {
	59	app.db.query("DELETE FROM route_hour").run();
	60	const ledger = createHourLedger();
	61	expect(step(ledger, recordWith(2), now)).toBe(2);
	62	expect(routeHours(app.db, 1, now)).toEqual([
	63	{ route: "/r0", hour, n: 10, p50: 50, p95: 100 },
	64	{ route: "/r1", hour, n: 10, p50: 51, p95: 101 },
	65	]);
	66	step(createHourLedger(), recordWith(2), now);
	67	expect(count()).toBe(2);
	68	});
	69
	70	test("traffic at 10:50 is filed under 10, though the tick that sees it runs at 11:00", () => {
	71	app.db.query("DELETE FROM route_hour").run();
	72	const r = createPerfRecord();
	73	const ledger = createHourLedger();
	74	const at = 499 * HOUR_MS + 50 * 60_000;
	75	feed(r, at, 900);
	76	step(ledger, r, 500 * HOUR_MS); // minute 0 of the next hour
	77	expect(app.db.query("SELECT route, hour, n FROM route_hour").all()).toEqual([{ route: "/r0", hour: 499, n: 1 }]);
	78	});
	79
	80	test("a row is the whole hour's p95, not the last 15 minutes'", () => {
	81	app.db.query("DELETE FROM route_hour").run();
	82	const r = createPerfRecord();
	83	const ledger = createHourLedger();
	84	const start = 500 * HOUR_MS;
	85	feed(r, start + 60_000, 5000); // slow, early
	86	step(ledger, r, start + 2 * 60_000);
	87	for (let m = 20; m <= 50; m += 5) {
	88	feed(r, start + m * 60_000, 10);
	89	step(ledger, r, start + m * 60_000);
	90	}
	91	const [row] = routeHours(app.db, 1, start + 55 * 60_000);
	92	expect(row!.n).toBe(8);
	93	expect(row!.p95).toBe(5000); // the early slow request is long out of the 15-minute window
	94	});
	95
	96	test("an empty record writes nothing, and a restart never thins an hour's row", () => {
	97	app.db.query("DELETE FROM route_hour").run();
	98	expect(step(createHourLedger(), createPerfRecord(), now)).toBe(0);
	99	expect(count()).toBe(0);
	100	step(createHourLedger(), recordWith(1, 10), now);
	101	const r = createPerfRecord();
	102	feed(r, now - 1000, 1);
	103	step(createHourLedger(), r, now); // a restarted process saw one request
	104	expect(routeHours(app.db, 1, now)[0]!.n).toBe(10);
	105	});
	106
	107	test("at most 200 routes are written, the busiest first", () => {
	108	app.db.query("DELETE FROM route_hour").run();
	109	const r = recordWith(MAX_ROUTES);
	110	feed(r, now - 500, 5, "/extra");
	111	expect(step(createHourLedger(), r, now)).toBe(MAX_ROUTES);
	112	expect(count()).toBe(MAX_ROUTES);
	113	expect(routeHours(app.db, 1, now).some((x) => x.route === "/extra")).toBe(false);
	114	});
	115
	116	test("a row older than 168 hours is deleted in the same write", () => {
	117	app.db.query("DELETE FROM route_hour").run();
	118	const put = app.db.query("INSERT INTO route_hour (route, hour, n, p50, p95) VALUES (?1, ?2, 1, 1, 1)");
	119	put.run("/old", hour - 8 * 24);
	120	put.run("/edge", hour - MAX_HOURS);
	121	put.run("/kept", hour - MAX_HOURS + 1);
	122	step(createHourLedger(), recordWith(1), now);
	123	const left = app.db.query<{ route: string }, []>("SELECT route FROM route_hour ORDER BY route").all().map((x) => x.route);
	124	expect(left).toEqual(["/kept", "/r0"]);
	125	});
	126
	127	test("hours is a whole number 1 to 168", () => {
	128	expect([readHours(null), readHours("1"), readHours("168"), readHours("0"), readHours("169"), readHours("x"), readHours("-1"), readHours("1.5")]).toEqual([24, 1, 168, null, null, null, null, null]);
	129	});
	130
	131	test("the API answers an admin, and refuses hours=0 with 400, a non-admin with 403 and no one with 401", async () => {
	132	const url = `${servers.url}/api/v1/telemetry/routes`;
	133	const h = (t: string) => ({ headers: { authorization: `Bearer ${t}` } });
	134	const bad = await fetch(`${url}?hours=0`, h(adminToken));
	135	expect(bad.status).toBe(400);
	136	expect(((await bad.json()) as any).error).toBe("invalid_hours");
	137	expect((await fetch(`${url}?hours=169`, h(adminToken))).status).toBe(400);
	138	expect((await fetch(url, h(plainToken))).status).toBe(403);
	139	expect((await fetch(url)).status).toBe(401);
	140	app.db.query("DELETE FROM route_hour").run();
	141	app.db.query("INSERT INTO route_hour (route, hour, n, p50, p95) VALUES ('/x', ?1, 3, 1, 2)").run(Math.floor(Date.now() / HOUR_MS));
	142	const ok = await fetch(`${url}?hours=2`, h(adminToken));
	143	expect(ok.status).toBe(200);
	144	const body = (await ok.json()) as any;
	145	expect(body.hours).toBe(2);
	146	expect(body.rows).toEqual([{ route: "/x", hour: Math.floor(Date.now() / HOUR_MS), n: 3, p50: 1, p95: 2 }]);
	147	});