Public: anyone can read this; the crew can change it.
The forge alarms when main is green and ahead of production for more than 90… #11512
Check · Review · Land · Live — Changes were asked on this head.
scout/forge:scout/11507-the-forge-alarms-when-main-is-green-and → main 3 commits fork 2 threads · 2 unresolved
14 files
changed +403
−7
docs/features/release-heartbeat.md added +7
| @@ -0,0 +1,7 @@ | ||
| 1 | # Release heartbeat and the main-ahead alarm (#11507) | |
| 2 | ||
| 3 | The release tick records a heartbeat each time it runs (`src/keeper/beat.ts`, table `keeper_beat`): when, whether it cut, skipped or failed, and why. `release_keeper`, `GET /api/v1/keeper` (`heartbeat`) show the last one. None for 60 minutes is said plainly ("No heartbeat from the release tick for …"). | |
| 4 | ||
| 5 | The flow alarm `main_ahead` (`src/flow/alarm_main_ahead.ts`) fires when main's last finished check passed, its head is not the commit production runs, and main has been ahead for more than 90 minutes. Change the limit with the `release.ahead_minutes` row of `forge_setting` (1 to 10080). It names production's version and commit, the commits and pulls ahead, how long, and when the tick was last heard from. It is an ask for the owner (home) and one Sentinel issue, which closes itself at the next hunt after production catches up. | |
| 6 | ||
| 7 | `/api/v1/telemetry/home`: `live` is now the commit production runs; `production` names it with its version, `main` is main's newest deploy. |
src/contract/openapi/routes/getApiV1TelemetryHome.ts +1 −1
| @@ -1,3 +1,3 @@ | ||
| 1 | 1 | import type { Route } from "../shared.ts"; |
| 2 | 2 | |
| 3 | export const route: Route = { method: "get", path: "/api/v1/telemetry/home", summary: "Read the figures the home is scored against: landed in 24 h, live version, builders and why idle, spend against the ceiling, what waits on the caller; the owner or an agent holding telemetry:read, with a ro token; every agent read is logged", auth: true, role: "member" }; | |
| 3 | export const route: Route = { method: "get", path: "/api/v1/telemetry/home", summary: "Read the figures the home is scored against: landed in 24 h, live version (live.sha is the commit production runs; main.sha is main's newest deploy), builders and why idle, spend against the ceiling, what waits on the caller; the owner or an agent holding telemetry:read, with a ro token; every agent read is logged", auth: true, role: "member" }; |
src/core/migration-pins/20261111170000-keeper-beat.pin added +1
| @@ -0,0 +1,1 @@ | ||
| 1 | a57e110db188bf5db091597675159f303ad60ac496f0c841a66d62e09a6df833 |
src/core/migrations/20261111170000-keeper-beat.ts added +10
| @@ -0,0 +1,10 @@ | ||
| 1 | // The release tick's last heartbeat (#11507): one row, replaced each time the tick | |
| 2 | // reports in — when, what it did (cut, skipped, failed) and why. Additive. | |
| 3 | export default ` | |
| 4 | CREATE TABLE keeper_beat ( | |
| 5 | id INTEGER PRIMARY KEY CHECK (id = 1), | |
| 6 | at TEXT NOT NULL, | |
| 7 | outcome TEXT NOT NULL CHECK (outcome IN ('cut', 'skipped', 'failed')), | |
| 8 | reason TEXT NOT NULL | |
| 9 | ); | |
| 10 | `; |
src/crew/sentinel.ts +45 −1
| @@ -47,6 +47,7 @@ import { | ||
| 47 | 47 | } from "../checks/shared_red.ts"; |
| 48 | 48 | import { readRunLogTail } from "../runs/log.ts"; |
| 49 | 49 | import { clip } from "../text/clip.ts"; |
| 50 | import { mainAheadAlarm } from "../flow/alarm_main_ahead.ts"; | |
| 50 | 51 | import type { FindingKind } from "../hunt/finding.ts"; |
| 51 | 52 | import { addLabels, kindLabels } from "../hunt/label.ts"; |
| 52 | 53 | |
| @@ -569,8 +570,47 @@ function sharedLines( | ||
| 569 | 570 | } |
| 570 | 571 | |
| 571 | 572 | /** Everything the sentinel reads, in one pass. */ |
| 573 | /** Main green and ahead of production past the setting (#11507): one finding; it closes when production catches up (`closeCaughtUp`). */ | |
| 574 | export const MAIN_AHEAD_KEY = "main-ahead"; | |
| 575 | export function mainAhead(db: Database, now: number): Finding[] { | |
| 576 | const a = mainAheadAlarm(db, new Date(now)); | |
| 577 | if (!a.fired) return []; | |
| 578 | return [{ | |
| 579 | key: MAIN_AHEAD_KEY, | |
| 580 | title: "Main is green and ahead of production: the release tick has not cut", | |
| 581 | evidence: a.facts ?? [a.says], | |
| 582 | pillar: "P0 Trust: the forge says when it is not well, and is well again", | |
| 583 | kind: "defect", | |
| 584 | lookFor: "Production runs main's head, or main has been ahead of it for under the limit.", | |
| 585 | urgent: true, | |
| 586 | }]; | |
| 587 | } | |
| 588 | ||
| 589 | /** The alarm's issue closes itself when production catches up; one a person spoke on is theirs to close. */ | |
| 590 | function closeCaughtUp(app: App, repo: Repo, actor: User, active: ReadonlySet<string>, now: number): void { | |
| 591 | if (active.has(MAIN_AHEAD_KEY)) return; | |
| 592 | const open = app.db | |
| 593 | .query<{ issue_id: string }, [string]>( | |
| 594 | `SELECT t.issue_id FROM sentinel_finding t JOIN issue i ON i.id = t.issue_id WHERE i.state = 'open' AND t.key = ?1`, | |
| 595 | ) | |
| 596 | .all(MAIN_AHEAD_KEY); | |
| 597 | for (const t of open) { | |
| 598 | try { | |
| 599 | if (personSpoke(app.db, t.issue_id)) continue; | |
| 600 | const issue = getIssueById(app.db, t.issue_id); | |
| 601 | if (issue === undefined || issue.repoId !== repo.id) continue; | |
| 602 | const said = addComment(app, actor, repo, issue, `Production caught up with main at ${new Date(now).toISOString()}. Closing as done; if it falls behind again it is filed again.`); | |
| 603 | if (!said.ok) continue; | |
| 604 | setIssueState(app, actor, repo, issue, "closed", { reason: "done", system: true }); | |
| 605 | } catch (error) { | |
| 606 | log.error("sentinel close failed", { key: MAIN_AHEAD_KEY, error: String(error) }); | |
| 607 | } | |
| 608 | } | |
| 609 | } | |
| 610 | ||
| 572 | 611 | export function findFaults(db: Database, now = Date.now(), forgeRepoId?: string, dataDir?: string): Finding[] { |
| 573 | 612 | const found = [ |
| 613 | ...mainAhead(db, now), | |
| 574 | 614 | ...budgetBreaches(db, now, forgeRepoId, dataDir), |
| 575 | 615 | ...heldSlots(db, now), |
| 576 | 616 | ...strayTriggers(db), |
| @@ -1107,7 +1147,11 @@ export function hunt( | ||
| 1107 | 1147 | } |
| 1108 | 1148 | } |
| 1109 | 1149 | if (repo !== undefined && actor !== undefined) |
| 1110 | closeHeld(app, repo, actor, new Set(findings.map((f) => f.key)), now); | |
| 1150 | { | |
| 1151 | const active = new Set(findings.map((f) => f.key)); | |
| 1152 | closeHeld(app, repo, actor, active, now); | |
| 1153 | closeCaughtUp(app, repo, actor, active, now); | |
| 1154 | } | |
| 1111 | 1155 | // A hunt with nowhere to file is recorded as such, never as a quiet one. |
| 1112 | 1156 | const unfiled = repo === undefined || actor === undefined; |
| 1113 | 1157 | app.db |
src/flow/alarm_main_ahead.ts added +81
| @@ -0,0 +1,81 @@ | ||
| 1 | /** | |
| 2 | * The "main is ahead of production" flow alarm (#11507): the forge's own main | |
| 3 | * head is proven green (its last finished check passed), differs from the | |
| 4 | * commit production runs, and has for longer than the setting | |
| 5 | * `release.ahead_minutes` (default 90). On 2026-11-11 production stood still | |
| 6 | * for 5 h 50 min with main green and nothing said so. Names production's | |
| 7 | * version and commit, how far main is ahead (commits and pulls), how long, and | |
| 8 | * the last time the release tick was heard from. Pure of the clock. | |
| 9 | */ | |
| 10 | ||
| 11 | import type { Database } from "bun:sqlite"; | |
| 12 | import { getRepo } from "../core/repos.ts"; | |
| 13 | import { agoWords, lastBeat } from "../keeper/beat.ts"; | |
| 14 | import { ownRepoPath } from "../kernel/own_repo.ts"; | |
| 15 | import { running } from "../kernel/version.ts"; | |
| 16 | import { waitingRows } from "../release/landings.ts"; | |
| 17 | ||
| 18 | export const AHEAD_SETTING = "release.ahead_minutes"; | |
| 19 | export const AHEAD_DEFAULT_MIN = 90; | |
| 20 | ||
| 21 | export interface MainAheadAlarm { | |
| 22 | readonly fired: boolean; | |
| 23 | /** When main first moved past production; while it is ahead. */ | |
| 24 | readonly since?: string; | |
| 25 | readonly says: string; | |
| 26 | /** Facts for the issue and the ask; only when fired. */ | |
| 27 | readonly facts?: readonly string[]; | |
| 28 | } | |
| 29 | ||
| 30 | /** The minutes main may be ahead and green before the alarm; a whole number of 1 or more is the owner's, else 90. */ | |
| 31 | export function aheadMinutes(db: Database): number { | |
| 32 | const row = db.query<{ value: string }, [string]>("SELECT value FROM forge_setting WHERE key = ?1").get(AHEAD_SETTING); | |
| 33 | const n = row === null ? NaN : Number(row.value); | |
| 34 | return Number.isInteger(n) && n >= 1 && n <= 10_080 ? n : AHEAD_DEFAULT_MIN; | |
| 35 | } | |
| 36 | ||
| 37 | /** The commit of the last finished check of the forge's default branch, when that check passed. */ | |
| 38 | function greenHead(db: Database): string | undefined { | |
| 39 | const [owner, name] = ownRepoPath().split("/"); | |
| 40 | const repo = owner && name ? getRepo(db, owner, name) : undefined; | |
| 41 | if (repo === undefined) return undefined; | |
| 42 | const last = db | |
| 43 | .query<{ state: string; commit_oid: string }, [string, string]>( | |
| 44 | `SELECT state, commit_oid FROM run | |
| 45 | WHERE repo_id = ?1 AND kind = 'check' AND issue_id IS NULL AND env = ?2 AND state IN ('ok', 'failed') | |
| 46 | ORDER BY id DESC LIMIT 1`, | |
| 47 | ) | |
| 48 | .get(repo.id, repo.defaultBranch); | |
| 49 | return last?.state === "ok" ? last.commit_oid : undefined; | |
| 50 | } | |
| 51 | ||
| 52 | export function mainAheadAlarm(db: Database, now: Date): MainAheadAlarm { | |
| 53 | const prod = running(); | |
| 54 | const head = greenHead(db); | |
| 55 | const waiting = waitingRows(db); | |
| 56 | const first = waiting[0]; | |
| 57 | if (head === undefined || prod.commit === null || first === undefined || head.startsWith(prod.commit) || prod.commit.startsWith(head)) | |
| 58 | return { fired: false, says: "Production runs main's head, or main's head is not proven green." }; | |
| 59 | const wait = now.getTime() - Date.parse(first.at); | |
| 60 | const limit = aheadMinutes(db) * 60_000; | |
| 61 | if (!(wait > limit)) return { fired: false, since: first.at, says: `Main is ahead of production ${agoWords(wait).replace(" ago", "")}; not yet due.` }; | |
| 62 | const commits = new Set(waiting.map((r) => r.oid).filter((o) => o !== "")).size || waiting.length; | |
| 63 | const pulls = waiting.length; | |
| 64 | const beat = lastBeat(db); | |
| 65 | const tick = beat === null ? "never" : agoWords(now.getTime() - Date.parse(beat.at)); | |
| 66 | const how = `${commits} ${commits === 1 ? "commit" : "commits"} and ${pulls} ${pulls === 1 ? "pull" : "pulls"}`; | |
| 67 | const forHow = agoWords(wait).replace(" ago", ""); | |
| 68 | const facts = [ | |
| 69 | `production runs ${prod.version} at ${prod.commit.slice(0, 7)}`, | |
| 70 | `main is green at ${head.slice(0, 7)}, ${how} ahead`, | |
| 71 | `ahead since ${first.at}`, | |
| 72 | // Absolute times: the evidence is commented again only when it changes, not as the clock moves. | |
| 73 | `the release tick was last heard from ${beat === null ? "never" : `${beat.at} (${beat.outcome}: ${beat.reason})`}`, | |
| 74 | ]; | |
| 75 | return { | |
| 76 | fired: true, | |
| 77 | since: first.at, | |
| 78 | says: `Main is green and ${how} ahead of production (${prod.version} at ${prod.commit.slice(0, 7)}) for ${forHow}; the release tick was last heard from ${tick}.`, | |
| 79 | facts, | |
| 80 | }; | |
| 81 | } |
src/flow/alarms.ts +4 −1
| @@ -16,6 +16,7 @@ import { alarmBackup } from "./alarm_backup.ts"; | ||
| 16 | 16 | import { alarmFromApp } from "./alarm_from_app.ts"; |
| 17 | 17 | import { alarmPaidOrder } from "./alarm_paid_order.ts"; |
| 18 | 18 | import { alarmIdleCrew } from "./alarm_idle_crew.ts"; |
| 19 | import { mainAheadAlarm } from "./alarm_main_ahead.ts"; | |
| 19 | 20 | import { noReleaseAlarm } from "./alarm_no_release.ts"; |
| 20 | 21 | import { redMainAlarm } from "./alarm_red_main.ts"; |
| 21 | 22 | import { alarmRepeat } from "./alarm_repeat.ts"; |
| @@ -23,7 +24,7 @@ import { alarmSilent } from "./alarm_silent.ts"; | ||
| 23 | 24 | import { alarmStuck } from "./alarm_stuck.ts"; |
| 24 | 25 | |
| 25 | 26 | export interface FiredAlarm { |
| 26 | readonly key: "landing_stopped" | "red_main" | "stuck" | "idle_crew" | "no_release" | "bug_clock" | "silent" | "repeat" | "from_app" | "unreachable" | "backup" | "paid_order"; | |
| 27 | readonly key: "landing_stopped" | "red_main" | "stuck" | "idle_crew" | "no_release" | "main_ahead" | "bug_clock" | "silent" | "repeat" | "from_app" | "unreachable" | "backup" | "paid_order"; | |
| 27 | 28 | readonly says: string; |
| 28 | 29 | readonly since: string; |
| 29 | 30 | /** A same-origin path to the item the alarm names. */ |
| @@ -70,6 +71,8 @@ export function firedAlarms( | ||
| 70 | 71 | } |
| 71 | 72 | const release = noReleaseAlarm(db, now); |
| 72 | 73 | if (release.fired) out.push({ key: "no_release", says: release.says, since: release.since!, href: "/releases" }); |
| 74 | const ahead = mainAheadAlarm(db, now); | |
| 75 | if (ahead.fired) out.push({ key: "main_ahead", says: ahead.says, since: ahead.since!, href: "/releases" }); | |
| 73 | 76 | const bug = bugClockAlarm(db, now, opts.publicOnly ? { publicOnly: true } : {}); |
| 74 | 77 | if (bug.fired) out.push({ key: "bug_clock", says: bug.says, since: bug.since!, href: bug.href }); |
| 75 | 78 | return out; |
src/http/mcp/tools/release_keeper.ts +1 −1
| @@ -4,7 +4,7 @@ import { bad, good, type Tool } from "../shared.ts"; | ||
| 4 | 4 | |
| 5 | 5 | export const tool: Tool = { |
| 6 | 6 | name: "release_keeper", |
| 7 | doc: "`{}`: what the release keeper (#7557) did: its releases newest first (version, commit (short sha), stage — rolling, verifying, verified or rolled_back —, the known-good version it would roll back to, roll probes and non-200s, probes and pages under load, worst ms, seconds dark, reason, landedToLiveSeconds — from the merge of its pull to the new version answering, null until it has (#8042)) and its holds (kind failed or owner, version, reason, probe numbers, the pull that said `release hold N`, lifted); `blocked` says what stops the next cut; for whoever may read /releases", | |
| 7 | doc: "`{}`: what the release keeper (#7557) did: its releases newest first (version, commit (short sha), stage — rolling, verifying, verified or rolled_back —, the known-good version it would roll back to, roll probes and non-200s, probes and pages under load, worst ms, seconds dark, reason, landedToLiveSeconds — from the merge of its pull to the new version answering, null until it has (#8042)) and its holds (kind failed or owner, version, reason, probe numbers, the pull that said `release hold N`, lifted); `blocked` says what stops the next cut; `heartbeat` is the release tick's last report (at, outcome cut/skipped/failed, reason, silent when over an hour old, #11507); for whoever may read /releases", | |
| 8 | 8 | description: "The release keeper's releases, holds and what blocks the next cut.", |
| 9 | 9 | inputSchema: { type: "object", properties: {} }, |
| 10 | 10 | writes: false, |
src/keeper/beat.ts added +57
| @@ -0,0 +1,57 @@ | ||
| 1 | /** | |
| 2 | * The release tick's heartbeat (#11507): each time the tick runs it reports | |
| 3 | * what it did — cut, skipped and why, or failed and why — and the forge keeps | |
| 4 | * the last. The tick runs outside the forge's own judgment, so when it stops | |
| 5 | * this is the only trace; `release_keeper` and /flow show it, and a beat older | |
| 6 | * than {@link SILENT_MS} is said plainly. Plain rows in, plain rows out. | |
| 7 | */ | |
| 8 | ||
| 9 | import type { Database } from "bun:sqlite"; | |
| 10 | ||
| 11 | export type Outcome = "cut" | "skipped" | "failed"; | |
| 12 | export const OUTCOMES: readonly Outcome[] = ["cut", "skipped", "failed"]; | |
OUTCOMES is exported and unused: remove it. |
||
| 13 | ||
| 14 | /** No heartbeat for this long is itself said. */ | |
| 15 | export const SILENT_MS = 60 * 60_000; | |
| 16 | const REASON_MAX = 300; | |
| 17 | ||
| 18 | export interface Beat { | |
| 19 | readonly at: string; | |
| 20 | readonly outcome: Outcome; | |
| 21 | readonly reason: string; | |
| 22 | } | |
| 23 | ||
| 24 | export function recordBeat(db: Database, outcome: Outcome, reason: string, at: Date = new Date()): Beat { | |
| 25 | const beat: Beat = { at: at.toISOString(), outcome, reason: reason.replace(/\s+/g, " ").trim().slice(0, REASON_MAX) }; | |
| 26 | db.query( | |
| 27 | `INSERT INTO keeper_beat (id, at, outcome, reason) VALUES (1, ?1, ?2, ?3) | |
| 28 | ON CONFLICT (id) DO UPDATE SET at = excluded.at, outcome = excluded.outcome, reason = excluded.reason`, | |
| 29 | ).run(beat.at, beat.outcome, beat.reason); | |
| 30 | return beat; | |
| 31 | } | |
| 32 | ||
| 33 | export function lastBeat(db: Database): Beat | null { | |
| 34 | return db.query<Beat, []>("SELECT at, outcome, reason FROM keeper_beat WHERE id = 1").get() ?? null; | |
| 35 | } | |
| 36 | ||
| 37 | /** What a tick's line meant: a cut, a failure, or a skip with its reason. */ | |
| 38 | export function outcomeOf(line: string): Outcome { | |
| 39 | if (line.startsWith("cut ")) return "cut"; | |
| 40 | if (/refused|failed|unreadable/.test(line)) return "failed"; | |
| 41 | return "skipped"; | |
| 42 | } | |
| 43 | ||
| 44 | /** "never", "4 min ago", "2 h 5 min ago". */ | |
| 45 | export function agoWords(ms: number): string { | |
| 46 | const min = Math.max(0, Math.floor(ms / 60_000)); | |
| 47 | if (min < 60) return `${min} min ago`; | |
| 48 | return `${Math.floor(min / 60)} h ${min % 60} min ago`; | |
| 49 | } | |
| 50 | ||
| 51 | /** The heartbeat as one sentence, saying plainly when there is none or it is old. */ | |
| 52 | export function beatLine(beat: Beat | null, now: Date): string { | |
| 53 | if (beat === null) return "The release tick has never reported a heartbeat."; | |
| 54 | const age = now.getTime() - Date.parse(beat.at); | |
| 55 | const said = `The release tick last reported ${agoWords(age)} (${beat.outcome}): ${beat.reason}`; | |
| 56 | return age > SILENT_MS ? `No heartbeat from the release tick for ${agoWords(age).replace(" ago", "")}. ${said}` : said; | |
| 57 | } |
src/keeper/landed.ts +15 −1
| @@ -7,6 +7,7 @@ | ||
| 7 | 7 | */ |
| 8 | 8 | |
| 9 | 9 | import type { Database } from "bun:sqlite"; |
| 10 | import { beatLine, lastBeat, SILENT_MS, type Beat } from "./beat.ts"; | |
| 10 | 11 | import { blocking, listHolds, standingHolds, type Hold } from "./hold.ts"; |
| 11 | 12 | import { listKeeperReleases, type KeeperRelease } from "./record.ts"; |
| 12 | 13 | |
| @@ -55,11 +56,24 @@ export function withLandedToLive(db: Database, releases: readonly KeeperRelease[ | ||
| 55 | 56 | return releases.map((r) => ({ ...r, commit: r.sha.slice(0, 7), landedToLiveSeconds: landedToLive(db, r) ?? null })); |
| 56 | 57 | } |
| 57 | 58 | |
| 59 | /** The tick's last heartbeat with its sentence and whether it has gone quiet (#11507); null before the first. */ | |
| 60 | export type Heartbeat = Beat & { readonly silent: boolean; readonly says: string }; | |
| 61 | ||
| 62 | export function heartbeatOf(db: Database, now: Date = new Date()): Heartbeat | null { | |
| 63 | const beat = lastBeat(db); | |
| 64 | if (beat === null) return null; | |
| 65 | return { ...beat, silent: now.getTime() - Date.parse(beat.at) > SILENT_MS, says: beatLine(beat, now) }; | |
| 66 | } | |
| 67 | ||
| 58 | 68 | /** What the keeper did and what stops the next cut: one answer for MCP `release_keeper` and `GET /api/v1/keeper`. */ |
| 59 | export function keeperAnswer(db: Database): { blocked: string | null; releases: LandedRelease[]; holds: Hold[] } { | |
| 69 | export function keeperAnswer( | |
| 70 | db: Database, | |
| 71 | now: Date = new Date(), | |
| 72 | ): { blocked: string | null; releases: LandedRelease[]; holds: Hold[]; heartbeat: Heartbeat | null } { | |
| 60 | 73 | return { |
| 61 | 74 | blocked: blocking(standingHolds(db)) ?? null, |
| 62 | 75 | releases: withLandedToLive(db, listKeeperReleases(db)), |
| 63 | 76 | holds: listHolds(db), |
| 77 | heartbeat: heartbeatOf(db, now), | |
| 64 | 78 | }; |
| 65 | 79 | } |
src/main.ts +6 −1
| @@ -98,6 +98,7 @@ import { CHECK_EVERY_MS, setBehind, watchBehind } from "./release/behind.ts"; | ||
| 98 | 98 | import { readLandings } from "./release/landings.ts"; |
| 99 | 99 | import { ownTagsReader } from "./release/own_tags.ts"; |
| 100 | 100 | import { rollProbe, tick as keeperTick } from "./keeper/keeper.ts"; |
| 101 | import { outcomeOf, recordBeat } from "./keeper/beat.ts"; | |
| 101 | 102 | import { keeperEnv, keeperPorts } from "./keeper/wire.ts"; |
| 102 | 103 | import { snapshotPlace } from "./actions/health.ts"; |
| 103 | 104 | import { capacityDefault, egressEnvIgnored } from "./core/capacity.ts"; |
| @@ -826,10 +827,14 @@ if (keeperOn.on) { | ||
| 826 | 827 | const step = () => |
| 827 | 828 | void keeperTick(ports) |
| 828 | 829 | .then((line) => { |
| 830 | recordBeat(app.db, outcomeOf(line), line); | |
| 829 | 831 | if (line !== said) app.log.info("release keeper", { line }); |
| 830 | 832 | said = line; |
| 831 | 833 | }) |
| 832 | .catch((error) => app.log.warn("release keeper step failed", { error: String(error) })); | |
| 834 | .catch((error) => { | |
| 835 | recordBeat(app.db, "failed", `step failed: ${error instanceof Error ? error.message : String(error)}`); | |
| 836 | app.log.warn("release keeper step failed", { error: String(error) }); | |
| 837 | }); | |
| 833 | 838 | during("release-keeper", step); |
| 834 | 839 | setInterval(() => during("release-keeper", step), 60_000); |
| 835 | 840 | setInterval( |
src/release/landings.ts +8
| @@ -134,6 +134,14 @@ export function waitingSince(db: Database): string | undefined { | ||
| 134 | 134 | return onItsWay.at(-1)?.at; |
| 135 | 135 | } |
| 136 | 136 | |
| 137 | /** The merged pulls not yet in the running commit, oldest first, with their merge commits; empty when nothing was read (#11507). */ | |
| 138 | export function waitingRows(db: Database): MergedRow[] { | |
| 139 | if (kept === undefined) return []; | |
| 140 | const rows = mergedRows(db); | |
| 141 | const way = new Set(split(rows, kept).onItsWay.map((l) => `${l.repo}#${l.number}`)); | |
| 142 | return rows.filter((r) => way.has(`${r.repo}#${r.number}`)).reverse(); | |
| 143 | } | |
| 144 | ||
| 137 | 145 | /** How long a miss is believed: a repository can turn public, or merge its first pull, after boot. */ |
| 138 | 146 | const MISS_MS = 60_000; |
| 139 | 147 |
src/system/home_truth.ts +10 −1
| @@ -9,6 +9,7 @@ import type { App } from "../app.ts"; | ||
| 9 | 9 | import { listReposVisibleTo } from "../core/repos.ts"; |
| 10 | 10 | import type { User } from "../core/users.ts"; |
| 11 | 11 | import { forgeCeiling } from "../flow/ceiling.ts"; |
| 12 | import { running } from "../kernel/version.ts"; | |
| 12 | 13 | import { readKpis } from "../flow/kpis.ts"; |
| 13 | 14 | import { waitingOn } from "../web/studio/asks.ts"; |
| 14 | 15 | |
| @@ -24,9 +25,17 @@ export function homeTruth(app: App, user: User, now: Date = new Date()) { | ||
| 24 | 25 | const k = readKpis(app.db, now, { ceilingUsd: forgeCeiling(app.config) }); |
| 25 | 26 | const asks = waitingOn(app.db, user, listReposVisibleTo(app.db, user, { limit: 200, withoutArchived: true })); |
| 26 | 27 | const oldest = asks.reduce<string | null>((o, a) => (o === null || Date.parse(a.since) < Date.parse(o) ? a.since : o), null); |
| 28 | // `k.live` is the newest deploy of main; production is the commit this process runs (#11507). | |
| 29 | const prod = running(); | |
| 30 | const production = prod.commit === null ? null : { version: prod.version, sha: prod.commit }; | |
| 31 | const since = app.db | |
| 32 | .query<{ at: string | null }, [string]>("SELECT live_at AS at FROM keeper_release WHERE version = ?1 ORDER BY id DESC LIMIT 1") | |
| 33 | .get(prod.version)?.at; | |
| 27 | 34 | return { |
| 28 | 35 | landed: k.landed, |
| 29 | live: k.live, | |
| 36 | live: production === null ? k.live : { sha: production.sha, ...(since ?? k.live?.at ? { at: (since ?? k.live?.at)! } : {}) }, | |
| 37 | production, | |
| 38 | main: k.live, | |
| 30 | 39 | builders: { ...k.builders, idle: idleReason(k.builders, k.spend) }, |
| 31 | 40 | spend: k.spend, |
| 32 | 41 | waiting: { count: asks.length, oldestAt: oldest }, |
test/flow-alarm-main-ahead.test.ts added +157
| @@ -0,0 +1,157 @@ | ||
| 1 | /** Main green and ahead of production (#11507): one alarm past 90 min with the facts, none at 89, closes on catch-up; the heartbeat shows. */ | |
| 2 | import { afterAll, beforeAll, describe, expect, test } from "bun:test"; | |
| 3 | import { mkdtempSync, rmSync } from "node:fs"; | |
| 4 | import { tmpdir } from "node:os"; | |
| 5 | import { join } from "node:path"; | |
| 6 | import { createApp, type App } from "../src/app.ts"; | |
| 7 | import { createRepo } from "../src/core/repos.ts"; | |
| 8 | import { createUser } from "../src/core/users.ts"; | |
| 9 | import { hunt } from "../src/crew/sentinel.ts"; | |
| 10 | import { firedAlarms } from "../src/flow/alarms.ts"; | |
| 11 | import { mainAheadAlarm } from "../src/flow/alarm_main_ahead.ts"; | |
| 12 | import { lastBeat, recordBeat } from "../src/keeper/beat.ts"; | |
| 13 | import { keeperAnswer } from "../src/keeper/landed.ts"; | |
| 14 | import { id } from "../src/kernel/id.ts"; | |
| 15 | import { forgetLive, keepLive } from "../src/release/landings.ts"; | |
| 16 | import { alarmLines } from "../src/crew/notify.ts"; | |
| 17 | import { homeTruth } from "../src/system/home_truth.ts"; | |
| 18 | ||
| 19 | const NOW = new Date("2026-11-11T12:00:00.000Z"); | |
| 20 | const ago = (m: number) => new Date(NOW.getTime() - m * 60_000).toISOString(); | |
| 21 | const PROD = "abcdef1234567890abcdef1234567890abcdef12"; | |
| 22 | const HEAD = "1111111111111111111111111111111111111111"; | |
| 23 | ||
| 24 | let root: string; | |
| 25 | let app: App; | |
| 26 | let repoId: string; | |
| 27 | let branch: string; | |
| 28 | let userId: string; | |
| 29 | let n = 0; | |
| 30 | const saved = { sentinel: process.env["FORGE_SENTINEL_REPO"], commit: process.env["FORGE_COMMIT"], version: process.env["FORGE_VERSION"] }; | |
| 31 | ||
| 32 | beforeAll(async () => { | |
| 33 | process.env["FORGE_SENTINEL_REPO"] = "trevato/forge"; | |
| 34 | process.env["FORGE_COMMIT"] = PROD; | |
| 35 | process.env["FORGE_VERSION"] = "0.7.535"; | |
| 36 | root = mkdtempSync(join(tmpdir(), "forge-main-ahead-")); | |
| 37 | app = createApp({ dataDir: root, port: 0 }); | |
| 38 | const u = await createUser(app.db, { username: "trevato", email: "[email protected]", password: "a-good-passphrase", origin: "seed", trusted: true, adminIfFirst: true }); | |
| 39 | if (!u.ok) throw new Error(u.error); | |
| 40 | userId = u.value.id; | |
| 41 | const repo = await createRepo(app.db, app.reposRoot, { ownerId: u.value.id, name: "forge", visibility: "public", description: "f" }); | |
| 42 | if (!repo.ok) throw new Error(repo.error); | |
| 43 | repoId = repo.value.id; | |
| 44 | branch = repo.value.defaultBranch; | |
| 45 | }); | |
| 46 | afterAll(() => { | |
| 47 | app.close(); | |
| 48 | rmSync(root, { recursive: true, force: true }); | |
| 49 | for (const [k, v] of [["FORGE_SENTINEL_REPO", saved.sentinel], ["FORGE_COMMIT", saved.commit], ["FORGE_VERSION", saved.version]] as const) | |
| 50 | if (v === undefined) delete process.env[k]; | |
| 51 | else process.env[k] = v; | |
| 52 | forgetLive(); | |
| 53 | }); | |
| 54 | ||
| 55 | function check(state: "ok" | "failed", oid: string): void { | |
| 56 | app.db | |
| 57 | .query(`INSERT INTO run (id, repo_id, kind, env, state, summary, check_detail, commit_oid, created_at, finished_at) VALUES (?1, ?2, 'check', ?3, ?4, '', '{}', ?5, ?6, ?6)`) | |
| 58 | .run(`${String(++n).padStart(4, "0")}${id()}`, repoId, branch, state, oid, ago(1)); | |
| 59 | } | |
| 60 | function merge(minAgo: number, oid: string): void { | |
| 61 | const issueId = id(); | |
| 62 | n++; | |
| 63 | app.db.query(`INSERT INTO issue (id, repo_id, number, kind, title, body, author_id, state, created_at) VALUES (?1, ?2, ?3, 'pull', 'P', '', ?4, 'closed', ?5)`).run(issueId, repoId, n, userId, ago(minAgo)); | |
| 64 | app.db.query(`INSERT INTO pull (issue_id, base_branch, head_branch, base_oid, head_oid, head_repo_id, merged_at, merged_oid) VALUES (?1, ?2, ?3, '', '', ?4, ?5, ?6)`).run(issueId, branch, `b/${n}`, repoId, ago(minAgo), oid); | |
| 65 | } | |
| 66 | const reset = () => { | |
| 67 | app.db.query(`DELETE FROM run`).run(); | |
| 68 | app.db.query(`DELETE FROM pull`).run(); | |
| 69 | keepLive("trevato/forge", [], NOW.getTime() - 600 * 60_000); | |
| 70 | }; | |
| 71 | ||
| 72 | describe("main ahead alarm", () => { | |
| 73 | test("none at 89 minutes, one at 91 with the facts", () => { | |
| 74 | reset(); | |
| 75 | check("ok", HEAD); | |
| 76 | merge(89, "2".repeat(40)); | |
| 77 | expect(mainAheadAlarm(app.db, NOW).fired).toBe(false); | |
| 78 | expect(firedAlarms(app.db, NOW, { dataDir: null }).filter((a) => a.key === "main_ahead")).toHaveLength(0); | |
| 79 | reset(); | |
| 80 | check("ok", HEAD); | |
| 81 | merge(91, "2".repeat(40)); | |
| 82 | merge(30, "3".repeat(40)); | |
| 83 | recordBeat(app.db, "skipped", "no cut: a hold stands", new Date(NOW.getTime() - 61 * 60_000)); | |
| 84 | const fired = firedAlarms(app.db, NOW, { dataDir: null }).filter((a) => a.key === "main_ahead"); | |
| 85 | expect(fired).toHaveLength(1); | |
| 86 | const says = fired[0]!.says; | |
| 87 | expect(says).toContain("0.7.535"); | |
| 88 | expect(says).toContain("abcdef1"); | |
| 89 | expect(says).toContain("2 commits and 2 pulls"); | |
| 90 | expect(says).toContain("1 h 31 min"); | |
| 91 | expect(says).toContain("1 h 1 min ago"); | |
| 92 | expect(fired[0]!.since).toBe(ago(91)); | |
| 93 | }); | |
| 94 | ||
| 95 | test("a red head, or production on the head, does not fire", () => { | |
| 96 | reset(); | |
| 97 | merge(200, "2".repeat(40)); | |
| 98 | check("failed", HEAD); | |
| 99 | expect(mainAheadAlarm(app.db, NOW).fired).toBe(false); | |
| 100 | check("ok", PROD); | |
| 101 | expect(mainAheadAlarm(app.db, NOW).fired).toBe(false); | |
| 102 | }); | |
| 103 | ||
| 104 | test("the limit is a setting", () => { | |
| 105 | reset(); | |
| 106 | check("ok", HEAD); | |
| 107 | merge(50, "2".repeat(40)); | |
| 108 | expect(mainAheadAlarm(app.db, NOW).fired).toBe(false); | |
| 109 | app.db.query(`INSERT INTO forge_setting (key, value, updated_by, updated_at) VALUES ('release.ahead_minutes', '45', 'test', 'now') ON CONFLICT (key) DO UPDATE SET value = '45'`).run(); | |
| 110 | expect(mainAheadAlarm(app.db, NOW).fired).toBe(true); | |
| 111 | app.db.query(`DELETE FROM forge_setting WHERE key = 'release.ahead_minutes'`).run(); | |
| 112 | }); | |
| 113 | ||
| 114 | test("it reaches the owner's ask and one Sentinel issue, which closes when production catches up", () => { | |
| 115 | reset(); | |
| 116 | check("ok", HEAD); | |
| 117 | merge(120, "2".repeat(40)); | |
| 118 | const owner = app.db.query<{ id: string }, []>("SELECT id FROM user LIMIT 1").get()!; | |
| 119 | const lines = alarmLines(app, { ...(app.db.query("SELECT * FROM user LIMIT 1").get() as any), id: owner.id, isAdmin: true, kind: "user" }, NOW.getTime()); | |
| 120 | expect(lines.some((l) => l.id.startsWith("alarm:main_ahead@"))).toBe(true); | |
| 121 | hunt(app, "trevato/forge", NOW.getTime()); | |
| 122 | hunt(app, "trevato/forge", NOW.getTime() + 60_000); | |
| 123 | const open = () => app.db.query<{ title: string }, []>(`SELECT title FROM issue WHERE state = 'open' AND title LIKE 'Sentinel: Main is green and ahead%'`).all(); | |
| 124 | expect(open()).toHaveLength(1); | |
| 125 | // Production catches up: it runs the head and the pull is in the running commit. | |
| 126 | keepLive("trevato/forge", ["2".repeat(40)], NOW.getTime()); | |
| 127 | hunt(app, "trevato/forge", NOW.getTime() + 120_000); | |
| 128 | expect(open()).toHaveLength(0); | |
| 129 | }); | |
| 130 | }); | |
| 131 | ||
| 132 | describe("heartbeat", () => { | |
| 133 | test("release_keeper shows the last heartbeat and its reason, and says when it is quiet", () => { | |
| 134 | app.db.query(`DELETE FROM keeper_beat`).run(); | |
| 135 | expect(keeperAnswer(app.db, NOW).heartbeat).toBeNull(); | |
| 136 | recordBeat(app.db, "skipped", "not cut: a hold stands", new Date(NOW.getTime() - 5 * 60_000)); | |
| 137 | const h = keeperAnswer(app.db, NOW).heartbeat!; | |
| 138 | expect(h).toMatchObject({ outcome: "skipped", reason: "not cut: a hold stands", silent: false }); | |
| 139 | recordBeat(app.db, "failed", "tag refused", new Date(NOW.getTime() - 61 * 60_000)); | |
| 140 | const quiet = keeperAnswer(app.db, NOW).heartbeat!; | |
| 141 | expect(quiet.silent).toBe(true); | |
| 142 | expect(quiet.says).toContain("No heartbeat from the release tick for 1 h 1 min"); | |
| 143 | expect(lastBeat(app.db)!.reason).toBe("tag refused"); | |
| 144 | }); | |
| 145 | }); | |
| 146 | ||
| 147 | describe("home telemetry", () => { | |
| 148 | test("production's commit is named apart from main's", () => { | |
| 149 | reset(); | |
| 150 | app.db.query(`INSERT INTO run (id, repo_id, kind, env, state, commit_oid, created_at, serving_at) VALUES (?1, ?2, 'deploy', 'production', 'ok', ?3, ?4, ?4)`).run(id(), repoId, HEAD, ago(5)); | |
| 151 | const user = app.db.query("SELECT * FROM user LIMIT 1").get() as any; | |
| 152 | const t = homeTruth(app, { ...user, isAdmin: true, kind: "user" } as any, NOW); | |
| 153 | expect(t.production).toEqual({ version: "0.7.535", sha: PROD }); | |
| 154 | expect(t.main?.sha).toBe(HEAD); | |
| 155 | expect(t.live?.sha).toBe(PROD); | |
| 156 | }); | |
| 157 | }); |
waitingRows runs before the cheap head-versus-production check settles. Compute it only once greenHead differs from production; this runs on every /flow and home request.