df2048c · 1928689 · 8e7dae6
@@ -23,6 +23,10 @@
not an admin, 200 for an admin's `ro` token. It is never cached
| `forge_ask_to_live_seconds` | histogram | none (plus `le`) | Seconds from an issue opening to the first successful release of a pull that closes it. Buckets: 1 m, 5 m, 15 m, 1 h, 4 h, 12 h, 1 d, 3 d, 7 d. |
| `forge_main_red_seconds_total` | counter | `repo` | Seconds the default branch's check spent failing: from a failed check to the next green one, or to now while still red. |
| `forge_telemetry_reads_total` | counter | `route`, `reader` | Reads of `/api/v1/telemetry` routes since the process started, by route and reader; the rate is the slope. |
| `forge_loop_stall_milliseconds_total` | counter | `route` | Milliseconds the main thread stalled past 250 ms since the process started, charged in full to every route pattern running across the stall (`none` when no request was). |
| `forge_loop_stalls_total` | counter | `route` | Those stalls, counted the same way. |
| `forge_loop_stall_hour_milliseconds` | gauge | `route` | Stall milliseconds in the last hour: the top 10 routes, most first, plus `/api/v1/telemetry/flow` always (0 when it stalled nothing). |
| `forge_loop_stall_hour_count` | gauge | `route` | Stalls in the last hour, for the routes the gauge above lists. |
| `forge_app_up` | gauge | `app`, `env` | 1 when the app environment is serving, 0 when it is asleep, stopped, deploying or failed. |
| `forge_cell_cpu_seconds` (samples `forge_cell_cpu_seconds_total`) | counter | `app`, `env` | CPU seconds (user plus system) used by the processes of a running app cell. |
| `forge_cell_memory_bytes` | gauge | `app`, `env` | Resident memory of the processes of a running app cell. |
@@ -45,6 +49,15 @@
every scrape, so the scrape cost grows with those tables. The check histogram
reads only the checks finished since the last scrape, through the
`run_kind_finished` index; the queue and crew series are small grouped reads.
The stall families (#9016) are the `event loop blocked` log lines
(`src/perf/loop.ts`) as figures, so a fix's before and after reads from the
forge itself. A stall overlapping two requests counts against both, as the
log line names both, so summing over routes can exceed the wall time. To
compare the telemetry flow read with #8978 (69.6 s of stalls in 6 minutes,
about 700 s an hour at that rate), read
`forge_loop_stall_hour_milliseconds{route="/api/v1/telemetry/flow"}`; for any
window, `increase(forge_loop_stall_milliseconds_total{route="/api/v1/telemetry/flow"}[6m])`.
A public repository's `repo` label is `owner/name`; a private one appears
under its id only, never its name.
@@ -0,0 +1,32 @@
# Main-thread stalls by route (#9016)
The forge counts every wake of its event loop more than 250 ms late as a
stall, and charges it in full to each route pattern whose request ran across
it (`none` when no request did) — the same reading as the `event loop blocked`
log lines (`src/perf/loop.ts`), so a fix's before and after reads from the
forge itself, not the pod log.
Where to look (a forge admin who is a person; anyone else gets 404, or no
palette entry):
- **`/system`**, the "Main-thread stalls, last hour" card: route, stall ms and
  count for the top 10 routes, most first, plus `/api/v1/telemetry/flow`
  always (0 when it stalled nothing). As of the page's load.
- **The terminal**: `:` → "Main-thread stalls", the same rows.
- **`GET /metrics`** (an admin `ro` token): `forge_loop_stall_milliseconds_total`
  and `forge_loop_stalls_total` by `route` since the process started, and the
  last hour as `forge_loop_stall_hour_milliseconds` / `forge_loop_stall_hour_count`
  (docs/METRICS.md lists them).
## Comparing with #8978
#8978 measured `/api/v1/telemetry/flow` holding the thread 69.6 s in 6
minutes (2026-11-02, 0.7.349): about 11.6 s a minute, or roughly 700,000 ms
an hour at that rate. The `/api/v1/telemetry/flow` row on `/system` is that
figure for the last hour; for the same 6-minute window,
`increase(forge_loop_stall_milliseconds_total{route="/api/v1/telemetry/flow"}[6m])`
in Prometheus, compared with 69,600.
Caveats: a stall over two requests counts against both, so routes sum past
the wall time; a request still running when the wake comes is not yet named;
a restart starts the figures at zero.
@@ -18,6 +18,8 @@
import type { EnvState } from "../apps/runtime.ts";
import { EDGES_MS, readTotals } from "../core/route_timing.ts";
import { closesFromBody } from "../core/pulls.ts";
import { telemetryReadsFamily } from "../system/telemetry_reads.ts";
import { loopWatch } from "../perf/live.ts";
import { stallFamilies } from "./stalls.ts";
import { openMetrics, type Family, type HistogramSample, type Sample } from "./openmetrics.ts";
export const DURATION_FAMILY = "forge_http_request_duration_seconds";
@@ -345,5 +347,6 @@
export function forgeMetrics(
    askToLiveFamily(db),
    mainRedFamily(db, now),
    telemetryReadsFamily(),
    ...stallFamilies(loopWatch.tally(performance.now())),
  ]).replace(/# EOF\n$/, "");
}
@@ -0,0 +1,55 @@
/**
 * Main-thread stalls by route for `GET /metrics` (#9016), from the loop
 * watch's tally (`perf/loop.ts`): milliseconds and counts since the process
 * started as counters, and the top routes of the last hour as gauges. The
 * telemetry flow route is always in the hour, at zero when it stalled
 * nothing, so its before and after (#8978: 69.6 s in 6 minutes) reads from
 * one series. `stallHour` is the selection the families, `/system` and the
 * terminal's Stalls screen all read.
 */
import type { RouteStall, StallTally } from "../perf/loop.ts";
import type { Family } from "./openmetrics.ts";
/** Routes the hour lists, most milliseconds first; the rest are in the totals. */
export const TOP_ROUTES = 10;
/** Routes always in the hour, whatever their place. */
export const WATCHED_ROUTES: readonly string[] = ["/api/v1/telemetry/flow"];
/** The last hour's top routes, most milliseconds first, then each watched route not among them (at zero when it stalled nothing). */
      
        sentinelcrew
        11d ago
        outdated
      
      The hourly top routes exist only as OpenMetrics here. The issue wants them on the metrics page and the terminal as well, so reuse this selection (top N plus the watched route) from a web section and a tui screen. Move the selection into a plain function that returns rows, so the page, the screen and the families all read the same data.
    
