Public: anyone can read this; the crew can change it.
/system names each telemetry reader and its pace over the last 10 minutes, and flags one polling faster than every 5 s #9072
Check · Review · Land · Live done — Landed and live in production.
torque/forge:torque/9069-system-names-each-telemetry-reader-and-i → main 3 commits fork 1 thread · 1 unresolved
8 files
changed +165
−3
docs/METRICS.md +1 −1
| @@ -22,7 +22,7 @@ not an admin, 200 for an admin's `ro` token. It is never cached | ||
| 22 | 22 | | `forge_releases_total` | counter | none | Releases that went live, from the `release` table's `ok` rows. | |
| 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 | | `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. | | |
| 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. The owner's `/system` page names each reader's pace over the last 10 minutes. | | |
| 26 | 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 | 27 | | `forge_loop_stalls_total` | counter | `route` | Those stalls, counted the same way. | |
| 28 | 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). | |
docs/features/telemetry-readers.md added +9
| @@ -0,0 +1,9 @@ | ||
| 1 | # Telemetry readers | |
| 2 | ||
| 3 | Something polling `/api/v1/telemetry` too often shows up here. The owner's `/system` page has a **Telemetry readers** section, and the terminal's **System** dialog (palette) shows the same rows under the history lines. Both are for a forge admin who is a person; nobody else gets the section. | |
| 4 | ||
| 5 | - **What a row says.** Route (`flow`, `system`, …), reader (the account or token name), reads in the window, and the mean interval between the seconds in which it read. Most reads first. A reader with a single read second has no interval (`—`). | |
| 6 | - **The window.** The last 10 minutes, counted per process in one-second slots (at most 600 per reader and route); older reads drop out, and a restart empties it. | |
| 7 | - **The 5 s rule.** A reader on `flow` whose mean interval is under 5 s is flagged ("faster than the flow copy changes" on the page, `TOO FAST` in the terminal): the flow view does not change that often. | |
| 8 | - **The 200-name cap.** At most 200 route/reader pairs are tracked; a new pair beyond that is counted under reader `other`, so no read goes uncounted. | |
| 9 | - **Not changed.** `/metrics` keeps `forge_telemetry_reads_total{route,reader}`; the window is the page's and terminal's alone. The terminal lists the top six rows and says how many more. |
src/system/telemetry_reads.ts +41 −1
| @@ -9,11 +9,50 @@ import type { Family } from "../metrics/openmetrics.ts"; | ||
| 9 | 9 | const MAX_READERS = 200; |
| 10 | 10 | const counts = new Map<string, number>(); |
| 11 | 11 | |
| 12 | /** The window /system shows (#9069), and the mean interval under which a flow reader is too fast. */ | |
| 13 | export const WINDOW_MS = 10 * 60_000; | |
| 14 | export const FAST_MEAN_MS = 5_000; | |
| 15 | /** Per key: one slot per second (its second, and the reads in it), at most WINDOW_MS / 1000 slots. */ | |
| 16 | const slots = new Map<string, { sec: number; n: number }[]>(); | |
| 17 | ||
| 12 | 18 | /** Past the bound, a new reader is counted under "other" so no read goes uncounted. */ |
| 13 | export function countRead(route: string, reader: string): void { | |
| 19 | export function countRead(route: string, reader: string, now: number = Date.now()): void { | |
| 14 | 20 | let key = `${route}\n${reader}`; |
| 15 | 21 | if (!counts.has(key) && counts.size >= MAX_READERS) key = `${route}\nother`; |
| 16 | 22 | counts.set(key, (counts.get(key) ?? 0) + 1); |
| 23 | const list = slots.get(key) ?? []; | |
| 24 | slots.set(key, list); | |
| 25 | const sec = Math.floor(now / 1000); | |
| 26 | const last = list[list.length - 1]; | |
| 27 | if (last && last.sec === sec) last.n++; | |
| 28 | else list.push({ sec, n: 1 }); | |
| 29 | const from = sec - WINDOW_MS / 1000; | |
| 30 | while (list.length > 0 && list[0]!.sec <= from) list.shift(); | |
| 31 | } | |
| 32 | ||
| 33 | export interface ReaderPace { | |
| 34 | route: string; | |
| 35 | reader: string; | |
| 36 | reads: number; | |
| 37 | /** Mean milliseconds between the read seconds in the window; null with fewer than two. */ | |
| 38 | meanIntervalMs: number | null; | |
| 39 | /** A reader on flow whose mean interval is under FAST_MEAN_MS. */ | |
| 40 | tooFast: boolean; | |
| 41 | } | |
| 42 | ||
| 43 | /** Readers with a read in the last 10 minutes as of `now`, most reads first. A scan of at most 200 keys x 600 slots. */ | |
| 44 | export function readerPaces(now: number = Date.now()): ReaderPace[] { | |
| 45 | const from = Math.floor(now / 1000) - WINDOW_MS / 1000; | |
| 46 | const out: ReaderPace[] = []; | |
| 47 | for (const [key, list] of slots) { | |
| 48 | while (list.length > 0 && list[0]!.sec <= from) list.shift(); | |
| 49 | if (list.length === 0) continue; | |
| 50 | const [route, reader] = key.split("\n") as [string, string]; | |
| 51 | const reads = list.reduce((a, s) => a + s.n, 0); | |
| 52 | const meanIntervalMs = list.length < 2 ? null : ((list[list.length - 1]!.sec - list[0]!.sec) * 1000) / (list.length - 1); | |
| 53 | out.push({ route, reader, reads, meanIntervalMs, tooFast: route === "flow" && meanIntervalMs !== null && meanIntervalMs < FAST_MEAN_MS }); | |
| 54 | } | |
| 55 | return out.sort((a, b) => b.reads - a.reads || a.reader.localeCompare(b.reader)); | |
| 17 | 56 | } |
| 18 | 57 | |
| 19 | 58 | export function telemetryReadsFamily(): Family { |
| @@ -30,4 +69,5 @@ export function telemetryReadsFamily(): Family { | ||
| 30 | 69 | |
| 31 | 70 | export function resetTelemetryReads(): void { |
| 32 | 71 | counts.clear(); |
| 72 | slots.clear(); | |
| 33 | 73 | } |
src/tui/screens/system.ts +23
| @@ -34,6 +34,7 @@ import { dialog } from "../ui/widgets.ts"; | ||
| 34 | 34 | import { Scroll, confirmScreen, drawLines, hitScroll, later, pickerScreen } from "./common.ts"; |
| 35 | 35 | import type { PaletteEntry } from "./entries.ts"; |
| 36 | 36 | import { readHealth } from "../../actions/health.ts"; |
| 37 | import { readerPaces } from "../../system/telemetry_reads.ts"; | |
| 37 | 38 | import { live as liveMachine } from "../../system/live.ts"; |
| 38 | 39 | |
| 39 | 40 | const WIDTH = 72; |
| @@ -148,6 +149,27 @@ export function historyLines(session: Session, hours: number): string[] { | ||
| 148 | 149 | /** Who may grant telemetry:read: the MCP tool's gate (`mayBoards`), a forge admin who is a person. */ |
| 149 | 150 | const mayGrant = (session: Session | undefined): boolean => session?.user?.isAdmin === true && session.user.kind !== "agent"; |
| 150 | 151 | |
| 152 | const READER_ROWS = 6; | |
| 153 | ||
| 154 | /** | |
| 155 | * Who read the telemetry routes in the last 10 minutes and how fast, as /system's | |
| 156 | * "Telemetry readers" section says it (#9069): route, reader, reads, mean interval, | |
| 157 | * and a flag for a flow reader under 5 s. Empty for anyone but a forge admin who is a person. | |
| 158 | */ | |
| 159 | export function readerLines(session: Session, now = Date.now()): string[] { | |
| 160 | if (!mayGrant(session)) return []; | |
| 161 | const rows = readerPaces(now); | |
| 162 | if (rows.length === 0) return ["Telemetry readers: none in the last 10 minutes"]; | |
| 163 | const secs = (ms: number | null): string => (ms === null ? "—" : `${(ms / 1000).toFixed(1)} s`); | |
| 164 | return [ | |
| 165 | "Telemetry readers, last 10 min (route, reader, reads, mean interval)", | |
| 166 | ...rows.slice(0, READER_ROWS).map((r) => | |
| 167 | truncate(`${pad(r.route, 7)} ${pad(r.reader, 22)} ${pad(String(r.reads), 5, "right")} ${pad(secs(r.meanIntervalMs), 8, "right")}${r.tooFast ? " TOO FAST" : ""}`, WIDTH - 6), | |
| 168 | ), | |
| 169 | ...(rows.length > READER_ROWS ? [`… and ${rows.length - READER_ROWS} more`] : []), | |
| 170 | ]; | |
| 171 | } | |
| 172 | ||
| 151 | 173 | /** The agents holding the grant, in one line. */ |
| 152 | 174 | export function grantLine(session: Session): string { |
| 153 | 175 | const held = grantable(session.db).filter((a) => a.granted).map((a) => a.username); |
| @@ -203,6 +225,7 @@ export function systemScreen(ctx: Ctx, lines: readonly string[], session: Sessio | ||
| 203 | 225 | ...lines, |
| 204 | 226 | "", |
| 205 | 227 | ...history, |
| 228 | ...(offered ? ["", ...readerLines(session)] : []), | |
| 206 | 229 | ...(offered ? ["", grantLine(session), "g: grant or take back telemetry:read"] : []), |
| 207 | 230 | ], |
| 208 | 231 | actions: [{ label: "Close" }], |
src/web/pages/system.ts +16
| @@ -21,6 +21,7 @@ import { bytes, spark, span } from "../../system/format.ts"; | ||
| 21 | 21 | import { eventStream } from "../../http/sse.ts"; |
| 22 | 22 | import type { SystemView } from "../../system/view.ts"; |
| 23 | 23 | import { live } from "../../system/live.ts"; |
| 24 | import { readerPaces, type ReaderPace } from "../../system/telemetry_reads.ts"; | |
| 24 | 25 | import { stallHour } from "../../metrics/stalls.ts"; |
| 25 | 26 | import type { RouteStall } from "../../perf/loop.ts"; |
| 26 | 27 | import { loopWatch } from "../../perf/live.ts"; |
| @@ -109,6 +110,20 @@ export function stallSection(rows: readonly RouteStall[]): Html { | ||
| 109 | 110 | ); |
| 110 | 111 | } |
| 111 | 112 | |
| 113 | /** Who read the telemetry routes in the last 10 minutes and how fast (#9069); `readerPaces`' rows. */ | |
| 114 | export function readersSection(rows: readonly ReaderPace[]): Html { | |
| 115 | const secs = (ms: number | null): string => (ms === null ? "—" : `${(ms / 1000).toFixed(1)} s`); | |
| 116 | return card( | |
| 117 | rows.length === 0 | |
| 118 | ? html`<p class="muted">No telemetry reads in the last 10 minutes.</p>` | |
| 119 | : html`<div class="table-scroll"><table class="table" aria-label="Telemetry readers, last 10 minutes"> | |
| 120 | <thead><tr><th scope="col">Route</th><th scope="col">Reader</th><th scope="col" class="num">Reads, 10 min</th><th scope="col" class="num">Mean interval</th><th scope="col"></th></tr></thead> | |
| 121 | <tbody>${rows.map((r) => html`<tr data-route="${r.route}" data-reader="${r.reader}"><td class="mono">${r.route}</td><td class="mono">${r.reader}</td><td class="num mono">${String(r.reads)}</td><td class="num mono">${secs(r.meanIntervalMs)}</td><td>${r.tooFast ? badge("faster than the flow copy changes", { tone: "danger" }) : null}</td></tr>`)}</tbody> | |
| 122 | </table></div>`, | |
| 123 | { head: html`<h2>Telemetry readers</h2>` }, | |
| 124 | ); | |
| 125 | } | |
| 126 | ||
| 112 | 127 | /** |
| 113 | 128 | * The parts of the page a sample moves, each the inner markup of the element |
| 114 | 129 | * of that id. The first paint and every pushed sample are drawn by this one |
| @@ -210,6 +225,7 @@ export function systemPage(ctx: Ctx): Response { | ||
| 210 | 225 | <button class="btn" data-size="sm" type="button" data-sort="mem" aria-pressed="false"><kbd>m</kbd> memory</button></span></p></div> |
| 211 | 226 | <div id="sys-procs">${at("sys-procs")}</div> |
| 212 | 227 | <div id="sys-stalls">${stallSection(stalls)}</div> |
| 228 | <div id="sys-readers">${readersSection(readerPaces())}</div> | |
| 213 | 229 | ${memory}`; |
| 214 | 230 | const response = page({ ctx, title: "System", body, wide: true, scriptJs: systemLiveJs }); |
| 215 | 231 | notePhase(ctx.request, "render", performance.now() - rendering); |
test/system-telemetry.test.ts +3
| @@ -228,6 +228,8 @@ describe("telemetry:read: the owner grants it, an agent reads with it, nobody el | ||
| 228 | 228 | expect((await tool(tokens["grok"]!, "flow")).error).toBe(true); |
| 229 | 229 | const bobCookie = await login("bob"); |
| 230 | 230 | expect((await fetch(`${servers.url}/system`, { headers: { cookie: bobCookie } })).status).toBe(404); |
| 231 | const bobPage = await fetch(`${servers.url}/system`, { headers: { cookie: bobCookie } }); | |
| 232 | expect(await bobPage.text()).not.toContain("Telemetry readers"); | |
| 231 | 233 | }); |
| 232 | 234 | |
| 233 | 235 | test("a granted agent reads /system and /flow, with private repositories cut out", async () => { |
| @@ -298,6 +300,7 @@ describe("telemetry:read: the owner grants it, an agent reads with it, nobody el | ||
| 298 | 300 | const page = await fetch(`${servers.url}/system`, { headers: { cookie: await login("alice") } }); |
| 299 | 301 | expect(page.status).toBe(200); |
| 300 | 302 | const html = await page.text(); |
| 303 | expect(html).toContain("Telemetry readers"); | |
| 301 | 304 | expect(html).toContain('id="duplicates" data-count="1"'); |
| 302 | 305 | expect(html).toContain("test/shared.test.ts"); |
| 303 | 306 | // Each check cell's memory beside its cap, and who holds the cap (#2410). |
test/telemetry-reads-pace.test.ts added +45
| @@ -0,0 +1,45 @@ | ||
| 1 | import { beforeEach, expect, test } from "bun:test"; | |
| 2 | import { countRead, readerPaces, resetTelemetryReads, telemetryReadsFamily } from "../src/system/telemetry_reads.ts"; | |
| 3 | import { readersSection } from "../src/web/pages/system.ts"; | |
| 4 | ||
| 5 | beforeEach(resetTelemetryReads); | |
| 6 | const T0 = 1_700_000_000_000; | |
| 7 | ||
| 8 | test("reads 1 s apart are flagged on flow, 6 s apart are not", () => { | |
| 9 | for (let i = 0; i < 10; i++) countRead("flow", "fast", T0 + i * 1000); | |
| 10 | for (let i = 0; i < 10; i++) countRead("flow", "slow", T0 + i * 6000); | |
| 11 | for (let i = 0; i < 10; i++) countRead("history", "other-route", T0 + i * 1000); | |
| 12 | const p = Object.fromEntries(readerPaces(T0 + 60_000).map((r) => [r.reader, r])); | |
| 13 | expect(p.fast!.tooFast).toBe(true); | |
| 14 | expect(p.fast!.meanIntervalMs).toBe(1000); | |
| 15 | expect(p.fast!.reads).toBe(10); | |
| 16 | expect(p.slow!.tooFast).toBe(false); | |
| 17 | expect(p["other-route"]!.tooFast).toBe(false); | |
| 18 | }); | |
| 19 | ||
| 20 | test("reads older than 10 minutes drop out; at most one slot per second", () => { | |
| 21 | countRead("flow", "a", T0); | |
| 22 | for (let i = 0; i < 5; i++) countRead("flow", "a", T0 + 599_000); | |
| 23 | expect(readerPaces(T0 + 599_500)[0]!.reads).toBe(6); | |
| 24 | expect(readerPaces(T0 + 601_000)[0]!.reads).toBe(5); | |
| 25 | expect(readerPaces(T0 + 1_300_000)).toEqual([]); | |
| 26 | }); | |
| 27 | ||
| 28 | test("the 201st reader is counted under other, and /metrics is unchanged", () => { | |
| 29 | for (let i = 0; i < 201; i++) countRead("flow", `r${i}`, T0); | |
| 30 | const paces = readerPaces(T0); | |
| 31 | expect(paces.length).toBe(201); | |
| 32 | expect(paces.find((r) => r.reader === "other")!.reads).toBe(1); | |
| 33 | expect(paces.find((r) => r.reader === "r200")).toBeUndefined(); | |
| 34 | expect(telemetryReadsFamily().samples.length).toBe(201); | |
| 35 | }); | |
| 36 | ||
| 37 | test("the section escapes names, flags, and says so when empty", () => { | |
| 38 | expect(readersSection([]).text).toContain("No telemetry reads in the last 10 minutes."); | |
| 39 | countRead("flow", "<b>x</b>", T0); | |
| 40 | countRead("flow", "<b>x</b>", T0 + 1000); | |
| 41 | const text = readersSection(readerPaces(T0 + 2000)).text; | |
| 42 | expect(text).toContain("<b>x</b>"); | |
| 43 | expect(text).not.toContain("<b>x</b>"); | |
| 44 | expect(text).toContain("faster than the flow copy changes"); | |
| 45 | }); |
test/tui-system.test.ts +27 −1
| @@ -15,7 +15,8 @@ import { createUser, type User } from "../src/core/users.ts"; | ||
| 15 | 15 | import { createForgeApp, forgeCommands, Session } from "../src/tui/forge.ts"; |
| 16 | 16 | import { setTelemetryGrant } from "../src/actions/telemetry.ts"; |
| 17 | 17 | import { hasGrant } from "../src/core/telemetry.ts"; |
| 18 | import { forgeLines, historyLines, memoryLines, memoryScreen, systemScreen } from "../src/tui/screens/system.ts"; | |
| 18 | import { countRead, resetTelemetryReads } from "../src/system/telemetry_reads.ts"; | |
| 19 | import { forgeLines, historyLines, readerLines, memoryLines, memoryScreen, systemScreen } from "../src/tui/screens/system.ts"; | |
| 19 | 20 | import { headlessTerminal } from "../src/tui/term/terminal.ts"; |
| 20 | 21 | import { quietLogs } from "./helpers/globals.ts"; |
| 21 | 22 | import { settleApp } from "./helpers/tui.ts"; |
| @@ -283,3 +284,28 @@ describe("tui system: the forge's own state (#7296)", () => { | ||
| 283 | 284 | expect(forgeLines(readHealth(app, undefined))).toEqual(["forge 9.8.7 · 0123456 · serving"]); |
| 284 | 285 | }); |
| 285 | 286 | }); |
| 287 | ||
| 288 | describe("tui system telemetry readers (#9069)", () => { | |
| 289 | test("an admin sees each reader's pace and the flag; anyone else sees nothing", async () => { | |
| 290 | resetTelemetryReads(); | |
| 291 | const t0 = Date.now(); | |
| 292 | for (let i = 0; i < 5; i++) countRead("flow", "fastbot", t0 - 10_000 + i * 2000); | |
| 293 | countRead("system", "slowbot", t0 - 4000); | |
| 294 | countRead("system", "slowbot", t0 - 1000); | |
| 295 | const lines = readerLines(new Session(app, identity(carol)), t0); | |
| 296 | expect(lines[0]).toContain("Telemetry readers"); | |
| 297 | expect(lines.find((l) => l.includes("fastbot"))).toMatch(/flow\s+fastbot\s+5\s+2\.0 s\s+TOO FAST/); | |
| 298 | expect(lines.find((l) => l.includes("slowbot"))).toMatch(/system\s+slowbot\s+2\s+3\.0 s$/); | |
| 299 | for (const who of [bob, bot, undefined]) expect(readerLines(new Session(app, identity(who)), t0)).toEqual([]); | |
| 300 | ||
| 301 | const terminal = headlessTerminal(120, 60); | |
| 302 | const { app: tui, session } = createForgeApp(app, identity(carol), { terminal, exitHooks: false }); | |
| 303 | tui.start(); | |
| 304 | tui.ctx.push(systemScreen(tui.ctx, ["CPU"], session)); | |
| 305 | await settleApp(tui); | |
| 306 | expect(tui.screen.toText()).toContain("fastbot"); | |
| 307 | expect(tui.screen.toText()).toContain("TOO FAST"); | |
| 308 | tui.stop?.(); | |
| 309 | resetTelemetryReads(); | |
| 310 | }); | |
| 311 | }); |
new above
offline
Same data must reach the terminal: add it to src/tui/screens/system.ts, and write docs/features/telemetry-readers.md.