Public: anyone can read this; the crew can change it.
/metrics adds the delivery series: pulls merged, releases, ask-to-live seconds, red-main seconds #4057
Check · Review · Land · Live done — Landed and live in production.
scout/forge:scout/3750-metrics-adds-the-delivery-series-pulls-m → main 4 commits fork 2 threads · 2 unresolved
6 files
changed +246
−5
docs/METRICS.md +10
| @@ -12,6 +12,10 @@ not an admin, 200 for an admin's `ro` token. It is never cached | ||
| 12 | 12 | | `forge_egress_bytes_in` | gauge | `repo`, `destination` | Bytes received from the destination over open connections. | |
| 13 | 13 | | `forge_egress_bytes_out` | gauge | `repo`, `destination` | Bytes sent to the destination over open connections. | |
| 14 | 14 | | `forge_http_request_duration_seconds` | histogram | `pattern` (plus `le`) | Seconds taken to answer a request, by the route pattern matched (never the raw path), since the process started. Buckets are `route_timing`'s edges, 1 ms to 2.5 s, in seconds. | |
| 15 | | `forge_pulls_merged_total` | counter | `repo` | Pulls merged, from `pull.merged_at`. | | |
| 16 | | `forge_releases_total` | counter | none | Releases that went live, from the `release` table's `ok` rows. | | |
| 17 | | `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. | | |
| 18 | | `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. | | |
| 15 | 19 | | `forge_app_up` | gauge | `app`, `env` | 1 when the app environment is serving, 0 when it is asleep, stopped, deploying or failed. | |
| 16 | 20 | | `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. | |
| 17 | 21 | | `forge_cell_memory_bytes` | gauge | `app`, `env` | Resident memory of the processes of a running app cell. | |
| @@ -21,6 +25,12 @@ never in the body. `env` is `production` or `pull-<n>`. The cell families are | ||
| 21 | 25 | what the cell watch last read (every few seconds); a cell that is not running |
| 22 | 26 | has no series (a cell keeps the slug it started under, so after a rename its figures return when it restarts), and the forge starts nothing and reads no process to answer. |
| 23 | 27 | |
| 28 | The delivery series are read from the `pull`, `release` and `run` tables on | |
| 29 | every scrape, so the scrape cost grows with those tables. | |
| 30 | ||
| 31 | A public repository's `repo` label is `owner/name`; a private one appears | |
| 32 | under its id only, never its name. | |
| 33 | ||
| 24 | 34 | The duration histogram counts every request the process has answered since |
| 25 | 35 | it started; its `_bucket`, `_count` and `_sum` only grow, so `rate()` and |
| 26 | 36 | `histogram_quantile()` read it as Prometheus expects. A restart starts it at |
src/metrics/forge.ts +140 −2
| @@ -5,12 +5,16 @@ | ||
| 5 | 5 | * totals `route_timing` keeps in memory since the process started, not from |
| 6 | 6 | * the hourly table, so every value only grows (#4013): Prometheus reads a drop |
| 7 | 7 | * as a counter reset, and a restart resets them, which it expects. Nothing is |
| 8 | * started or shelled out to read a figure. The text comes from `openmetrics.ts`. | |
| 8 | * started or shelled out to read a figure. The delivery series (#4057) are | |
| 9 | * read from the tables that hold the facts: `pull`, `release` (successful rows | |
| 10 | * only) and the default branch's `run` rows. The text comes from | |
| 11 | * `openmetrics.ts`. | |
| 9 | 12 | */ |
| 10 | 13 | import type { Database } from "bun:sqlite"; |
| 11 | 14 | import type { CellCounter } from "../apps/contain.ts"; |
| 12 | 15 | import type { EnvState } from "../apps/runtime.ts"; |
| 13 | 16 | import { EDGES_MS, readTotals } from "../core/route_timing.ts"; |
| 17 | import { closesFromBody } from "../core/pulls.ts"; | |
| 14 | 18 | import { openMetrics, type Family, type HistogramSample, type Sample } from "./openmetrics.ts"; |
| 15 | 19 | |
| 16 | 20 | export const DURATION_FAMILY = "forge_http_request_duration_seconds"; |
| @@ -35,6 +39,132 @@ export function durationFamily(db: Database): Family { | ||
| 35 | 39 | }; |
| 36 | 40 | } |
| 37 | 41 | |
| 42 | export const PULLS_FAMILY = "forge_pulls_merged_total"; | |
| 43 | export const RELEASES_FAMILY = "forge_releases_total"; | |
| 44 | export const ASK_FAMILY = "forge_ask_to_live_seconds"; | |
| 45 | export const RED_FAMILY = "forge_main_red_seconds_total"; | |
| 46 | ||
| 47 | /** Ask-to-live bucket edges in seconds: a minute to a week. */ | |
| 48 | export const ASK_EDGES_S = [60, 300, 900, 3600, 14_400, 43_200, 86_400, 259_200, 604_800]; | |
| 49 | ||
| 50 | /** A repository's label: `owner/name` when public, its id alone when private. */ | |
| 51 | const REPO_LABEL = `CASE WHEN repo.visibility = 'public' THEN user.username || '/' || repo.name ELSE repo.id END`; | |
| 52 | ||
| 53 | const seconds = (from: string, to: string): number => Math.max(0, (Date.parse(to) - Date.parse(from)) / 1000); | |
| 54 | ||
| 55 | const bySeries = (a: Sample, b: Sample): number => | |
| 56 | (a.labels?.repo ?? "") < (b.labels?.repo ?? "") ? -1 : 1; | |
| 57 | ||
| 58 | /** Pulls merged, per repository: one grouped read of `pull` by its issue's repository. */ | |
| 59 | export function pullsMergedFamily(db: Database): Family { | |
| 60 | const rows = db | |
| 61 | .query<{ repo: string; n: number }, []>( | |
| 62 | `SELECT ${REPO_LABEL} AS repo, COUNT(*) AS n | |
| 63 | FROM pull JOIN issue ON issue.id = pull.issue_id | |
| 64 | JOIN repo ON repo.id = issue.repo_id JOIN user ON user.id = repo.owner_id | |
| 65 | WHERE pull.merged_at IS NOT NULL GROUP BY repo.id`, | |
| 66 | ) | |
| 67 | .all(); | |
| 68 | return { | |
| 69 | type: "counter", | |
| 70 | name: PULLS_FAMILY, | |
| 71 | help: "Pulls merged, by repository.", | |
| 72 | samples: rows.map((r) => ({ labels: { repo: r.repo }, value: r.n })).sort(bySeries), | |
| 73 | }; | |
| 74 | } | |
| 75 | ||
| 76 | /** Releases cut: one count of the `release` rows that went live (`ok = 1`). */ | |
| 77 | export function releasesFamily(db: Database): Family { | |
| 78 | const row = db.query<{ n: number }, []>("SELECT COUNT(*) AS n FROM release WHERE ok = 1").get(); | |
| 79 | return { type: "counter", name: RELEASES_FAMILY, help: "Releases cut.", samples: [{ value: row?.n ?? 0 }] }; | |
| 80 | } | |
| 81 | ||
| 82 | /** | |
| 83 | * Seconds from an ask opening to the release of the pull that closes it. Each | |
| 84 | * release names its pull; the pull's body names the issues it closes; the | |
| 85 | * first successful release of a pull counts once, against the oldest issue it closes. | |
| 86 | */ | |
| 87 | export function askToLiveFamily(db: Database): Family { | |
| 88 | const releases = db | |
| 89 | .query<{ at: string; body: string; repo_id: string }, []>( | |
| 90 | `SELECT MIN(release.created_at) AS at, issue.body, issue.repo_id | |
| 91 | FROM release JOIN issue ON issue.repo_id = release.repo_id | |
| 92 | AND issue.number = release.pull_number AND issue.kind = 'pull' | |
| 93 | WHERE release.pull_number IS NOT NULL AND release.ok = 1 GROUP BY issue.id`, | |
| 94 | ) | |
| 95 | .all(); | |
| 96 | const opened = db.query<{ created_at: string }, [string, number]>( | |
| 97 | "SELECT created_at FROM issue WHERE repo_id = ?1 AND number = ?2 AND kind = 'issue'", | |
| 98 | ); | |
| 99 | const counts = new Array<number>(ASK_EDGES_S.length).fill(0); | |
| 100 | let count = 0; | |
| 101 | let sum = 0; | |
| 102 | for (const r of releases) { | |
| 103 | let from: string | undefined; | |
| 104 | for (const n of closesFromBody(r.body)) { | |
| 105 | const at = opened.get(r.repo_id, n)?.created_at; | |
| 106 | if (at !== undefined && (from === undefined || at < from)) from = at; | |
| 107 | } | |
| 108 | if (from === undefined) continue; | |
| 109 | const s = seconds(from, r.at); | |
| 110 | count++; | |
| 111 | sum += s; | |
| 112 | const i = ASK_EDGES_S.findIndex((edge) => s <= edge); | |
| 113 | if (i >= 0) counts[i]!++; | |
| 114 | } | |
| 115 | let running = 0; | |
| 116 | const buckets = ASK_EDGES_S.map((le, i) => ({ le, count: (running += counts[i]!) })); | |
| 117 | return { | |
| 118 | type: "histogram", | |
| 119 | name: ASK_FAMILY, | |
| 120 | help: "Seconds from an issue opening to the release of the pull that closed it.", | |
| 121 | samples: [{ buckets, count, sum }], | |
| 122 | }; | |
| 123 | } | |
| 124 | ||
| 125 | /** | |
| 126 | * Seconds the default branch's check spent failing, per repository: from a | |
| 127 | * failed check's finish to the finish of the next green one (or `now` while | |
| 128 | * it is still red). One read of the branch's finished checks in run order. | |
| 129 | */ | |
| 130 | export function mainRedFamily(db: Database, now: number = Date.now()): Family { | |
| 131 | const rows = db | |
| 132 | .query<{ repo: string; repo_id: string; state: string; finished_at: string | null }, []>( | |
| 133 | `SELECT ${REPO_LABEL} AS repo, run.repo_id, run.state, run.finished_at | |
| 134 | FROM run JOIN repo ON repo.id = run.repo_id JOIN user ON user.id = repo.owner_id | |
| 135 | WHERE run.kind = 'check' AND run.issue_id IS NULL AND run.env = repo.default_branch | |
| 136 | AND run.state IN ('ok','failed') AND run.finished_at IS NOT NULL | |
| 137 | ORDER BY run.repo_id, run.id`, | |
| 138 | ) | |
| 139 | .all(); | |
| 140 | const red = new Map<string, number>(); | |
| 141 | const since = new Map<string, string>(); | |
| 142 | const nowIso = new Date(now).toISOString(); | |
| 143 | const seen = new Set<string>(); | |
| 144 | const close = (id: string, at: string): void => { | |
| 145 | const from = since.get(id); | |
| 146 | if (from === undefined) return; | |
| 147 | red.set(id, (red.get(id) ?? 0) + seconds(from, at)); | |
| 148 | since.delete(id); | |
| 149 | }; | |
| 150 | const labels = new Map<string, string>(); | |
| 151 | for (const r of rows) { | |
| 152 | labels.set(r.repo_id, r.repo); | |
| 153 | seen.add(r.repo_id); | |
| 154 | if (r.state === "failed") { | |
| 155 | if (!since.has(r.repo_id)) since.set(r.repo_id, r.finished_at!); | |
| 156 | } else close(r.repo_id, r.finished_at!); | |
| 157 | } | |
| 158 | for (const id of [...since.keys()]) close(id, nowIso); | |
| 159 | const samples = [...seen].map((id) => ({ labels: { repo: labels.get(id)! }, value: red.get(id) ?? 0 })); | |
| 160 | return { | |
| 161 | type: "counter", | |
| 162 | name: RED_FAMILY, | |
| 163 | help: "Seconds the default branch's check spent failing, by repository.", | |
| 164 | samples: samples.sort(bySeries), | |
| 165 | }; | |
| 166 | } | |
| 167 | ||
| 38 | 168 | export const UP_FAMILY = "forge_app_up"; |
| 39 | 169 | export const CELL_CPU_FAMILY = "forge_cell_cpu_seconds_total"; |
| 40 | 170 | export const CELL_MEMORY_FAMILY = "forge_cell_memory_bytes"; |
| @@ -96,6 +226,14 @@ export function appFamilies({ apps, cells }: AppSources): Family[] { | ||
| 96 | 226 | export function forgeMetrics( |
| 97 | 227 | db: Database, |
| 98 | 228 | sources: AppSources = { apps: [], cells: [] }, |
| 229 | now: number = Date.now(), | |
| 99 | 230 | ): string { |
| 100 | return openMetrics([durationFamily(db), ...appFamilies(sources)]).replace(/# EOF\n$/, ""); | |
| 231 | return openMetrics([ | |
| 232 | durationFamily(db), | |
| 233 | ...appFamilies(sources), | |
| 234 | pullsMergedFamily(db), | |
| 235 | releasesFamily(db), | |
| 236 | askToLiveFamily(db), | |
| 237 | mainRedFamily(db, now), | |
| 238 | ]).replace(/# EOF\n$/, ""); | |
| 101 | 239 | } |
test/metrics-cells.test.ts +4 −2
| @@ -5,6 +5,8 @@ import { Database } from "bun:sqlite"; | ||
| 5 | 5 | import type { CellCounter } from "../src/apps/contain.ts"; |
| 6 | 6 | import { appFamilies, forgeMetrics, type AppReading } from "../src/metrics/forge.ts"; |
| 7 | 7 | import { openMetrics } from "../src/metrics/openmetrics.ts"; |
| 8 | import { migrate } from "../src/kernel/migrate.ts"; | |
| 9 | import { migrationFiles } from "../src/core/schema.ts"; | |
| 8 | 10 | |
| 9 | 11 | const app = (state: "running" | "asleep"): AppReading[] => [ |
| 10 | 12 | { id: "app1", slug: "notes", private: false, envs: [{ env: "production", state }] }, |
| @@ -35,7 +37,7 @@ test("a private app appears under its id only", () => { | ||
| 35 | 37 | |
| 36 | 38 | test("forgeMetrics carries the families as Prometheus text without a trailing EOF", () => { |
| 37 | 39 | const db = new Database(":memory:"); |
| 38 | db.run("CREATE TABLE route_timing (hour TEXT, pattern TEXT, bucket INTEGER, n INTEGER, sum_us INTEGER)"); | |
| 40 | migrate(db, migrationFiles); | |
| 39 | 41 | const body = forgeMetrics(db, { apps: app("running"), cells: [] }); |
| 40 | 42 | expect(body).toContain("# TYPE forge_app_up gauge"); |
| 41 | 43 | expect(body).toContain("# TYPE forge_cell_cpu_seconds counter"); |
| @@ -44,7 +46,7 @@ test("forgeMetrics carries the families as Prometheus text without a trailing EO | ||
| 44 | 46 | |
| 45 | 47 | test("two cells under one label (a deploy's old and new) are one series, summed, and the scrape does not throw", () => { |
| 46 | 48 | const db = new Database(":memory:"); |
| 47 | db.run("CREATE TABLE route_timing (hour TEXT, pattern TEXT, bucket INTEGER, n INTEGER, sum_us INTEGER)"); | |
| 49 | migrate(db, migrationFiles); | |
| 48 | 50 | const cells = [cell("app:notes/production"), { ...cell("app:notes/production"), key: 2 }]; |
| 49 | 51 | const body = forgeMetrics(db, { apps: app("running"), cells }); |
| 50 | 52 | expect(body).toContain('forge_cell_memory_bytes{app="notes",env="production"} 8192'); |
test/metrics-delivery.test.ts added +89
| @@ -0,0 +1,89 @@ | ||
| 1 | /** The delivery series on `/metrics` (#3750): each moves when its fact lands, and a private repository shows its id only. */ | |
The header cites #3750, but this pull is #4057. |
||
| 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 { recordRelease } from "../src/release/record.ts"; | |
| 9 | import { forgeMetrics } from "../src/metrics/forge.ts"; | |
| 10 | ||
| 11 | let dir: string; | |
| 12 | let app: App; | |
| 13 | ||
| 14 | beforeAll(async () => { | |
| 15 | dir = await mkdtemp(join(tmpdir(), "metrics-delivery-")); | |
| 16 | app = createApp({ dataDir: dir, port: 0 }); | |
| 17 | app.db.run("INSERT INTO user (id, username, email, password_hash) VALUES ('u1', 'ann', '[email protected]', 'x')"); | |
| 18 | app.db.run("INSERT INTO repo (id, owner_id, name, visibility) VALUES ('rpub', 'u1', 'open', 'public')"); | |
| 19 | app.db.run("INSERT INTO repo (id, owner_id, name, visibility) VALUES ('rpriv', 'u1', 'secretname', 'private')"); | |
| 20 | }); | |
| 21 | ||
| 22 | afterAll(async () => { | |
| 23 | app.close(); | |
| 24 | await rm(dir, { recursive: true, force: true }); | |
| 25 | }); | |
| 26 | ||
| 27 | const text = (now?: number) => forgeMetrics(app.db, undefined, now); | |
| 28 | const issue = (id: string, repo: string, n: number, kind: string, body: string, at: string) => | |
| 29 | app.db.run( | |
| 30 | "INSERT INTO issue (id, repo_id, number, kind, title, body, author_id, created_at) VALUES (?1, ?2, ?3, ?4, 't', ?5, 'u1', ?6)", | |
| 31 | [id, repo, n, kind, body, at], | |
| 32 | ); | |
| 33 | ||
| 34 | test("a merged pull moves forge_pulls_merged_total, public by name and private by id", () => { | |
| 35 | expect(text()).not.toContain("forge_pulls_merged_total{"); | |
| 36 | issue("p1", "rpub", 2, "pull", "Closes #1", "2026-01-01T00:10:00.000Z"); | |
| 37 | issue("p2", "rpriv", 1, "pull", "", "2026-01-01T00:10:00.000Z"); | |
| 38 | for (const id of ["p1", "p2"]) | |
| 39 | app.db.run("INSERT INTO pull (issue_id, base_branch, head_branch, base_oid, head_oid, merged_at) VALUES (?1,'main','h','a','b','2026-01-01T01:00:00.000Z')", [id]); | |
| 40 | const t = text(); | |
| 41 | expect(t).toContain('forge_pulls_merged_total{repo="ann/open"} 1'); | |
| 42 | expect(t).toContain('forge_pulls_merged_total{repo="rpriv"} 1'); | |
| 43 | expect(t).not.toContain("secretname"); | |
| 44 | }); | |
| 45 | ||
| 46 | test("a release moves forge_releases_total and the ask-to-live histogram", () => { | |
| 47 | issue("i1", "rpub", 1, "issue", "ask", "2026-01-01T00:00:00.000Z"); | |
| 48 | expect(text()).toContain("forge_releases_total 0"); | |
| 49 | expect(text()).toContain("forge_ask_to_live_seconds_count 0"); | |
| 50 | const r = recordRelease(app.db, { sha: "abc", repoId: "rpub", pullNumber: 2, ok: true, line: "ok" }); | |
| 51 | app.db.run("UPDATE release SET created_at = '2026-01-01T00:30:00.000Z' WHERE id = ?1", [r.id]); | |
| 52 | const t = text(); | |
| 53 | expect(t).toContain("forge_releases_total 1"); | |
| 54 | expect(t).toContain("forge_ask_to_live_seconds_count 1"); | |
| 55 | expect(t).toContain("forge_ask_to_live_seconds_sum 1800"); | |
| 56 | expect(t).toContain('forge_ask_to_live_seconds_bucket{le="900"} 0'); | |
| 57 | expect(t).toContain('forge_ask_to_live_seconds_bucket{le="3600"} 1'); | |
| 58 | }); | |
| 59 | ||
| 60 | test("a failing then fixed main moves forge_main_red_seconds_total", () => { | |
| 61 | const run = (id: string, state: string, at: string) => | |
| 62 | app.db.run( | |
| 63 | "INSERT INTO run (id, repo_id, kind, env, state, finished_at) VALUES (?1, 'rpriv', 'check', 'main', ?2, ?3)", | |
| 64 | [id, state, at], | |
| 65 | ); | |
| 66 | run("r1", "ok", "2026-02-01T00:00:00.000Z"); | |
| 67 | expect(text()).toContain('forge_main_red_seconds_total{repo="rpriv"} 0'); | |
| 68 | run("r2", "failed", "2026-02-01T01:00:00.000Z"); | |
| 69 | const still = Date.parse("2026-02-01T01:01:00.000Z"); | |
| 70 | expect(text(still)).toContain('forge_main_red_seconds_total{repo="rpriv"} 60'); | |
| 71 | run("r3", "ok", "2026-02-01T01:10:00.000Z"); | |
| 72 | expect(text(still + 86_400_000)).toContain('forge_main_red_seconds_total{repo="rpriv"} 600'); | |
| 73 | }); | |
| 74 | ||
| 75 | test("a failed release is not the ask going live: only the good one counts", () => { | |
| 76 | issue("i9", "rpub", 8, "issue", "ask", "2026-02-01T00:00:00.000Z"); | |
| 77 | issue("p9", "rpub", 9, "pull", "Closes #8", "2026-02-01T00:01:00.000Z"); | |
| 78 | const before = /forge_releases_total (\d+)/.exec(text())![1]!; | |
| 79 | const sumBefore = Number(/forge_ask_to_live_seconds_sum (\S+)/.exec(text())![1]); | |
| 80 | const at = (ok: boolean, time: string) => { | |
| 81 | const r = recordRelease(app.db, { sha: "def", repoId: "rpub", pullNumber: 9, ok, line: "x" }); | |
| 82 | app.db.run("UPDATE release SET created_at = ?2 WHERE id = ?1", [r.id, time]); | |
| 83 | }; | |
| 84 | at(false, "2026-02-01T00:05:00.000Z"); | |
| 85 | at(true, "2026-02-01T00:30:00.000Z"); | |
| 86 | const t = text(); | |
| 87 | expect(Number(/forge_ask_to_live_seconds_sum (\S+)/.exec(t)![1]) - sumBefore).toBe(1800); | |
| 88 | expect(Number(/forge_releases_total (\d+)/.exec(t)![1]) - Number(before)).toBe(1); | |
| 89 | }); |
test/metrics-forge.test.ts +1
| @@ -47,6 +47,7 @@ test("no bucket, count or sum drops as the hours pass", () => { | ||
| 47 | 47 | |
| 48 | 48 | test("the HELP line says since the process started, not the last hour", () => { |
| 49 | 49 | const db = new Database(":memory:"); |
| 50 | migrate(db, migrationFiles); | |
| 50 | 51 | expect(forgeMetrics(db)).toContain( |
| 51 | 52 | "# HELP forge_http_request_duration_seconds Seconds the forge took to answer a request, by route pattern, since the process started.", |
| 52 | 53 | ); |
test/metrics-route.test.ts +2 −1
| @@ -73,5 +73,6 @@ test("every family the route serves is listed in docs/METRICS.md", async () => { | ||
| 73 | 73 | const families = [...text.matchAll(/^# TYPE (\S+) /gm)].map((m) => m[1]!); |
| 74 | 74 | expect(families).toContain("forge_egress_connections"); |
| 75 | 75 | expect(families).toContain("forge_http_request_duration_seconds"); |
| 76 | for (const f of families) expect(doc).toContain(`\`${f}\``); | |
| 76 | // A counter's TYPE line names the family without `_total`; the doc names the sample. | |
| 77 | for (const f of families) expect(doc.includes(`\`${f}\``) || doc.includes(`\`${f}_total\``)).toBe(true); | |
| 77 | 78 | }); |
new above
offline
The seen set duplicates labels.keys(). Drop it and iterate labels.