From 7a07f93f50d607584bb25f286efb4b634e1594db Mon Sep 17 00:00:00 2001 From: JSONbored <49853598+JSONbored@users.noreply.github.com> Date: Mon, 13 Jul 2026 01:34:03 -0700 Subject: [PATCH] feat(miner): add portfolio-queue Prometheus metrics + stuck/backlog alerts Neither #4827 (lease/timeout/reclaim CLI logic) nor #4840 (alerting guidance docs) actually produces a scrapeable metric for claimed-but-not- completed portfolio-queue items -- this issue's own stated dependency was on the metric existing, but no portfolio-queue metrics renderer existed anywhere in the codebase yet. Adds one, mirroring event-ledger-cli.js's renderEventLedgerMetrics / the engine's renderMinerPredictionMetrics conventions (HELP/TYPE, deterministic sorted series, well-formed on an empty queue): - gittensory_miner_portfolio_queue_items{status} -- current count per status (queued/in_progress/done). - gittensory_miner_portfolio_queue_oldest_in_progress_lease_age_seconds -- age of the oldest still-in-flight claim lease, 0 when nothing is in-flight. The concrete "is anything stuck" signal. Exposed via a new `gittensory-miner queue metrics` subcommand (mirrors `gittensory-miner metrics` / `gittensory-miner ledger metrics`'s existing pattern -- local + offline, no network). Adds two Prometheus alert rules in the same dormant-until-a-scrape-target- exists posture as the existing gittensory-miner-prediction group (#5188): absent gittensory_miner_portfolio_queue_* series yield no result, so they load cleanly via selfhost:validate-observability and never false-fire on an install with no miner scrape configured. - GittensoryMinerPortfolioQueueItemStuck: oldest in-flight lease age past 1h (a generous multiple of the 30m self-heal default), sustained 15m -- the self-heal isn't running or is itself stuck. - GittensoryMinerPortfolioQueueBacklogHigh: queued backlog past 200, sustained 30m -- claiming is falling behind discovery. A dedicated fixture test (alerts-miner-portfolio-queue-backlog.test.ts, mirroring alerts-miner-prediction-calibration-drift.test.ts) pins each rule's formula/threshold/metric-names to the real renderer's exported constants, so a future rename can't silently drift the alert away from what the renderer actually produces. Closes #5186. --- packages/gittensory-miner/lib/cli.js | 1 + .../lib/portfolio-queue-cli.d.ts | 14 +++ .../lib/portfolio-queue-cli.js | 77 +++++++++++++++ prometheus/rules/alerts.yml | 39 ++++++++ ...erts-miner-portfolio-queue-backlog.test.ts | 99 +++++++++++++++++++ test/unit/miner-portfolio-queue-cli.test.ts | 84 ++++++++++++++++ 6 files changed, 314 insertions(+) create mode 100644 test/unit/alerts-miner-portfolio-queue-backlog.test.ts diff --git a/packages/gittensory-miner/lib/cli.js b/packages/gittensory-miner/lib/cli.js index a66676638b..abb7d4c4b6 100644 --- a/packages/gittensory-miner/lib/cli.js +++ b/packages/gittensory-miner/lib/cli.js @@ -33,6 +33,7 @@ export function printHelp(input) { " gittensory-miner queue next [--global-wip ] [--per-repo-wip ] [--dry-run] [--json]", " Claim the highest-priority queued item, optionally WIP-cap-aware", " gittensory-miner queue claim-batch [--global-wip ] [--per-repo-wip ] [--dry-run] [--json]", + " gittensory-miner queue metrics Print portfolio-queue counters in Prometheus text format", " gittensory-miner queue done [--dry-run] [--json]", " gittensory-miner queue release [--dry-run] [--json] Return a claimed item to the queue", " gittensory-miner queue requeue [--dry-run] [--json] Put a completed item back on the queue", diff --git a/packages/gittensory-miner/lib/portfolio-queue-cli.d.ts b/packages/gittensory-miner/lib/portfolio-queue-cli.d.ts index 798da1ad0e..f2cf0ddb3b 100644 --- a/packages/gittensory-miner/lib/portfolio-queue-cli.d.ts +++ b/packages/gittensory-miner/lib/portfolio-queue-cli.d.ts @@ -77,6 +77,20 @@ export function runQueueClaimBatch( options?: { initPortfolioQueueManager?: (opts: unknown) => PortfolioQueueManager }, ): number; +export const QUEUE_ITEMS: string; +export const QUEUE_OLDEST_IN_PROGRESS_LEASE_AGE_SECONDS: string; + +export function renderPortfolioQueueMetrics( + queueEntries: Array<{ status: string }>, + leaseEntries: Array<{ leasedAt: string | null }>, + nowMs: number, +): string; + +export function runQueueMetrics( + args: string[], + options?: { initPortfolioQueue?: () => PortfolioQueueStore; nowMs?: number }, +): number; + export function runQueueCli( subcommand: string | undefined, args: string[], diff --git a/packages/gittensory-miner/lib/portfolio-queue-cli.js b/packages/gittensory-miner/lib/portfolio-queue-cli.js index 7a8003df60..f7cbedf125 100644 --- a/packages/gittensory-miner/lib/portfolio-queue-cli.js +++ b/packages/gittensory-miner/lib/portfolio-queue-cli.js @@ -497,6 +497,82 @@ export function runQueueClaimBatch(args, options = {}) { } } +const QUEUE_METRICS_USAGE = "Usage: gittensory-miner queue metrics"; + +// Prometheus metric names for the portfolio-queue gauges (#5186). Mirrors the `gittensory_miner_*` naming and +// HELP/TYPE/label conventions of event-ledger-cli.js's renderEventLedgerMetrics / the engine's +// renderMinerPredictionMetrics, rather than importing across the package boundary. +export const QUEUE_ITEMS = "gittensory_miner_portfolio_queue_items"; +export const QUEUE_OLDEST_IN_PROGRESS_LEASE_AGE_SECONDS = "gittensory_miner_portfolio_queue_oldest_in_progress_lease_age_seconds"; + +/** HELP-text escaping — backslash + newline (mirrors miner-prediction-metrics.ts's escapeHelpText). */ +function escapeMetricsHelpText(help) { + return help.replace(/\\/g, "\\\\").replace(/\n/g, "\\n"); +} + +/** + * Render portfolio-queue backlog health as Prometheus text-exposition gauges: current item count per status, and + * the age of the OLDEST still-in-flight lease -- the concrete "is anything stuck" signal a + * `loopover_queue_oldest_maintenance_pending_age_seconds`-style alert rule can threshold on (#5186). Pure and + * side-effect-free: the caller supplies the rows and `nowMs` (no internal clock read, matching + * store-maintenance.js's pruneLedgerByRetention convention) and prints the result. Deterministic (status series + * sorted); always emits HELP/TYPE so an empty queue is still a well-formed exposition document, and the lease-age + * gauge reads 0 (never stuck) rather than being omitted when nothing is in-flight. + * @param {Array<{ status: string }>} queueEntries - every row, any status (e.g. store.listQueue()'s output). + * @param {Array<{ leasedAt: string | null }>} leaseEntries - in-flight rows only (store.listInProgress()'s output). + * @param {number} nowMs + */ +export function renderPortfolioQueueMetrics(queueEntries, leaseEntries, nowMs) { + const countByStatus = new Map(); + for (const entry of queueEntries) { + countByStatus.set(entry.status, (countByStatus.get(entry.status) ?? 0) + 1); + } + + let oldestLeaseAgeSeconds = 0; + for (const lease of leaseEntries) { + const leasedAtMs = Date.parse(lease.leasedAt ?? ""); + if (!Number.isFinite(leasedAtMs)) continue; + const ageSeconds = Math.max(0, (nowMs - leasedAtMs) / 1000); + if (ageSeconds > oldestLeaseAgeSeconds) oldestLeaseAgeSeconds = ageSeconds; + } + + const lines = [ + `# HELP ${QUEUE_ITEMS} ${escapeMetricsHelpText("Current portfolio-queue item count, by status.")}`, + `# TYPE ${QUEUE_ITEMS} gauge`, + ]; + for (const [status, count] of [...countByStatus.entries()].sort((a, b) => a[0].localeCompare(b[0]))) { + lines.push(`${QUEUE_ITEMS}{status="${status}"} ${count}`); + } + + lines.push( + `# HELP ${QUEUE_OLDEST_IN_PROGRESS_LEASE_AGE_SECONDS} ${escapeMetricsHelpText("Age in seconds of the oldest still-in-flight (in_progress) claim lease. 0 when nothing is in-flight.")}`, + ); + lines.push(`# TYPE ${QUEUE_OLDEST_IN_PROGRESS_LEASE_AGE_SECONDS} gauge`); + lines.push(`${QUEUE_OLDEST_IN_PROGRESS_LEASE_AGE_SECONDS} ${oldestLeaseAgeSeconds}`); + + return `${lines.join("\n")}\n`; +} + +export function runQueueMetrics(args, options = {}) { + if (args.length > 0) { + return reportCliFailure(argsWantJson(args), QUEUE_METRICS_USAGE); + } + + try { + return withPortfolioQueue(options, (portfolioQueue) => { + const nowMs = Number.isFinite(options.nowMs) ? options.nowMs : Date.now(); + // renderPortfolioQueueMetrics returns a newline-terminated document; console.log re-adds the terminator, so + // trim it to emit exactly one trailing newline (mirrors metrics-cli.js's runMetrics). + console.log( + renderPortfolioQueueMetrics(portfolioQueue.listQueue(), portfolioQueue.listInProgress(), nowMs).trimEnd(), + ); + return 0; + }); + } catch (error) { + return reportCliFailure(argsWantJson(args), describeCliError(error)); + } +} + export function runQueueCli(subcommand, args, options = {}) { if (subcommand === "list") return runQueueList(args, options); if (subcommand === "next") return runQueueNext(args, options); @@ -504,6 +580,7 @@ export function runQueueCli(subcommand, args, options = {}) { if (subcommand === "release") return runQueueRelease(args, options); if (subcommand === "requeue") return runQueueRequeue(args, options); if (subcommand === "claim-batch") return runQueueClaimBatch(args, options); + if (subcommand === "metrics") return runQueueMetrics(args, options); if (subcommand === "dashboard") return runPortfolioDashboard(args, options); return reportCliFailure(argsWantJson(args), `Unknown queue subcommand: ${subcommand ?? ""}. ${QUEUE_LIST_USAGE}`); } diff --git a/prometheus/rules/alerts.yml b/prometheus/rules/alerts.yml index 8078bf49e6..0a67a5bff1 100644 --- a/prometheus/rules/alerts.yml +++ b/prometheus/rules/alerts.yml @@ -663,3 +663,42 @@ groups: summary: "gittensory miner prediction calibration has drifted" description: "{{ $value | humanizePercentage }} of the miner's recently resolved gate predictions were incorrect over the last 6h (sustained 30m). Predicted-gate accuracy has drifted out of tolerance." runbook: "Compare gittensory_miner_prediction_correct_total vs gittensory_miner_prediction_incorrect_total and review the miner's own calibration report (`gittensory-miner calibration`). Sustained drift usually means the predicted-gate heuristics need recalibration against the repo(s) the miner now targets, or a recent upstream gate-behavior change the predictor hasn't caught up to." + + # ── Miner portfolio-queue backlog health (#5186) ────────────────────────── + # Same DORMANT-until-a-scrape-target-exists posture as gittensory-miner-prediction above: an operator runs + # `gittensory-miner queue metrics` (packages/gittensory-miner/lib/portfolio-queue-cli.js's + # renderPortfolioQueueMetrics) to a file/pushgateway their Prometheus scrapes. Absent + # gittensory_miner_portfolio_queue_* series simply yield no result, so this loads cleanly via + # `selfhost:validate-observability` and never false-fires on an install with no miner scrape configured. + - name: gittensory-miner-portfolio-queue + rules: + - alert: GittensoryMinerPortfolioQueueItemStuck + # The concrete "is a claimed item actually stuck" signal, distinct from #4827 (the lease/timeout/reclaim + # CLI logic itself, which already self-heals a stuck lease past DEFAULT_MAX_LEASE_MS = 30m) and #4840 + # (alerting guidance docs, not a rule definition) -- this is the rule that pages an operator when the + # self-heal ISN'T running (no cron/scheduled `queue claim-batch`/reclaim sweep configured) or is itself + # stuck, so a lease sits well past its own 30m default with nothing automatically reclaiming it. + # 3600s (1h) is a generous multiple of DEFAULT_MAX_LEASE_MS so a healthy install's own reclaim sweep + # always clears this long before the alert would fire; tune down if your reclaim cadence is tighter. + expr: gittensory_miner_portfolio_queue_oldest_in_progress_lease_age_seconds > 3600 + for: 15m + labels: + severity: warning + annotations: + summary: "gittensory miner has a claimed portfolio-queue item stuck in progress" + description: "The oldest in-flight portfolio-queue claim lease is {{ $value | printf \"%.0f\" }}s old (sustained 15m), well past the 30m default reclaim window. A crashed/killed attempt process's lease isn't being automatically reclaimed." + runbook: "Run `gittensory-miner queue list --json` to find the stuck item, and `gittensory-miner queue claim-batch` (or a scheduled reclaim sweep) to trigger the lease-expiry self-heal (portfolio-queue-expiry.js's sweepStuckItems). If it stays stuck after that, release it manually with `gittensory-miner queue release `." + + - alert: GittensoryMinerPortfolioQueueBacklogHigh + # Standing size of the queued (not yet claimed) backlog, the miner counterpart of + # LoopoverQueueBacklogHigh above -- a sustained high queued count means discovery is outpacing + # claiming, mirroring the main product's own "queue > threshold for N minutes" shape. 200 is a + # generous default for a single-host laptop-mode install; tune to your normal steady-state depth. + expr: gittensory_miner_portfolio_queue_items{status="queued"} > 200 + for: 30m + labels: + severity: warning + annotations: + summary: "gittensory miner portfolio-queue backlog above 200" + description: "{{ $value | printf \"%.0f\" }} portfolio-queue items are queued (sustained 30m) -- claiming/attempting is falling behind discovery." + runbook: "Check whether `queue next` / `loop` is running at all (a laptop-mode miner only drains the queue while actively invoked), or whether WIP caps (#4850's --global-wip/--per-repo-wip) are set low enough to bottleneck throughput relative to discovery volume." diff --git a/test/unit/alerts-miner-portfolio-queue-backlog.test.ts b/test/unit/alerts-miner-portfolio-queue-backlog.test.ts new file mode 100644 index 0000000000..d92acf1a53 --- /dev/null +++ b/test/unit/alerts-miner-portfolio-queue-backlog.test.ts @@ -0,0 +1,99 @@ +import { readFileSync } from "node:fs"; +import { parse as parseYaml } from "yaml"; +import { describe, expect, it } from "vitest"; +import { + QUEUE_ITEMS, + QUEUE_OLDEST_IN_PROGRESS_LEASE_AGE_SECONDS, +} from "../../packages/gittensory-miner/lib/portfolio-queue-cli.js"; + +// Fixture for the GittensoryMinerPortfolioQueueItemStuck / GittensoryMinerPortfolioQueueBacklogHigh alerts +// (#5186). This is the config-side equivalent of a `promtool test rules` harness (the repo ships no promtool +// dependency): it pins each rule's formula, threshold, and metric names to the real renderer surface so the +// alerts can't silently drift away from the metrics they consume. Mirrors +// alerts-miner-prediction-calibration-drift.test.ts (#5188) and alerts-job-failure-ratio-formula.test.ts (#3892). +// +// Deliberately keyed off portfolio-queue-cli.js's exported metric-name CONSTANTS (renderPortfolioQueueMetrics) +// rather than hardcoded strings: if that renderer ever renames a gauge, this test fails instead of the alert +// going quietly stale against a metric name that no longer exists. + +interface AlertRule { + alert: string; + expr: string; + for?: string; + labels?: { severity?: string }; + annotations?: { summary?: string; description?: string; runbook?: string }; +} +interface AlertGroup { + name: string; + rules: AlertRule[]; +} +interface AlertsDoc { + groups: AlertGroup[]; +} + +const alertsDoc = parseYaml(readFileSync("prometheus/rules/alerts.yml", "utf8")) as AlertsDoc; + +function findAlert(name: string): AlertRule { + for (const group of alertsDoc.groups) { + const rule = group.rules.find((r) => r.alert === name); + if (rule) return rule; + } + throw new Error(`alert ${name} not found in prometheus/rules/alerts.yml`); +} + +describe("GittensoryMinerPortfolioQueueItemStuck alert (#5186)", () => { + const rule = findAlert("GittensoryMinerPortfolioQueueItemStuck"); + const flat = rule.expr.replace(/\s+/g, " ").trim(); + + it("lives in its own miner-scoped rule group, separate from the loopover server groups", () => { + const group = alertsDoc.groups.find((g) => g.rules.some((r) => r.alert === rule.alert)); + expect(group?.name).toBe("gittensory-miner-portfolio-queue"); + }); + + it("keys off the real renderer's oldest-lease-age gauge, not an invented metric name", () => { + expect(QUEUE_OLDEST_IN_PROGRESS_LEASE_AGE_SECONDS).toBe( + "gittensory_miner_portfolio_queue_oldest_in_progress_lease_age_seconds", + ); + expect(flat).toContain(QUEUE_OLDEST_IN_PROGRESS_LEASE_AGE_SECONDS); + }); + + it("thresholds at a generous multiple of the 30m default reclaim window (1h), sustained 15m", () => { + expect(flat).toBe(`${QUEUE_OLDEST_IN_PROGRESS_LEASE_AGE_SECONDS} > 3600`); + expect(rule.for).toBe("15m"); + }); + + it("never references any loopover_* server metric (a miner rule must not fire on server data)", () => { + expect(flat).not.toMatch(/loopover_/); + }); + + it("has warning severity and human-readable annotations", () => { + expect(rule.labels?.severity).toBe("warning"); + expect(rule.annotations?.summary).toBeTruthy(); + expect(rule.annotations?.description).toBeTruthy(); + expect(rule.annotations?.runbook).toBeTruthy(); + }); +}); + +describe("GittensoryMinerPortfolioQueueBacklogHigh alert (#5186)", () => { + const rule = findAlert("GittensoryMinerPortfolioQueueBacklogHigh"); + const flat = rule.expr.replace(/\s+/g, " ").trim(); + + it("lives in the same miner-scoped portfolio-queue rule group", () => { + const group = alertsDoc.groups.find((g) => g.rules.some((r) => r.alert === rule.alert)); + expect(group?.name).toBe("gittensory-miner-portfolio-queue"); + }); + + it("keys off the real renderer's items gauge, scoped to the queued status label", () => { + expect(QUEUE_ITEMS).toBe("gittensory_miner_portfolio_queue_items"); + expect(flat).toBe(`${QUEUE_ITEMS}{status="queued"} > 200`); + }); + + it("has a 30m sustain window and warning severity", () => { + expect(rule.for).toBe("30m"); + expect(rule.labels?.severity).toBe("warning"); + }); + + it("never references any loopover_* server metric (a miner rule must not fire on server data)", () => { + expect(flat).not.toMatch(/loopover_/); + }); +}); diff --git a/test/unit/miner-portfolio-queue-cli.test.ts b/test/unit/miner-portfolio-queue-cli.test.ts index c1c88fec29..1b5a03d2d7 100644 --- a/test/unit/miner-portfolio-queue-cli.test.ts +++ b/test/unit/miner-portfolio-queue-cli.test.ts @@ -12,10 +12,12 @@ import { parseQueueNextArgs, parseQueueReleaseArgs, parseQueueRequeueArgs, + renderPortfolioQueueMetrics, renderQueueTable, runQueueCli, runQueueDone, runQueueList, + runQueueMetrics, runQueueNext, runQueueRelease, runQueueRequeue, @@ -380,6 +382,88 @@ describe("gittensory-miner portfolio queue CLI (#2292)", () => { expect(error).not.toHaveBeenCalled(); }); + describe("renderPortfolioQueueMetrics() / runQueueMetrics (#5186)", () => { + it("emits per-status counts and the oldest in-flight lease age", () => { + const now = Date.parse("2026-07-13T12:00:00.000Z"); + const output = renderPortfolioQueueMetrics( + [{ status: "queued" }, { status: "queued" }, { status: "in_progress" }, { status: "done" }], + [ + { leasedAt: "2026-07-13T11:50:00.000Z" }, // 600s old -- the oldest, seen first + { leasedAt: "2026-07-13T11:55:00.000Z" }, // 300s old -- younger than the running max, must not replace it + ], + now, + ); + expect(output).toContain('gittensory_miner_portfolio_queue_items{status="queued"} 2'); + expect(output).toContain('gittensory_miner_portfolio_queue_items{status="in_progress"} 1'); + expect(output).toContain('gittensory_miner_portfolio_queue_items{status="done"} 1'); + expect(output).toContain("gittensory_miner_portfolio_queue_oldest_in_progress_lease_age_seconds 600"); + expect(output).toContain("# HELP gittensory_miner_portfolio_queue_items"); + expect(output).toContain("# TYPE gittensory_miner_portfolio_queue_items gauge"); + expect(output.endsWith("\n")).toBe(true); + expect(output.endsWith("\n\n")).toBe(false); + }); + + it("is well-formed (HELP/TYPE always present, lease age 0) for an empty queue", () => { + const output = renderPortfolioQueueMetrics([], [], Date.parse("2026-07-13T12:00:00.000Z")); + expect(output).toContain("# TYPE gittensory_miner_portfolio_queue_items gauge"); + expect(output).toContain("gittensory_miner_portfolio_queue_oldest_in_progress_lease_age_seconds 0"); + expect(output).not.toContain('gittensory_miner_portfolio_queue_items{status='); + }); + + it("ignores a lease row with an unparseable leasedAt rather than corrupting the max", () => { + const output = renderPortfolioQueueMetrics( + [{ status: "in_progress" }], + [{ leasedAt: null }, { leasedAt: "not-a-date" }], + Date.parse("2026-07-13T12:00:00.000Z"), + ); + expect(output).toContain("gittensory_miner_portfolio_queue_oldest_in_progress_lease_age_seconds 0"); + }); + + it("runQueueMetrics prints the rendered document from the real store", () => { + const portfolioQueue = tempQueueStore(); + portfolioQueue.enqueue({ repoFullName: "acme/widgets", identifier: "issue:1", priority: 1 }); + portfolioQueue.dequeueNext(); + + const log = vi.spyOn(console, "log").mockImplementation(() => undefined); + expect( + runQueueMetrics([], { initPortfolioQueue: () => portfolioQueue, nowMs: Date.parse("2026-07-13T12:00:00.000Z") }), + ).toBe(0); + const output = String(log.mock.calls[0]?.[0]); + expect(output).toContain('gittensory_miner_portfolio_queue_items{status="in_progress"} 1'); + expect(output.endsWith("\n")).toBe(false); // console.log adds its own trailing newline + }); + + it("runQueueMetrics defaults nowMs to the real clock when not injected", () => { + const portfolioQueue = tempQueueStore(); + const log = vi.spyOn(console, "log").mockImplementation(() => undefined); + expect(runQueueMetrics([], { initPortfolioQueue: () => portfolioQueue })).toBe(0); + expect(String(log.mock.calls[0]?.[0])).toContain("gittensory_miner_portfolio_queue_oldest_in_progress_lease_age_seconds 0"); + }); + + it("rejects unexpected positional args and surfaces a store failure", () => { + const error = vi.spyOn(console, "error").mockImplementation(() => undefined); + expect(runQueueMetrics(["extra"])).toBe(2); + expect(String(error.mock.calls[0]?.[0])).toContain("Usage: gittensory-miner queue metrics"); + + error.mockClear(); + expect( + runQueueMetrics([], { + initPortfolioQueue: () => { + throw new Error("store_broken"); + }, + }), + ).toBe(2); + expect(error).toHaveBeenCalledWith("store_broken"); + }); + + it("runQueueCli dispatches the metrics subcommand", () => { + const portfolioQueue = tempQueueStore(); + const log = vi.spyOn(console, "log").mockImplementation(() => undefined); + expect(runQueueCli("metrics", [], { initPortfolioQueue: () => portfolioQueue })).toBe(0); + expect(log).toHaveBeenCalled(); + }); + }); + describe("release / requeue escape hatch (#4828)", () => { it("parseQueueReleaseArgs and parseQueueRequeueArgs validate argv with their own usage", () => { expect(parseQueueReleaseArgs(["acme/widgets", "issue:1"])).toEqual({