export function stallHour(tally: StallTally): RouteStall[] {
  const hour = tally.hour.slice(0, TOP_ROUTES);
  for (const route of WATCHED_ROUTES)
    if (!hour.some((r) => r.route === route)) hour.push(tally.hour.find((r) => r.route === route) ?? { route, ms: 0, count: 0 });
  return hour;
}
export function stallFamilies(tally: StallTally): Family[] {
  const hour = stallHour(tally);
  return [
    {
      type: "counter",
      name: "forge_loop_stall_milliseconds_total",
      help: "Milliseconds the main thread stalled past 250 ms, by the route running across the stall (route=\"none\" when none), since the process started.",
      samples: tally.total.map((r) => ({ labels: { route: r.route }, value: Math.round(r.ms) })),
    },
    {
      type: "counter",
      name: "forge_loop_stalls_total",
      help: "Main-thread stalls past 250 ms, by the route running across the stall, since the process started.",
      samples: tally.total.map((r) => ({ labels: { route: r.route }, value: r.count })),
    },
    {
      type: "gauge",
      name: "forge_loop_stall_hour_milliseconds",
      help: `Milliseconds the main thread stalled in the last hour, the top ${TOP_ROUTES} routes plus ${WATCHED_ROUTES.join(", ")}.`,
      samples: hour.map((r) => ({ labels: { route: r.route }, value: Math.round(r.ms) })),
    },
    {
      type: "gauge",
      name: "forge_loop_stall_hour_count",
      help: "Main-thread stalls in the last hour, for the routes forge_loop_stall_hour_milliseconds lists.",
      samples: hour.map((r) => ({ labels: { route: r.route }, value: r.count })),
    },
  ];
}
@@ -2,12 +2,37 @@
 * Event-loop block attribution (#7559): which route was running when the loop
 * stalled. Each finished request is noted with its start and end; a stall of
 * `lateMs` ending at `at` blocked `[at - lateMs, at]`, and the requests whose
 * run overlaps that window are named, longest first. Patterns only; the stall
 * is logged, not kept.
 * run overlaps that window are named, longest first. Patterns only.
 *
 * Each stall is also tallied by route (#9016): milliseconds and counts since
 * the process started, and the stalls of the last hour, so `GET /metrics`
 * shows a fix's before and after without the pod log. A stall is counted in
 * full against every route that ran across it — the same reading as the log
 * lines, so the sum over routes can exceed the wall time — and against
 * `NO_REQUEST` when none did.
 */
export const LIMIT_MS = 250;
const RECENT = 256;
/** The window `StallTally.hour` covers, in ms. */
export const HOUR_MS = 3_600_000;
/** Stalls kept for the hour: a stall is over 250 ms, so 14,400 fill an hour solid. */
const HOUR_KEPT = 14_400;
/** The route a stall is counted against when no request ran across it. */
export const NO_REQUEST = "none";
export interface RouteStall {
  readonly route: string;
  readonly ms: number;
  readonly count: number;
}
export interface StallTally {
  /** Since the process started, by route; only ever grows. */
  readonly total: readonly RouteStall[];
  /** The last hour before `now`, by route, most milliseconds first. */
  readonly hour: readonly RouteStall[];
}
export interface Stall {
  readonly at: number;
@@ -20,10 +45,26 @@
export interface LoopWatch {
  finished(pattern: string, start: number, end: number): void;
  /** A wake `lateMs` late at `at`; over the limit it is named. */
  stalled(lateMs: number, at: number): Stall | null;
  /** The stalls so far by route, the hour ending at `now` (same clock as `at`). */
  tally(now: number): StallTally;
}
function byRoute(stalls: Iterable<Stall>): RouteStall[] {
  const sums = new Map<string, { ms: number; count: number }>();
  for (const s of stalls)
    for (const route of s.routes.length === 0 ? [NO_REQUEST] : s.routes) {
      const t = sums.get(route) ?? { ms: 0, count: 0 };
      t.ms += s.lateMs;
      t.count += 1;
      sums.set(route, t);
    }
  return [...sums].map(([route, t]) => ({ route, ms: t.ms, count: t.count }));
}
export function createLoopWatch(limitMs = LIMIT_MS): LoopWatch {
  const recent: { pattern: string; start: number; end: number }[] = [];
  const totals = new Map<string, { ms: number; count: number }>();
  const hour: Stall[] = [];
  return {
    finished(pattern, start, end) {
      recent.push({ pattern, start, end });
@@ -40,7 +81,23 @@
export function createLoopWatch(limitMs = LIMIT_MS): LoopWatch {
            .map((r) => r.pattern),
        ),
      ];
      return { at, lateMs, routes };
      const stall = { at, lateMs, routes };
      for (const r of byRoute([stall])) {
        const t = totals.get(r.route) ?? { ms: 0, count: 0 };
        t.ms += r.ms;
        t.count += r.count;
        totals.set(r.route, t);
      }
      hour.push(stall);
      if (hour.length > HOUR_KEPT) hour.shift();
      return stall;
    },
    tally(now) {
      while (hour.length > 0 && hour[0]!.at <= now - HOUR_MS) hour.shift();
      return {
        total: [...totals].map(([route, t]) => ({ route, ms: t.ms, count: t.count })).sort((a, b) => (a.route < b.route ? -1 : 1)),
        hour: byRoute(hour.filter((s) => s.at <= now)).sort((a, b) => b.ms - a.ms || (a.route < b.route ? -1 : 1)),
      };
    },
  };
}
@@ -28,6 +28,7 @@
import { entry as forges } from "./forges.ts";
import { entry as homePins } from "./home_pins.ts";
import { entry as invites } from "./invites.ts";
import { entry as limits } from "./limits.ts";
import { entry as loopStalls } from "./loopstalls.ts";
import { modelCeilingEntry, modelGrantEntry } from "./model.ts";
import { entry as orgGrants } from "./orggrants.ts";
import { entry as orgTeams } from "./orgteams.ts";
@@ -72,6 +73,7 @@
export const ENTRIES: readonly PaletteEntry[] = [
  bugs,
  homePins,
  system,
  loopStalls,
  telemetry,
  resilience,
  valves,
@@ -0,0 +1,62 @@
/**
 * Main-thread stalls in the terminal, the owner's (#9016): the last hour's
 * top routes by milliseconds the loop was held past 250 ms, with
 * /api/v1/telemetry/flow always listed — the rows `/system` and `/metrics`
 * read (`stallHour`). The gate is `/system`'s: a forge admin who is a person.
 * Read-only.
 */
import { stallHour } from "../../metrics/stalls.ts";
import type { RouteStall } from "../../perf/loop.ts";
import { loopWatch } from "../../perf/live.ts";
import type { Ctx, Screen } from "../app/app.ts";
import { binding } from "../app/keys.ts";
import type { Session } from "../session.ts";
import { style } from "../term/style.ts";
import { pad } from "../term/width.ts";
import { Scroll, drawLines, hitScroll } from "./common.ts";
import type { PaletteEntry } from "./entries.ts";
const mayRead = (session: Session): boolean => session.user?.isAdmin === true && session.user.kind !== "agent";
/** The header, then a route a row; empty for anyone the gate refuses. */
export function stallLines(session: Session, rows: readonly RouteStall[] = stallHour(loopWatch.tally(performance.now()))): string[] {
  if (!mayRead(session)) return [];
  const col = (s: string) => pad(s, 10, "right");
  return [
    `${pad("Route (last hour)", 40)}${col("Stall ms")}${col("Stalls")}`,
    ...rows.map((r) => `${pad(r.route, 40)}${col(String(Math.round(r.ms)))}${col(String(r.count))}`),
  ];
}
export function stallsScreen(session: Session, ctx: Ctx): Screen {
  const scroll = new Scroll();
  return {
    title: "Main-thread stalls",
    keys: [binding(["j", "k"], "scroll"), binding(["esc", "q"], "back")],
    render(area, s) {
      const c = ctx.theme.c;
      const lines = stallLines(session);
      const spans = lines.map((text, i) => [{ text, style: style(i === 0 ? c.fg : c.mutedFg, c.bg) }]);
      drawLines(s, area, c, scroll, spans);
      hitScroll(ctx, area, scroll, lines.length);
    },
    key(e) {
      if (scroll.key(e, stallLines(session).length)) return true;
      if (e.key === "esc" || e.key === "q") {
        ctx.pop();
        return true;
      }
      return false;
    },
  };
}
export const entry: PaletteEntry = {
  id: "stalls",
  title: "Main-thread stalls",
  hint: "the last hour's stall ms by route",
  after: ["system"],
  offered: mayRead,
  run: (session, ctx) => ctx.push(stallsScreen(session, ctx)),
};
@@ -9,6 +9,9 @@
 * Below it, for a forge admin who is a person, the forge's resident memory
 * (RSS) beside its JS heap, hourly for 24 h (#2151): RSS climbing while the
 * heap stays flat is native memory growth. Drawn on the server as SVG.
 * Between them, the main-thread stalls of the last hour by route (#9016),
 * read once at first paint from the loop watch: the top routes plus
 * /api/v1/telemetry/flow always, as /metrics exports them.
 */
import { canSeeMemory, memoryHours } from "../../boards/memory.ts";
import { telemetryReader } from "../../actions/telemetry.ts";
@@ -18,6 +21,9 @@
import { bytes, spark, span } from "../../system/format.ts";
import { eventStream } from "../../http/sse.ts";
import type { SystemView } from "../../system/view.ts";
import { live } from "../../system/live.ts";
import { stallHour } from "../../metrics/stalls.ts";
import type { RouteStall } from "../../perf/loop.ts";
import { loopWatch } from "../../perf/live.ts";
import { notePhase, takeSessionTime, timePhase } from "../../core/route_timing.ts";
import { notFoundPage, signInFirst } from "../chrome.ts";
import { html, raw, type Html } from "../html.ts";
@@ -91,6 +97,18 @@
function memorySection(ctx: Ctx): Html {
        </table></div>`;
}
/** The last hour's stalls by route, most milliseconds first; the rows are `stallHour`'s. */
export function stallSection(rows: readonly RouteStall[]): Html {
  return card(
    html`<p class="small muted">Milliseconds the main thread was held past 250 ms in the last hour, charged in full to every route running across the stall (<code>none</code>: no request was). As of this page's load; <code>/metrics</code> has the series.</p>
      <div class="table-scroll"><table class="table" aria-label="Main-thread stalls by route, last hour">
        <thead><tr><th scope="col">Route</th><th scope="col" class="num">Stall ms</th><th scope="col" class="num">Stalls</th></tr></thead>
        <tbody>${rows.map((r) => html`<tr data-route="${r.route}"><td class="mono">${r.route}</td><td class="num mono">${String(Math.round(r.ms))}</td><td class="num mono">${String(r.count)}</td></tr>`)}</tbody>
      </table></div>`,
    { head: html`<h2>Main-thread stalls, last hour</h2>` },
  );
}
/**
 * The parts of the page a sample moves, each the inner markup of the element
 * of that id. The first paint and every pushed sample are drawn by this one
@@ -164,6 +182,7 @@
export function systemPage(ctx: Ctx): Response {
      ? html`<p class="small" id="cell-caps" data-by="kernel">Each cell's memory is capped by the kernel (its own cgroup's <code>memory.max</code>): a cell over it is killed alone.</p>`
      : html`<p class="small" id="cell-caps" data-by="watch">Each cell's memory is watched once a second and the cell stopped over its cap; the kernel does not cap it (${holder.reason}).</p>`;
  const memory = memorySection(ctx);
  const stalls = timePhase(ctx.request, "stalls", () => stallHour(loopWatch.tally(performance.now())));
  const rendering = performance.now();
  const r = regions(v);
  const at = (id: string): Html => raw(r[id]!);
@@ -190,6 +209,7 @@
export function systemPage(ctx: Ctx): Response {
      <p class="small muted"><span class="js-only">Sort by <button class="btn" data-size="sm" type="button" data-sort="cpu" aria-pressed="true"><kbd>c</kbd> CPU</button>
        <button class="btn" data-size="sm" type="button" data-sort="mem" aria-pressed="false"><kbd>m</kbd> memory</button></span></p></div>
    <div id="sys-procs">${at("sys-procs")}</div>
    <div id="sys-stalls">${stallSection(stalls)}</div>
    ${memory}`;
  const response = page({ ctx, title: "System", body, wide: true, scriptJs: systemLiveJs });
  notePhase(ctx.request, "render", performance.now() - rendering);
@@ -0,0 +1,197 @@
/** Main-thread stalls are counted against the route running across them and read from `GET /metrics` (#9016). */
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 { watchStalls } from "../src/kernel/loop_lag.ts";
import { openMetrics } from "../src/metrics/openmetrics.ts";
import { stallFamilies, TOP_ROUTES } from "../src/metrics/stalls.ts";
import { loopWatch } from "../src/perf/live.ts";
import { createLoopWatch, HOUR_MS, NO_REQUEST } from "../src/perf/loop.ts";
import { createAgent } from "../src/actions/crew.ts";
import type { User } from "../src/core/users.ts";
import { stallSection } from "../src/web/pages/system.ts";
import { createForgeApp, forgeCommands, Session } from "../src/tui/forge.ts";
import { stallLines } from "../src/tui/screens/loopstalls.ts";
import { headlessTerminal } from "../src/tui/term/terminal.ts";
import { quietLogs } from "./helpers/globals.ts";
quietLogs();
test("a deliberate stall during a route is counted against it", async () => {
  // The loop watcher on a clock the test moves: the route holds the thread
  // 400 ms of that clock, and the wake after it is late by that much.
  let t = 0;
  const w = createLoopWatch(250);
  const heard = new Promise<void>((resolve) => {
    const stop = watchStalls({ warn() {} }, 1_000, 5, () => t, (late, at) => {
      if (w.stalled(late, at) !== null) {
        stop();
        resolve();
      }
    });
  });
  const start = t;
  t += 400;
  w.finished("/slow/:id", start, t);
  await heard;
  // Armed at 0 to wake at 5; woke at 400: 395 ms late.
  const tally = w.tally(t);
  expect(tally.total).toEqual([{ route: "/slow/:id", ms: 395, count: 1 }]);
  expect(tally.hour).toEqual([{ route: "/slow/:id", ms: 395, count: 1 }]);
  const text = openMetrics(stallFamilies(tally));
  expect(text).toContain('forge_loop_stall_milliseconds_total{route="/slow/:id"} 395');
  expect(text).toContain('forge_loop_stalls_total{route="/slow/:id"} 1');
  expect(text).toContain('forge_loop_stall_hour_milliseconds{route="/slow/:id"} 395');
});
test("each route across a stall is charged the whole stall; none is charged to `none`", () => {
  const w = createLoopWatch(250);
  w.finished("/a", 0, 1000);
  w.finished("/b", 500, 900);
  w.stalled(600, 1000);
  w.stalled(300, 5000);
  const { total } = w.tally(5000);
  expect(total).toEqual([
    { route: "/a", ms: 600, count: 1 },
    { route: "/b", ms: 600, count: 1 },
    { route: NO_REQUEST, ms: 300, count: 1 },
  ]);
});
test("the hour forgets a stall an hour old; the totals keep it", () => {
  const w = createLoopWatch(250);
  w.finished("/old", 0, 1000);
  w.stalled(500, 1000);
  w.finished("/new", HOUR_MS, HOUR_MS + 1000);
  w.stalled(700, HOUR_MS + 1000);
  w.stalled(400, HOUR_MS + 1000);
  const tally = w.tally(HOUR_MS + 1000);
  expect(tally.hour).toEqual([{ route: "/new", ms: 1100, count: 2 }]);
  expect(tally.total.map((r) => r.route)).toEqual(["/new", "/old"]);
});
test("the hour lists the top routes, most milliseconds first, and always the flow route", () => {
  const w = createLoopWatch(250);
  for (let i = 0; i < TOP_ROUTES + 3; i++) {
    const at = 10_000 * (i + 1);
    w.finished(`/r${i}`, at - 1000, at);
    w.stalled(300 + i, at);
  }
  const text = openMetrics(stallFamilies(w.tally(10_000 * (TOP_ROUTES + 4))));
  const hourly = [...text.matchAll(/^forge_loop_stall_hour_milliseconds\{route="([^"]+)"\} (\d+)$/gm)].map((m) => [m[1], Number(m[2])]);
  expect(hourly.length).toBe(TOP_ROUTES + 1);
  expect(hourly[0]).toEqual([`/r${TOP_ROUTES + 2}`, 300 + TOP_ROUTES + 2]);
  expect(hourly.some(([r]) => r === "/r0")).toBe(false);
  expect(hourly.at(-1)).toEqual(["/api/v1/telemetry/flow", 0]);
});
let dir: string;
let app: App;
let servers: Servers;
let ro: string;
let alice: User;
let bob: User;
let bot: User;
beforeAll(async () => {
  dir = await mkdtemp(join(tmpdir(), "loop-stall-route-"));
  app = createApp({ dataDir: dir, port: 0 });
  servers = await serve(app);
  const made = await createUser(app.db, {
    origin: "seed",
    trusted: true,
    username: "alice",
    email: "[email protected]",
    password: "a-good-passphrase",
    adminIfFirst: true,
  });
      
        sentinelcrew
        11d ago
        outdated
      
      loopWatch.stalled(400, ...) feeds the shared process singleton, so a later test in this process sees the stall. Keep assertions scoped to this route, or inject the watch.
    
  if (!made.ok) throw new Error(made.error);
  alice = made.value;
  ro = createToken(app.db, made.value.id, "t", "ro").token;
  const member = await createUser(app.db, { origin: "seed", trusted: true, username: "bob", email: "[email protected]", password: "a-good-passphrase" });
  if (!member.ok) throw new Error(member.error);
  bob = member.value;
  const agent = await createAgent(app, alice, { username: "stallbot", brief: "x" });
  if (!agent.ok) throw new Error(String(agent.error));
  // An admin agent: still not offered the screen, which is a person's.
  app.db.query("UPDATE user SET is_admin = 1 WHERE id = ?1").run(agent.value.user.id);
  bot = { ...agent.value.user, isAdmin: true };
}, 60_000);
afterAll(async () => {
  servers.stop();
  app.close();
  await rm(dir, { recursive: true, force: true });
});
test("GET /metrics names the route a stall ran across", async () => {
  // This feeds the process's own watch, which every test file in this
  // process shares: the stall stays in its totals, so every assertion here
  // and elsewhere reads route-specific lines, never a sum or a row count.
  const health = await fetch(`${servers.url}/api/v1/health`);
  expect(health.status).toBe(200);
  // The server noted the request on the process's watch; a wake 400 ms late
  // now covers it, as main.ts's watcher would report it.
  expect(loopWatch.stalled(400, performance.now())).not.toBeNull();
  const text = await (await fetch(`${servers.url}/metrics`, { headers: { authorization: `Bearer ${ro}` } })).text();
  expect(text).toMatch(/^forge_loop_stalls_total\{route="\/api\/v1\/health"\} [1-9]/m);
  expect(text).toMatch(/^forge_loop_stall_hour_milliseconds\{route="\/api\/v1\/health"\} [1-9]/m);
  expect(text).toMatch(/^forge_loop_stall_hour_milliseconds\{route="\/api\/v1\/telemetry\/flow"\} \d+$/m);
});
const login = async (username: string): Promise<string> => {
  const res = await fetch(`${servers.url}/signin`, {
    method: "POST",
    redirect: "manual",
    headers: { "content-type": "application/x-www-form-urlencoded", origin: servers.url },
    body: new URLSearchParams({ username, password: "a-good-passphrase" }),
  });
  return (res.headers.get("set-cookie") ?? "").split(";")[0] ?? "";
};
test("the stall section lists route, ms and count, the route escaped", () => {
  const text = stallSection([
    { route: "/a/<script>", ms: 1234.4, count: 3 },
    { route: "/api/v1/telemetry/flow", ms: 0, count: 0 },
  ]).text;
  expect(text).toContain("Main-thread stalls, last hour");
  expect(text).toContain('<td class="mono">/a/&lt;script&gt;</td><td class="num mono">1234</td><td class="num mono">3</td>');
  expect(text).not.toContain("<script>");
  expect(text).toContain('<td class="mono">/api/v1/telemetry/flow</td><td class="num mono">0</td><td class="num mono">0</td>');
});
test("/system shows the owner the stall section with the flow route; a member gets 404", async () => {
  const page = await fetch(`${servers.url}/system`, { headers: { cookie: await login("alice") } });
  expect(page.status).toBe(200);
  const html = await page.text();
  expect(html).toContain('id="sys-stalls"');
  expect(html).toContain('<tr data-route="/api/v1/telemetry/flow">');
  expect((await fetch(`${servers.url}/system`, { headers: { cookie: await login("bob") } })).status).toBe(404);
});
const identity = (user?: User) => ({ sshUsername: user?.username ?? "git", remoteAddress: "127.0.0.1", fingerprint: "SHA256:test", user });
const doors = (user?: User): string[] => {
  const { app: tui, session } = createForgeApp(app, identity(user), { terminal: headlessTerminal(80, 24), exitHooks: false });
  const ids = forgeCommands(session)(tui.ctx).map((c) => c.id);
  tui.stop?.();
  return ids;
};
test("the Stalls screen gives an admin person the rows and the door; nobody else either", () => {
  const rows = [{ route: "/slow/:id", ms: 812.6, count: 2 }, { route: "/api/v1/telemetry/flow", ms: 0, count: 0 }];
  const lines = stallLines(new Session(app, identity(alice)), rows);
  expect(lines[0]).toContain("Stall ms");
  expect(lines[1]).toMatch(/^\/slow\/:id\s+813\s+2$/);
  expect(lines[2]).toMatch(/^\/api\/v1\/telemetry\/flow\s+0\s+0$/);
  expect(doors(alice)).toContain("stalls");
  for (const who of [bob, bot, undefined]) {
    expect(stallLines(new Session(app, identity(who)), rows)).toEqual([]);
    expect(doors(who)).not.toContain("stalls");
  }
});
@@ -88,6 +88,7 @@
test("a site-admin person is offered the whole roster", () => {
    ["flow", "Flow", "the pipeline's bottleneck and throughput"],
    ["system", "System", "the machine now: CPU, memory, disks, processes"],
    ["valves", "Valves", "the week's budget as a valve per repository; turn one and the crew obeys"],
    ["stalls", "Main-thread stalls", "the last hour's stall ms by route"],
    ["telemetry", "Telemetry", "which agents may read flow and system; enter flips the grant"],
    ["capacity", "Capacity", "concurrency and guards, live; e changes a settable one"],
    ["resilience", "Resilience", "where snapshots go and the mirror; each protection green, red or untested"],
		@@ -23,6 +23,10 @@ not an admin, 200 for an admin's `ro` token. It is never cached
23	23	\| `forge_ask_to_live_seconds` \| histogram \| none (plus `le`) \| Seconds from an issue opening to the first successful release of a pull that closes it. Buckets: 1 m, 5 m, 15 m, 1 h, 4 h, 12 h, 1 d, 3 d, 7 d. \|
24	24	\| `forge_main_red_seconds_total` \| counter \| `repo` \| Seconds the default branch's check spent failing: from a failed check to the next green one, or to now while still red. \|
25	25	\| `forge_telemetry_reads_total` \| counter \| `route`, `reader` \| Reads of `/api/v1/telemetry` routes since the process started, by route and reader; the rate is the slope. \|
	26	\| `forge_loop_stall_milliseconds_total` \| counter \| `route` \| Milliseconds the main thread stalled past 250 ms since the process started, charged in full to every route pattern running across the stall (`none` when no request was). \|
	27	\| `forge_loop_stalls_total` \| counter \| `route` \| Those stalls, counted the same way. \|
	28	\| `forge_loop_stall_hour_milliseconds` \| gauge \| `route` \| Stall milliseconds in the last hour: the top 10 routes, most first, plus `/api/v1/telemetry/flow` always (0 when it stalled nothing). \|
	29	\| `forge_loop_stall_hour_count` \| gauge \| `route` \| Stalls in the last hour, for the routes the gauge above lists. \|
26	30	\| `forge_app_up` \| gauge \| `app`, `env` \| 1 when the app environment is serving, 0 when it is asleep, stopped, deploying or failed. \|
27	31	\| `forge_cell_cpu_seconds` (samples `forge_cell_cpu_seconds_total`) \| counter \| `app`, `env` \| CPU seconds (user plus system) used by the processes of a running app cell. \|
28	32	\| `forge_cell_memory_bytes` \| gauge \| `app`, `env` \| Resident memory of the processes of a running app cell. \|
		@@ -45,6 +49,15 @@ every scrape, so the scrape cost grows with those tables. The check histogram
45	49	reads only the checks finished since the last scrape, through the
46	50	`run_kind_finished` index; the queue and crew series are small grouped reads.
47	51
	52	The stall families (#9016) are the `event loop blocked` log lines
	53	(`src/perf/loop.ts`) as figures, so a fix's before and after reads from the
	54	forge itself. A stall overlapping two requests counts against both, as the
	55	log line names both, so summing over routes can exceed the wall time. To
	56	compare the telemetry flow read with #8978 (69.6 s of stalls in 6 minutes,
	57	about 700 s an hour at that rate), read
	58	`forge_loop_stall_hour_milliseconds{route="/api/v1/telemetry/flow"}`; for any
	59	window, `increase(forge_loop_stall_milliseconds_total{route="/api/v1/telemetry/flow"}[6m])`.
	60
48	61	A public repository's `repo` label is `owner/name`; a private one appears
49	62	under its id only, never its name.
50	63
		@@ -0,0 +1,32 @@
	1	# Main-thread stalls by route (#9016)
	2
	3	The forge counts every wake of its event loop more than 250 ms late as a
	4	stall, and charges it in full to each route pattern whose request ran across
	5	it (`none` when no request did) — the same reading as the `event loop blocked`
	6	log lines (`src/perf/loop.ts`), so a fix's before and after reads from the
	7	forge itself, not the pod log.
	8
	9	Where to look (a forge admin who is a person; anyone else gets 404, or no
	10	palette entry):
	11
	12	- `/system`, the "Main-thread stalls, last hour" card: route, stall ms and
	13	count for the top 10 routes, most first, plus `/api/v1/telemetry/flow`
	14	always (0 when it stalled nothing). As of the page's load.
	15	- The terminal: `:` → "Main-thread stalls", the same rows.
	16	- `GET /metrics` (an admin `ro` token): `forge_loop_stall_milliseconds_total`
	17	and `forge_loop_stalls_total` by `route` since the process started, and the
	18	last hour as `forge_loop_stall_hour_milliseconds` / `forge_loop_stall_hour_count`
	19	(docs/METRICS.md lists them).
	20
	21	## Comparing with #8978
	22
	23	#8978 measured `/api/v1/telemetry/flow` holding the thread 69.6 s in 6
	24	minutes (2026-11-02, 0.7.349): about 11.6 s a minute, or roughly 700,000 ms
	25	an hour at that rate. The `/api/v1/telemetry/flow` row on `/system` is that
	26	figure for the last hour; for the same 6-minute window,
	27	`increase(forge_loop_stall_milliseconds_total{route="/api/v1/telemetry/flow"}[6m])`
	28	in Prometheus, compared with 69,600.
	29
	30	Caveats: a stall over two requests counts against both, so routes sum past
	31	the wall time; a request still running when the wake comes is not yet named;
	32	a restart starts the figures at zero.
		@@ -18,6 +18,8 @@ import type { EnvState } from "../apps/runtime.ts";
18	18	import { EDGES_MS, readTotals } from "../core/route_timing.ts";
19	19	import { closesFromBody } from "../core/pulls.ts";
20	20	import { telemetryReadsFamily } from "../system/telemetry_reads.ts";
	21	import { loopWatch } from "../perf/live.ts";
	22	import { stallFamilies } from "./stalls.ts";
21	23	import { openMetrics, type Family, type HistogramSample, type Sample } from "./openmetrics.ts";
22	24
23	25	export const DURATION_FAMILY = "forge_http_request_duration_seconds";
		@@ -345,5 +347,6 @@ export function forgeMetrics(
345	347	askToLiveFamily(db),
346	348	mainRedFamily(db, now),
347	349	telemetryReadsFamily(),
	350	...stallFamilies(loopWatch.tally(performance.now())),
348	351	]).replace(/# EOF\n$/, "");
349	352	}
		@@ -0,0 +1,55 @@
	1	/**
	2	* Main-thread stalls by route for `GET /metrics` (#9016), from the loop
	3	* watch's tally (`perf/loop.ts`): milliseconds and counts since the process
	4	* started as counters, and the top routes of the last hour as gauges. The
	5	* telemetry flow route is always in the hour, at zero when it stalled
	6	* nothing, so its before and after (#8978: 69.6 s in 6 minutes) reads from
	7	* one series. `stallHour` is the selection the families, `/system` and the
	8	* terminal's Stalls screen all read.
	9	*/
	10
	11	import type { RouteStall, StallTally } from "../perf/loop.ts";
	12	import type { Family } from "./openmetrics.ts";
	13
	14	/** Routes the hour lists, most milliseconds first; the rest are in the totals. */
	15	export const TOP_ROUTES = 10;
	16	/** Routes always in the hour, whatever their place. */
	17	export const WATCHED_ROUTES: readonly string[] = ["/api/v1/telemetry/flow"];
	18
	19	/** The last hour's top routes, most milliseconds first, then each watched route not among them (at zero when it stalled nothing). */
		sentinelcrew 11d ago outdated The hourly top routes exist only as OpenMetrics here. The issue wants them on the metrics page and the terminal as well, so reuse this selection (top N plus the watched route) from a web section and a tui screen. Move the selection into a plain function that returns rows, so the page, the screen and the families all read the same data.
	20	export function stallHour(tally: StallTally): RouteStall[] {
	21	const hour = tally.hour.slice(0, TOP_ROUTES);
	22	for (const route of WATCHED_ROUTES)
	23	if (!hour.some((r) => r.route === route)) hour.push(tally.hour.find((r) => r.route === route) ?? { route, ms: 0, count: 0 });
	24	return hour;
	25	}
	26
	27	export function stallFamilies(tally: StallTally): Family[] {
	28	const hour = stallHour(tally);
	29	return [
	30	{
	31	type: "counter",
	32	name: "forge_loop_stall_milliseconds_total",
	33	help: "Milliseconds the main thread stalled past 250 ms, by the route running across the stall (route=\"none\" when none), since the process started.",
	34	samples: tally.total.map((r) => ({ labels: { route: r.route }, value: Math.round(r.ms) })),
	35	},
	36	{
	37	type: "counter",
	38	name: "forge_loop_stalls_total",
	39	help: "Main-thread stalls past 250 ms, by the route running across the stall, since the process started.",
	40	samples: tally.total.map((r) => ({ labels: { route: r.route }, value: r.count })),
	41	},
	42	{
	43	type: "gauge",
	44	name: "forge_loop_stall_hour_milliseconds",
	45	help: `Milliseconds the main thread stalled in the last hour, the top ${TOP_ROUTES} routes plus ${WATCHED_ROUTES.join(", ")}.`,
	46	samples: hour.map((r) => ({ labels: { route: r.route }, value: Math.round(r.ms) })),
	47	},
	48	{
	49	type: "gauge",
	50	name: "forge_loop_stall_hour_count",
	51	help: "Main-thread stalls in the last hour, for the routes forge_loop_stall_hour_milliseconds lists.",
	52	samples: hour.map((r) => ({ labels: { route: r.route }, value: r.count })),
	53	},
	54	];
	55	}
		@@ -2,12 +2,37 @@
2	2	* Event-loop block attribution (#7559): which route was running when the loop
3	3	* stalled. Each finished request is noted with its start and end; a stall of
4	4	* `lateMs` ending at `at` blocked `[at - lateMs, at]`, and the requests whose
5		* run overlaps that window are named, longest first. Patterns only; the stall
6		* is logged, not kept.
	5	* run overlaps that window are named, longest first. Patterns only.
	6	*
	7	* Each stall is also tallied by route (#9016): milliseconds and counts since
	8	* the process started, and the stalls of the last hour, so `GET /metrics`
	9	* shows a fix's before and after without the pod log. A stall is counted in
	10	* full against every route that ran across it — the same reading as the log
	11	* lines, so the sum over routes can exceed the wall time — and against
	12	* `NO_REQUEST` when none did.
7	13	*/
8	14
9	15	export const LIMIT_MS = 250;
10	16	const RECENT = 256;
	17	/** The window `StallTally.hour` covers, in ms. */
	18	export const HOUR_MS = 3_600_000;
	19	/** Stalls kept for the hour: a stall is over 250 ms, so 14,400 fill an hour solid. */
	20	const HOUR_KEPT = 14_400;
	21	/** The route a stall is counted against when no request ran across it. */
	22	export const NO_REQUEST = "none";
	23
	24	export interface RouteStall {
	25	readonly route: string;
	26	readonly ms: number;
	27	readonly count: number;
	28	}
	29
	30	export interface StallTally {
	31	/** Since the process started, by route; only ever grows. */
	32	readonly total: readonly RouteStall[];
	33	/** The last hour before `now`, by route, most milliseconds first. */
	34	readonly hour: readonly RouteStall[];
	35	}
11	36
12	37	export interface Stall {
13	38	readonly at: number;
		@@ -20,10 +45,26 @@ export interface LoopWatch {
20	45	finished(pattern: string, start: number, end: number): void;
21	46	/** A wake `lateMs` late at `at`; over the limit it is named. */
22	47	stalled(lateMs: number, at: number): Stall \| null;
	48	/** The stalls so far by route, the hour ending at `now` (same clock as `at`). */
	49	tally(now: number): StallTally;
	50	}
	51
	52	function byRoute(stalls: Iterable<Stall>): RouteStall[] {
	53	const sums = new Map<string, { ms: number; count: number }>();
	54	for (const s of stalls)
	55	for (const route of s.routes.length === 0 ? [NO_REQUEST] : s.routes) {
	56	const t = sums.get(route) ?? { ms: 0, count: 0 };
	57	t.ms += s.lateMs;
	58	t.count += 1;
	59	sums.set(route, t);
	60	}
	61	return [...sums].map(([route, t]) => ({ route, ms: t.ms, count: t.count }));
23	62	}
24	63
25	64	export function createLoopWatch(limitMs = LIMIT_MS): LoopWatch {
26	65	const recent: { pattern: string; start: number; end: number }[] = [];
	66	const totals = new Map<string, { ms: number; count: number }>();
	67	const hour: Stall[] = [];
27	68	return {
28	69	finished(pattern, start, end) {
29	70	recent.push({ pattern, start, end });
		@@ -40,7 +81,23 @@ export function createLoopWatch(limitMs = LIMIT_MS): LoopWatch {
40	81	.map((r) => r.pattern),
41	82	),
42	83	];
43		return { at, lateMs, routes };
	84	const stall = { at, lateMs, routes };
	85	for (const r of byRoute([stall])) {
	86	const t = totals.get(r.route) ?? { ms: 0, count: 0 };
	87	t.ms += r.ms;
	88	t.count += r.count;
	89	totals.set(r.route, t);
	90	}
	91	hour.push(stall);
	92	if (hour.length > HOUR_KEPT) hour.shift();
	93	return stall;
	94	},
	95	tally(now) {
	96	while (hour.length > 0 && hour[0]!.at <= now - HOUR_MS) hour.shift();
	97	return {
	98	total: [...totals].map(([route, t]) => ({ route, ms: t.ms, count: t.count })).sort((a, b) => (a.route < b.route ? -1 : 1)),
	99	hour: byRoute(hour.filter((s) => s.at <= now)).sort((a, b) => b.ms - a.ms \|\| (a.route < b.route ? -1 : 1)),
	100	};
44	101	},
45	102	};
46	103	}
		@@ -28,6 +28,7 @@ import { entry as forges } from "./forges.ts";
28	28	import { entry as homePins } from "./home_pins.ts";
29	29	import { entry as invites } from "./invites.ts";
30	30	import { entry as limits } from "./limits.ts";
	31	import { entry as loopStalls } from "./loopstalls.ts";
31	32	import { modelCeilingEntry, modelGrantEntry } from "./model.ts";
32	33	import { entry as orgGrants } from "./orggrants.ts";
33	34	import { entry as orgTeams } from "./orgteams.ts";
		@@ -72,6 +73,7 @@ export const ENTRIES: readonly PaletteEntry[] = [
72	73	bugs,
73	74	homePins,
74	75	system,
	76	loopStalls,
75	77	telemetry,
76	78	resilience,
77	79	valves,
		@@ -0,0 +1,62 @@
	1	/**
	2	* Main-thread stalls in the terminal, the owner's (#9016): the last hour's
	3	* top routes by milliseconds the loop was held past 250 ms, with
	4	* /api/v1/telemetry/flow always listed — the rows `/system` and `/metrics`
	5	* read (`stallHour`). The gate is `/system`'s: a forge admin who is a person.
	6	* Read-only.
	7	*/
	8
	9	import { stallHour } from "../../metrics/stalls.ts";
	10	import type { RouteStall } from "../../perf/loop.ts";
	11	import { loopWatch } from "../../perf/live.ts";
	12	import type { Ctx, Screen } from "../app/app.ts";
	13	import { binding } from "../app/keys.ts";
	14	import type { Session } from "../session.ts";
	15	import { style } from "../term/style.ts";
	16	import { pad } from "../term/width.ts";
	17	import { Scroll, drawLines, hitScroll } from "./common.ts";
	18	import type { PaletteEntry } from "./entries.ts";
	19
	20	const mayRead = (session: Session): boolean => session.user?.isAdmin === true && session.user.kind !== "agent";
	21
	22	/** The header, then a route a row; empty for anyone the gate refuses. */
	23	export function stallLines(session: Session, rows: readonly RouteStall[] = stallHour(loopWatch.tally(performance.now()))): string[] {
	24	if (!mayRead(session)) return [];
	25	const col = (s: string) => pad(s, 10, "right");
	26	return [
	27	`${pad("Route (last hour)", 40)}${col("Stall ms")}${col("Stalls")}`,
	28	...rows.map((r) => `${pad(r.route, 40)}${col(String(Math.round(r.ms)))}${col(String(r.count))}`),
	29	];
	30	}
	31
	32	export function stallsScreen(session: Session, ctx: Ctx): Screen {
	33	const scroll = new Scroll();
	34	return {
	35	title: "Main-thread stalls",
	36	keys: [binding(["j", "k"], "scroll"), binding(["esc", "q"], "back")],
	37	render(area, s) {
	38	const c = ctx.theme.c;
	39	const lines = stallLines(session);
	40	const spans = lines.map((text, i) => [{ text, style: style(i === 0 ? c.fg : c.mutedFg, c.bg) }]);
	41	drawLines(s, area, c, scroll, spans);
	42	hitScroll(ctx, area, scroll, lines.length);
	43	},
	44	key(e) {
	45	if (scroll.key(e, stallLines(session).length)) return true;
	46	if (e.key === "esc" \|\| e.key === "q") {
	47	ctx.pop();
	48	return true;
	49	}
	50	return false;
	51	},
	52	};
	53	}
	54
	55	export const entry: PaletteEntry = {
	56	id: "stalls",
	57	title: "Main-thread stalls",
	58	hint: "the last hour's stall ms by route",
	59	after: ["system"],
	60	offered: mayRead,
	61	run: (session, ctx) => ctx.push(stallsScreen(session, ctx)),
	62	};
		@@ -9,6 +9,9 @@
9	9	* Below it, for a forge admin who is a person, the forge's resident memory
10	10	* (RSS) beside its JS heap, hourly for 24 h (#2151): RSS climbing while the
11	11	* heap stays flat is native memory growth. Drawn on the server as SVG.
	12	* Between them, the main-thread stalls of the last hour by route (#9016),
	13	* read once at first paint from the loop watch: the top routes plus
	14	* /api/v1/telemetry/flow always, as /metrics exports them.
12	15	*/
13	16	import { canSeeMemory, memoryHours } from "../../boards/memory.ts";
14	17	import { telemetryReader } from "../../actions/telemetry.ts";
		@@ -18,6 +21,9 @@ import { bytes, spark, span } from "../../system/format.ts";
18	21	import { eventStream } from "../../http/sse.ts";
19	22	import type { SystemView } from "../../system/view.ts";
20	23	import { live } from "../../system/live.ts";
	24	import { stallHour } from "../../metrics/stalls.ts";
	25	import type { RouteStall } from "../../perf/loop.ts";
	26	import { loopWatch } from "../../perf/live.ts";
21	27	import { notePhase, takeSessionTime, timePhase } from "../../core/route_timing.ts";
22	28	import { notFoundPage, signInFirst } from "../chrome.ts";
23	29	import { html, raw, type Html } from "../html.ts";
		@@ -91,6 +97,18 @@ function memorySection(ctx: Ctx): Html {
91	97	</table></div>`;
92	98	}
93	99
	100	/** The last hour's stalls by route, most milliseconds first; the rows are `stallHour`'s. */
	101	export function stallSection(rows: readonly RouteStall[]): Html {
	102	return card(
	103	html`<p class="small muted">Milliseconds the main thread was held past 250 ms in the last hour, charged in full to every route running across the stall (<code>none</code>: no request was). As of this page's load; <code>/metrics</code> has the series.</p>
	104	<div class="table-scroll"><table class="table" aria-label="Main-thread stalls by route, last hour">
	105	<thead><tr><th scope="col">Route</th><th scope="col" class="num">Stall ms</th><th scope="col" class="num">Stalls</th></tr></thead>
	106	<tbody>${rows.map((r) => html`<tr data-route="${r.route}"><td class="mono">${r.route}</td><td class="num mono">${String(Math.round(r.ms))}</td><td class="num mono">${String(r.count)}</td></tr>`)}</tbody>
	107	</table></div>`,
	108	{ head: html`<h2>Main-thread stalls, last hour</h2>` },
	109	);
	110	}
	111
94	112	/**
95	113	* The parts of the page a sample moves, each the inner markup of the element
96	114	* of that id. The first paint and every pushed sample are drawn by this one
		@@ -164,6 +182,7 @@ export function systemPage(ctx: Ctx): Response {
164	182	? html`<p class="small" id="cell-caps" data-by="kernel">Each cell's memory is capped by the kernel (its own cgroup's <code>memory.max</code>): a cell over it is killed alone.</p>`
165	183	: html`<p class="small" id="cell-caps" data-by="watch">Each cell's memory is watched once a second and the cell stopped over its cap; the kernel does not cap it (${holder.reason}).</p>`;
166	184	const memory = memorySection(ctx);
	185	const stalls = timePhase(ctx.request, "stalls", () => stallHour(loopWatch.tally(performance.now())));
167	186	const rendering = performance.now();
168	187	const r = regions(v);
169	188	const at = (id: string): Html => raw(r[id]!);
		@@ -190,6 +209,7 @@ export function systemPage(ctx: Ctx): Response {
190	209	<p class="small muted"><span class="js-only">Sort by <button class="btn" data-size="sm" type="button" data-sort="cpu" aria-pressed="true"><kbd>c</kbd> CPU</button>
191	210	<button class="btn" data-size="sm" type="button" data-sort="mem" aria-pressed="false"><kbd>m</kbd> memory</button></span></p></div>
192	211	<div id="sys-procs">${at("sys-procs")}</div>
	212	<div id="sys-stalls">${stallSection(stalls)}</div>
193	213	${memory}`;
194	214	const response = page({ ctx, title: "System", body, wide: true, scriptJs: systemLiveJs });
195	215	notePhase(ctx.request, "render", performance.now() - rendering);
		@@ -0,0 +1,197 @@
	1	/** Main-thread stalls are counted against the route running across them and read from `GET /metrics` (#9016). */
	2
	3	import { afterAll, beforeAll, expect, test } from "bun:test";
	4	import { mkdtemp, rm } from "node:fs/promises";
	5	import { tmpdir } from "node:os";
	6	import { join } from "node:path";
	7	import { createApp, type App } from "../src/app.ts";
	8	import { createToken } from "../src/core/tokens.ts";
	9	import { createUser } from "../src/core/users.ts";
	10	import { serve, type Servers } from "../src/http/server.ts";
	11	import { watchStalls } from "../src/kernel/loop_lag.ts";
	12	import { openMetrics } from "../src/metrics/openmetrics.ts";
	13	import { stallFamilies, TOP_ROUTES } from "../src/metrics/stalls.ts";
	14	import { loopWatch } from "../src/perf/live.ts";
	15	import { createLoopWatch, HOUR_MS, NO_REQUEST } from "../src/perf/loop.ts";
	16	import { createAgent } from "../src/actions/crew.ts";
	17	import type { User } from "../src/core/users.ts";
	18	import { stallSection } from "../src/web/pages/system.ts";
	19	import { createForgeApp, forgeCommands, Session } from "../src/tui/forge.ts";
	20	import { stallLines } from "../src/tui/screens/loopstalls.ts";
	21	import { headlessTerminal } from "../src/tui/term/terminal.ts";
	22	import { quietLogs } from "./helpers/globals.ts";
	23
	24	quietLogs();
	25
	26	test("a deliberate stall during a route is counted against it", async () => {
	27	// The loop watcher on a clock the test moves: the route holds the thread
	28	// 400 ms of that clock, and the wake after it is late by that much.
	29	let t = 0;
	30	const w = createLoopWatch(250);
	31	const heard = new Promise<void>((resolve) => {
	32	const stop = watchStalls({ warn() {} }, 1_000, 5, () => t, (late, at) => {
	33	if (w.stalled(late, at) !== null) {
	34	stop();
	35	resolve();
	36	}
	37	});
	38	});
	39	const start = t;
	40	t += 400;
	41	w.finished("/slow/:id", start, t);
	42	await heard;
	43	// Armed at 0 to wake at 5; woke at 400: 395 ms late.
	44	const tally = w.tally(t);
	45	expect(tally.total).toEqual([{ route: "/slow/:id", ms: 395, count: 1 }]);
	46	expect(tally.hour).toEqual([{ route: "/slow/:id", ms: 395, count: 1 }]);
	47	const text = openMetrics(stallFamilies(tally));
	48	expect(text).toContain('forge_loop_stall_milliseconds_total{route="/slow/:id"} 395');
	49	expect(text).toContain('forge_loop_stalls_total{route="/slow/:id"} 1');
	50	expect(text).toContain('forge_loop_stall_hour_milliseconds{route="/slow/:id"} 395');
	51	});
	52
	53	test("each route across a stall is charged the whole stall; none is charged to `none`", () => {
	54	const w = createLoopWatch(250);
	55	w.finished("/a", 0, 1000);
	56	w.finished("/b", 500, 900);
	57	w.stalled(600, 1000);
	58	w.stalled(300, 5000);
	59	const { total } = w.tally(5000);
	60	expect(total).toEqual([
	61	{ route: "/a", ms: 600, count: 1 },
	62	{ route: "/b", ms: 600, count: 1 },
	63	{ route: NO_REQUEST, ms: 300, count: 1 },
	64	]);
	65	});
	66
	67	test("the hour forgets a stall an hour old; the totals keep it", () => {
	68	const w = createLoopWatch(250);
	69	w.finished("/old", 0, 1000);
	70	w.stalled(500, 1000);
	71	w.finished("/new", HOUR_MS, HOUR_MS + 1000);
	72	w.stalled(700, HOUR_MS + 1000);
	73	w.stalled(400, HOUR_MS + 1000);
	74	const tally = w.tally(HOUR_MS + 1000);
	75	expect(tally.hour).toEqual([{ route: "/new", ms: 1100, count: 2 }]);
	76	expect(tally.total.map((r) => r.route)).toEqual(["/new", "/old"]);
	77	});
	78
	79	test("the hour lists the top routes, most milliseconds first, and always the flow route", () => {
	80	const w = createLoopWatch(250);
	81	for (let i = 0; i < TOP_ROUTES + 3; i++) {
	82	const at = 10_000 * (i + 1);
	83	w.finished(`/r${i}`, at - 1000, at);
	84	w.stalled(300 + i, at);
	85	}
	86	const text = openMetrics(stallFamilies(w.tally(10_000 * (TOP_ROUTES + 4))));
	87	const hourly = [...text.matchAll(/^forge_loop_stall_hour_milliseconds\{route="([^"]+)"\} (\d+)$/gm)].map((m) => [m[1], Number(m[2])]);
	88	expect(hourly.length).toBe(TOP_ROUTES + 1);
	89	expect(hourly[0]).toEqual([`/r${TOP_ROUTES + 2}`, 300 + TOP_ROUTES + 2]);
	90	expect(hourly.some(([r]) => r === "/r0")).toBe(false);
	91	expect(hourly.at(-1)).toEqual(["/api/v1/telemetry/flow", 0]);
	92	});
	93
	94	let dir: string;
	95	let app: App;
	96	let servers: Servers;
	97	let ro: string;
	98	let alice: User;
	99	let bob: User;
	100	let bot: User;
	101
	102	beforeAll(async () => {
	103	dir = await mkdtemp(join(tmpdir(), "loop-stall-route-"));
	104	app = createApp({ dataDir: dir, port: 0 });
	105	servers = await serve(app);
	106	const made = await createUser(app.db, {
	107	origin: "seed",
	108	trusted: true,
	109	username: "alice",
	110	email: "[email protected]",
	111	password: "a-good-passphrase",
	112	adminIfFirst: true,
	113	});
		sentinelcrew 11d ago outdated loopWatch.stalled(400, ...) feeds the shared process singleton, so a later test in this process sees the stall. Keep assertions scoped to this route, or inject the watch.
	114	if (!made.ok) throw new Error(made.error);
	115	alice = made.value;
	116	ro = createToken(app.db, made.value.id, "t", "ro").token;
	117	const member = await createUser(app.db, { origin: "seed", trusted: true, username: "bob", email: "[email protected]", password: "a-good-passphrase" });
	118	if (!member.ok) throw new Error(member.error);
	119	bob = member.value;
	120	const agent = await createAgent(app, alice, { username: "stallbot", brief: "x" });
	121	if (!agent.ok) throw new Error(String(agent.error));
	122	// An admin agent: still not offered the screen, which is a person's.
	123	app.db.query("UPDATE user SET is_admin = 1 WHERE id = ?1").run(agent.value.user.id);
	124	bot = { ...agent.value.user, isAdmin: true };
	125	}, 60_000);
	126
	127	afterAll(async () => {
	128	servers.stop();
	129	app.close();
	130	await rm(dir, { recursive: true, force: true });
	131	});
	132
	133	test("GET /metrics names the route a stall ran across", async () => {
	134	// This feeds the process's own watch, which every test file in this
	135	// process shares: the stall stays in its totals, so every assertion here
	136	// and elsewhere reads route-specific lines, never a sum or a row count.
	137	const health = await fetch(`${servers.url}/api/v1/health`);
	138	expect(health.status).toBe(200);
	139	// The server noted the request on the process's watch; a wake 400 ms late
	140	// now covers it, as main.ts's watcher would report it.
	141	expect(loopWatch.stalled(400, performance.now())).not.toBeNull();
	142	const text = await (await fetch(`${servers.url}/metrics`, { headers: { authorization: `Bearer ${ro}` } })).text();
	143	expect(text).toMatch(/^forge_loop_stalls_total\{route="\/api\/v1\/health"\} [1-9]/m);
	144	expect(text).toMatch(/^forge_loop_stall_hour_milliseconds\{route="\/api\/v1\/health"\} [1-9]/m);
	145	expect(text).toMatch(/^forge_loop_stall_hour_milliseconds\{route="\/api\/v1\/telemetry\/flow"\} \d+$/m);
	146	});
	147
	148	const login = async (username: string): Promise<string> => {
	149	const res = await fetch(`${servers.url}/signin`, {
	150	method: "POST",
	151	redirect: "manual",
	152	headers: { "content-type": "application/x-www-form-urlencoded", origin: servers.url },
	153	body: new URLSearchParams({ username, password: "a-good-passphrase" }),
	154	});
	155	return (res.headers.get("set-cookie") ?? "").split(";")[0] ?? "";
	156	};
	157
	158	test("the stall section lists route, ms and count, the route escaped", () => {
	159	const text = stallSection([
	160	{ route: "/a/<script>", ms: 1234.4, count: 3 },
	161	{ route: "/api/v1/telemetry/flow", ms: 0, count: 0 },
	162	]).text;
	163	expect(text).toContain("Main-thread stalls, last hour");
	164	expect(text).toContain('<td class="mono">/a/<script></td><td class="num mono">1234</td><td class="num mono">3</td>');
	165	expect(text).not.toContain("<script>");
	166	expect(text).toContain('<td class="mono">/api/v1/telemetry/flow</td><td class="num mono">0</td><td class="num mono">0</td>');
	167	});
	168
	169	test("/system shows the owner the stall section with the flow route; a member gets 404", async () => {
	170	const page = await fetch(`${servers.url}/system`, { headers: { cookie: await login("alice") } });
	171	expect(page.status).toBe(200);
	172	const html = await page.text();
	173	expect(html).toContain('id="sys-stalls"');
	174	expect(html).toContain('<tr data-route="/api/v1/telemetry/flow">');
	175	expect((await fetch(`${servers.url}/system`, { headers: { cookie: await login("bob") } })).status).toBe(404);
	176	});
	177
	178	const identity = (user?: User) => ({ sshUsername: user?.username ?? "git", remoteAddress: "127.0.0.1", fingerprint: "SHA256:test", user });
	179	const doors = (user?: User): string[] => {
	180	const { app: tui, session } = createForgeApp(app, identity(user), { terminal: headlessTerminal(80, 24), exitHooks: false });
	181	const ids = forgeCommands(session)(tui.ctx).map((c) => c.id);
	182	tui.stop?.();
	183	return ids;
	184	};
	185
	186	test("the Stalls screen gives an admin person the rows and the door; nobody else either", () => {
	187	const rows = [{ route: "/slow/:id", ms: 812.6, count: 2 }, { route: "/api/v1/telemetry/flow", ms: 0, count: 0 }];
	188	const lines = stallLines(new Session(app, identity(alice)), rows);
	189	expect(lines[0]).toContain("Stall ms");
	190	expect(lines[1]).toMatch(/^\/slow\/:id\s+813\s+2$/);
	191	expect(lines[2]).toMatch(/^\/api\/v1\/telemetry\/flow\s+0\s+0$/);
	192	expect(doors(alice)).toContain("stalls");
	193	for (const who of [bob, bot, undefined]) {
	194	expect(stallLines(new Session(app, identity(who)), rows)).toEqual([]);
	195	expect(doors(who)).not.toContain("stalls");
	196	}
	197	});
		@@ -88,6 +88,7 @@ test("a site-admin person is offered the whole roster", () => {
88	88	["flow", "Flow", "the pipeline's bottleneck and throughput"],
89	89	["system", "System", "the machine now: CPU, memory, disks, processes"],
90	90	["valves", "Valves", "the week's budget as a valve per repository; turn one and the crew obeys"],
	91	["stalls", "Main-thread stalls", "the last hour's stall ms by route"],
91	92	["telemetry", "Telemetry", "which agents may read flow and system; enter flips the grant"],
92	93	["capacity", "Capacity", "concurrency and guards, live; e changes a settable one"],
93	94	["resilience", "Resilience", "where snapshots go and the mirror; each protection green, red or untested"],