From f2e0d2af278bcbfa3f3543dffeb2b2c1803c1f91 Mon Sep 17 00:00:00 2001 From: JSONbored <49853598+JSONbored@users.noreply.github.com> Date: Sat, 4 Jul 2026 18:40:54 -0700 Subject: [PATCH] fix(selfhost): gate orb relay registration alerts on failure streak, not one hiccup registerOrbRelayWithMonitor escalated a pull-mode registration failure to warn only, and unconditionally at that -- there was no way to tell a lone transient broker timeout apart from a sustained outage. Add a consecutive-failure streak to OrbRelayRegistrationState alongside the existing lifetime attempts counter, and only alert (error, not warn) once ORB_RELAY_REGISTER_UNHEALTHY_FAILURE_STREAK consecutive failures have occurred, or the pull-mode drain loop hasn't made progress in ORB_RELAY_DRAIN_NO_PROGRESS_WINDOW_MS -- whichever the caller can confirm. A single hiccup while orb_relay_drained keeps firing now stays a warning. Also record a recovered counter alongside the existing recovery log, add Grafana panels + a Prometheus alert for the new streak/no-progress gauges, and regenerate the stale self-host env-var reference the reordered server.ts wiring shifted. --- .../src/lib/selfhost-env-reference.ts | 8 +- grafana/dashboards/gittensory.json | 64 ++++++-- prometheus/rules/alerts.yml | 14 ++ src/orb/broker-client.ts | 19 ++- src/selfhost/metrics.ts | 2 + src/selfhost/monitored-work.ts | 62 ++++++- src/server.ts | 17 +- test/unit/orb-broker-client.test.ts | 45 +++++- test/unit/selfhost-grafana-dashboard.test.ts | 10 ++ test/unit/selfhost-monitored-work.test.ts | 151 ++++++++++++++++-- 10 files changed, 352 insertions(+), 40 deletions(-) diff --git a/apps/gittensory-ui/src/lib/selfhost-env-reference.ts b/apps/gittensory-ui/src/lib/selfhost-env-reference.ts index 219904da42..e586d65ab0 100644 --- a/apps/gittensory-ui/src/lib/selfhost-env-reference.ts +++ b/apps/gittensory-ui/src/lib/selfhost-env-reference.ts @@ -247,7 +247,7 @@ export const SELFHOST_ENV_REFERENCE_ROWS: SelfHostEnvReferenceRow[] = [ }, { name: "ORB_BROKER_URL", - firstReference: "src/server.ts:968", + firstReference: "src/server.ts:974", }, { name: "ORB_COLLECTOR_TOKEN", @@ -263,7 +263,7 @@ export const SELFHOST_ENV_REFERENCE_ROWS: SelfHostEnvReferenceRow[] = [ }, { name: "ORB_RELAY_MODE", - firstReference: "src/server.ts:970", + firstReference: "src/server.ts:962", }, { name: "OTEL_EXPORTER_OTLP_ENDPOINT", @@ -450,11 +450,11 @@ export const SELFHOST_ENV_REFERENCE_MARKDOWN = [ "| `ORB_AIR_GAP` | `src/selfhost/orb-collector.ts:161` |", "| `ORB_ANONYMIZE` | `src/selfhost/orb-collector.ts:174` |", "| `ORB_APP_ID` | `src/selfhost/orb-collector.ts:59` |", - "| `ORB_BROKER_URL` | `src/server.ts:968` |", + "| `ORB_BROKER_URL` | `src/server.ts:974` |", "| `ORB_COLLECTOR_TOKEN` | `src/selfhost/orb-collector.ts:205` |", "| `ORB_COLLECTOR_URL` | `src/selfhost/orb-collector.ts:172` |", "| `ORB_ENROLLMENT_SECRET` | `src/selfhost/orb-collector.ts:165` |", - "| `ORB_RELAY_MODE` | `src/server.ts:970` |", + "| `ORB_RELAY_MODE` | `src/server.ts:962` |", "| `OTEL_EXPORTER_OTLP_ENDPOINT` | `src/selfhost/otel.ts:47` |", "| `OTEL_EXPORTER_OTLP_TRACES_ENDPOINT` | `src/selfhost/otel.ts:45` |", "| `OTEL_SERVICE_ENVIRONMENT` | `src/selfhost/otel.ts:60` |", diff --git a/grafana/dashboards/gittensory.json b/grafana/dashboards/gittensory.json index e1a9dcba93..19a2c27ecb 100644 --- a/grafana/dashboards/gittensory.json +++ b/grafana/dashboards/gittensory.json @@ -2637,9 +2637,47 @@ } ] }, + { + "datasource": { "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, + "fieldConfig": { + "defaults": { + "color": { "mode": "palette-classic" }, + "custom": { "lineWidth": 2, "fillOpacity": 10 }, + "unit": "short" + }, + "overrides": [ + { + "matcher": { "id": "byName", "options": "seconds since last pull-mode drain" }, + "properties": [{ "id": "unit", "value": "s" }] + } + ] + }, + "gridPos": { "h": 8, "w": 12, "x": 0, "y": 170 }, + "id": 158, + "options": { + "legend": { "calcs": ["lastNotNull"], "displayMode": "table", "placement": "bottom" }, + "tooltip": { "mode": "multi", "sort": "desc" } + }, + "title": "Orb Relay Registration: Streak vs Drain Progress (one hiccup vs actually stuck)", + "type": "timeseries", + "targets": [ + { + "datasource": { "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, + "expr": "gittensory_orb_relay_register_consecutive_failures or vector(0)", + "legendFormat": "consecutive registration failures", + "refId": "A" + }, + { + "datasource": { "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, + "expr": "gittensory_orb_relay_drain_seconds_since_last or vector(0)", + "legendFormat": "seconds since last pull-mode drain", + "refId": "B" + } + ] + }, { "collapsed": false, - "gridPos": { "h": 1, "w": 24, "x": 0, "y": 171 }, + "gridPos": { "h": 1, "w": 24, "x": 0, "y": 179 }, "id": 145, "panels": [], "title": "Foreground Liveness (#selfhost-queue-liveness)", @@ -2648,7 +2686,7 @@ { "datasource": { "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, "fieldConfig": { "defaults": { "color": { "mode": "thresholds" }, "unit": "short" } }, - "gridPos": { "h": 4, "w": 4, "x": 0, "y": 172 }, + "gridPos": { "h": 4, "w": 4, "x": 0, "y": 180 }, "id": 146, "options": { "colorMode": "background", @@ -2671,7 +2709,7 @@ { "datasource": { "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, "fieldConfig": { "defaults": { "color": { "mode": "thresholds" }, "unit": "short" } }, - "gridPos": { "h": 4, "w": 4, "x": 4, "y": 172 }, + "gridPos": { "h": 4, "w": 4, "x": 4, "y": 180 }, "id": 147, "options": { "colorMode": "background", @@ -2694,7 +2732,7 @@ { "datasource": { "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, "fieldConfig": { "defaults": { "color": { "mode": "thresholds" }, "unit": "short" } }, - "gridPos": { "h": 4, "w": 4, "x": 8, "y": 172 }, + "gridPos": { "h": 4, "w": 4, "x": 8, "y": 180 }, "id": 148, "options": { "colorMode": "background", @@ -2730,7 +2768,7 @@ "unit": "s" } }, - "gridPos": { "h": 4, "w": 4, "x": 12, "y": 172 }, + "gridPos": { "h": 4, "w": 4, "x": 12, "y": 180 }, "id": 149, "options": { "colorMode": "background", @@ -2753,7 +2791,7 @@ { "datasource": { "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, "fieldConfig": { "defaults": { "color": { "mode": "thresholds" }, "unit": "short" } }, - "gridPos": { "h": 4, "w": 4, "x": 16, "y": 172 }, + "gridPos": { "h": 4, "w": 4, "x": 16, "y": 180 }, "id": 150, "options": { "colorMode": "background", @@ -2778,7 +2816,7 @@ "fieldConfig": { "defaults": { "color": { "mode": "palette-classic" }, "custom": { "lineWidth": 2, "fillOpacity": 10 }, "unit": "short" } }, - "gridPos": { "h": 6, "w": 12, "x": 0, "y": 176 }, + "gridPos": { "h": 6, "w": 12, "x": 0, "y": 184 }, "id": 151, "options": { "legend": { "calcs": ["lastNotNull"], "displayMode": "table", "placement": "bottom" }, @@ -2797,7 +2835,7 @@ }, { "collapsed": false, - "gridPos": { "h": 1, "w": 24, "x": 0, "y": 182 }, + "gridPos": { "h": 1, "w": 24, "x": 0, "y": 190 }, "id": 152, "title": "Backlog-vs-Fresh-Intake Lane Fairness (#selfhost-lane-observability)", "type": "row" @@ -2818,7 +2856,7 @@ "unit": "short" } }, - "gridPos": { "h": 4, "w": 4, "x": 0, "y": 183 }, + "gridPos": { "h": 4, "w": 4, "x": 0, "y": 191 }, "id": 153, "options": { "colorMode": "background", @@ -2854,7 +2892,7 @@ "unit": "short" } }, - "gridPos": { "h": 4, "w": 4, "x": 4, "y": 183 }, + "gridPos": { "h": 4, "w": 4, "x": 4, "y": 191 }, "id": 154, "options": { "colorMode": "background", @@ -2879,7 +2917,7 @@ "fieldConfig": { "defaults": { "color": { "mode": "palette-classic" }, "custom": { "lineWidth": 2, "fillOpacity": 10 }, "unit": "short" } }, - "gridPos": { "h": 6, "w": 16, "x": 8, "y": 183 }, + "gridPos": { "h": 6, "w": 16, "x": 8, "y": 191 }, "id": 155, "options": { "legend": { "calcs": ["lastNotNull"], "displayMode": "table", "placement": "bottom" }, @@ -2902,7 +2940,7 @@ "fieldConfig": { "defaults": { "color": { "mode": "palette-classic" }, "custom": { "lineWidth": 2, "fillOpacity": 10 }, "unit": "ops" } }, - "gridPos": { "h": 6, "w": 12, "x": 0, "y": 189 }, + "gridPos": { "h": 6, "w": 12, "x": 0, "y": 197 }, "id": 156, "options": { "legend": { "calcs": ["lastNotNull"], "displayMode": "table", "placement": "bottom" }, @@ -2922,7 +2960,7 @@ { "datasource": { "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, "fieldConfig": { "defaults": { "unit": "short" } }, - "gridPos": { "h": 6, "w": 12, "x": 12, "y": 189 }, + "gridPos": { "h": 6, "w": 12, "x": 12, "y": 197 }, "id": 157, "options": { "showHeader": true, diff --git a/prometheus/rules/alerts.yml b/prometheus/rules/alerts.yml index c2d3ae06ea..24ccfa43d3 100644 --- a/prometheus/rules/alerts.yml +++ b/prometheus/rules/alerts.yml @@ -389,6 +389,20 @@ groups: description: "Webhook enqueue failures are occurring for over 2m. Labels event/action show which GitHub event class is failing." runbook: "Check WEBHOOKS queue availability and the durable queue backend. If this coincides with Orb relay drains, inspect gittensory_orb_webhook_total{result=\"enqueue_failed\"}." + - alert: GittensoryOrbRelayRegistrationStuck + # #selfhost-runtime-drift follow-up: mirrors isOrbRelayRegistrationAlerting's own gate (3 consecutive + # registration failures, OR the pull-mode drain loop gone quiet for 30m) so Prometheus escalates on + # EXACTLY the same evidence the app itself uses to decide "actually stuck" vs "one hiccup, still + # draining fine". A single transient registration timeout will not trip this on its own. + expr: gittensory_orb_relay_register_consecutive_failures >= 3 or gittensory_orb_relay_drain_seconds_since_last > 1800 + for: 5m + labels: + severity: warning + annotations: + summary: "gittensory orb relay registration looks actually stuck, not just a transient hiccup" + description: "Either the consecutive registration-failure streak has reached {{ $value | printf \"%.0f\" }}, or the pull-mode drain loop hasn't completed in over 30m. A lone registration timeout alone would not trigger this." + runbook: "Check gittensory_orb_relay_register_total{result=\"failed\"} by mode for the failure pattern, and confirm ORB_BROKER_URL / ORB_ENROLLMENT_SECRET are still valid. If pull mode, verify the drain loop itself isn't crash-looping (selfhost_orb_relay_register_failed logs at level=error)." + # ── HTTP serving health (uses the PLANNED status label + duration histogram) ─ # NOTE: gittensory_http_requests_total is gaining a status="2xx|3xx|4xx|5xx" label, # and gittensory_http_request_duration_seconds (a histogram) is being added. Both diff --git a/src/orb/broker-client.ts b/src/orb/broker-client.ts index 4d55d1571a..45cb9f07cd 100644 --- a/src/orb/broker-client.ts +++ b/src/orb/broker-client.ts @@ -174,12 +174,23 @@ export async function registerOrbRelayTarget( } } -export type OrbRelayRegistrationState = { registered: boolean; lastAttemptAtMs: number | null; attempts: number }; +// `attempts` (below) is a lifetime total, never reset -- it answers "did this recover after prior +// failures" (see registerOrbRelayWithMonitor) but can't tell "is it CURRENTLY stuck" from "it hiccuped +// once years ago". `consecutiveFailures` is the complementary streak: it resets to 0 on any success, so +// only a SUSTAINED run of back-to-back failures grows it -- the same shape as ai.ts's +// `aiConsecutiveFailures` / `AI_UNHEALTHY_FAILURE_STREAK`. +export type OrbRelayRegistrationState = { registered: boolean; lastAttemptAtMs: number | null; attempts: number; consecutiveFailures: number }; export function createOrbRelayRegistrationState(): OrbRelayRegistrationState { - return { registered: false, lastAttemptAtMs: null, attempts: 0 }; + return { registered: false, lastAttemptAtMs: null, attempts: 0, consecutiveFailures: 0 }; } +// Mirrors AI_UNHEALTHY_FAILURE_STREAK's shape (src/selfhost/ai.ts): one bad registration attempt is +// routine (the broker had a slow tick, a deploy in flight, a momentary network blip) and must not alert +// on its own -- only a SUSTAINED run of consecutive failures indicates the broker link is actually +// stuck rather than just having hiccuped once (#selfhost-runtime-drift follow-up). +export const ORB_RELAY_REGISTER_UNHEALTHY_FAILURE_STREAK = 3; + // Mirrors RELAY_RETRY_BACKOFF_MINUTES (src/orb/relay.ts) for the same reason: a sustained broker outage must not // re-attempt registration on every ~1min tick -- fleet-wide, that is a synchronized retry storm against a // central Orb that is already degraded. @@ -206,11 +217,13 @@ export async function registerOrbRelayTargetWithRetry( state.lastAttemptAtMs = nowMs; state.attempts += 1; const result = await registerOrbRelayTarget(env, fetchImpl); - if (result.status === "skipped") return { status: "skipped" }; + if (result.status === "skipped") return { status: "skipped" }; // intentional no-op, not a broker failure -- leaves the streak untouched if (result.status === "registered") { state.registered = true; + state.consecutiveFailures = 0; return { status: "registered" }; } + state.consecutiveFailures += 1; /* v8 ignore next -- registerOrbRelayTarget's own "failed" returns always set a string reason (http_NNN or an * error message); the undefined arm only satisfies exactOptionalPropertyTypes for the shared result shape. */ return result.reason !== undefined ? { status: "failed", reason: result.reason } : { status: "failed" }; diff --git a/src/selfhost/metrics.ts b/src/selfhost/metrics.ts index f6566d75d0..c6f21b78a0 100644 --- a/src/selfhost/metrics.ts +++ b/src/selfhost/metrics.ts @@ -97,6 +97,8 @@ const DEFAULT_METRIC_META: readonly (readonly [string, MetricMeta])[] = [ ["gittensory_orb_events_exported_total", { help: "Orb events exported from the self-host runtime.", type: "counter" }], ["gittensory_orb_export_errors_total", { help: "Orb event export errors.", type: "counter" }], ["gittensory_orb_relay_drains_total", { help: "Orb relay drain outcomes.", type: "counter" }], + ["gittensory_orb_relay_register_consecutive_failures", { help: "Current consecutive orb relay registration failure streak, reset to 0 on any success.", type: "gauge" }], + ["gittensory_orb_relay_drain_seconds_since_last", { help: "Seconds since the pull-mode orb relay drain loop last completed successfully, or -1 if never (or in push mode).", type: "gauge" }], ["gittensory_orb_webhook_total", { help: "Orb webhook outcomes.", type: "counter" }], ["gittensory_ai_requests_total", { help: "AI provider request outcomes.", type: "counter" }], ["gittensory_ai_cost_usd_total", { help: "Estimated AI provider cost in USD.", type: "counter" }], diff --git a/src/selfhost/monitored-work.ts b/src/selfhost/monitored-work.ts index cd2d032780..682167d000 100644 --- a/src/selfhost/monitored-work.ts +++ b/src/selfhost/monitored-work.ts @@ -1,5 +1,5 @@ import type { EnqueueWebhookResult } from "../github/webhook"; -import type { OrbRelayRegistrationState } from "../orb/broker-client"; +import { ORB_RELAY_REGISTER_UNHEALTHY_FAILURE_STREAK, type OrbRelayRegistrationState } from "../orb/broker-client"; import { incr } from "./metrics"; import { withSentryMonitor } from "./sentry"; @@ -11,6 +11,11 @@ export type OrbRelayEvent = { export type OrbRelayDrainState = { pendingAck: string[]; + // Set on every drain call that completes WITHOUT throwing, regardless of whether it returned events -- + // an empty poll still proves the broker round-trip itself is alive. Read by + // isOrbRelayRegistrationAlerting so a registration failure streak below the alert threshold can still + // be judged against real evidence the relay connection is (or isn't) making progress. + lastDrainAtMs: number | null; }; type OrbRelayEnv = { @@ -65,6 +70,7 @@ export async function drainOrbRelayWithMonitor(args: { rawBody: string, ) => Promise; log?: (line: string) => void; + nowMs?: number; }): Promise { await withSentryMonitor( "orb-relay-drain", @@ -72,6 +78,10 @@ export async function drainOrbRelayWithMonitor(args: { async () => { const events = await args.drain(args.relayEnv, args.state.pendingAck); args.state.pendingAck = []; + // A successful round-trip (even zero events) proves the broker link itself is alive -- stamped + // BEFORE the per-event enqueue loop so a downstream enqueue failure still counts as drain progress + // (the relay connection, not the local queue, is what registration-alerting cares about). + args.state.lastDrainAtMs = args.nowMs ?? Date.now(); incr("gittensory_orb_relay_drains_total", { result: events.length > 0 ? "events" : "empty", }); @@ -104,16 +114,48 @@ type OrbRelayRegisterEnv = { }; type OrbRelayRegisterResult = { status: "registered" | "already_registered" | "skipped" | "backoff" | "failed"; reason?: string }; +// Pull mode has no inbound endpoint, so a stuck registration doesn't outright silence delivery the way a +// push-mode failure does -- events still arrive as long as drainOrbRelayWithMonitor keeps succeeding. But +// that grace period isn't unlimited: a container that hasn't drained in this long, on top of a failing +// registration, is presumptively stuck rather than just quiet, even if the failure streak itself never +// individually crossed ORB_RELAY_REGISTER_UNHEALTHY_FAILURE_STREAK (e.g. it flaps just under the threshold +// forever). +export const ORB_RELAY_DRAIN_NO_PROGRESS_WINDOW_MS = 30 * 60_000; + +/** Pull-mode registration alert gate (#selfhost-runtime-drift follow-up): a lone registration timeout is + * routine degraded telemetry, NOT an error, as long as the drain loop is still making progress -- so this + * only reports "actually stuck" (as opposed to "one hiccup") when EITHER the failure streak has crossed + * {@link ORB_RELAY_REGISTER_UNHEALTHY_FAILURE_STREAK}, OR a KNOWN prior drain has gone stale for over + * {@link ORB_RELAY_DRAIN_NO_PROGRESS_WINDOW_MS}. `drainLastAtMs` is `null` when there is no drain-progress + * evidence to judge yet (push mode has no drain loop at all; a pull-mode container may simply not have + * reached its first drain tick) -- treated as "insufficient signal to escalate on this basis", not as + * "stuck", so a lone registration hiccup at boot can't alert before the drain loop has had a chance to + * prove itself either way. */ +export function isOrbRelayRegistrationAlerting(args: { + consecutiveFailures: number; + drainLastAtMs: number | null; + nowMs?: number; +}): boolean { + if (args.consecutiveFailures >= ORB_RELAY_REGISTER_UNHEALTHY_FAILURE_STREAK) return true; + if (args.drainLastAtMs === null) return false; + const nowMs = args.nowMs ?? Date.now(); + return nowMs - args.drainLastAtMs > ORB_RELAY_DRAIN_NO_PROGRESS_WINDOW_MS; +} + /** Recurring wrapper around the retryable relay-registration attempt (#selfhost-runtime-drift): a bare * one-shot boot-time call never recovers from a transient broker outage without a process restart. Called on * a timer (state persists across calls), it observes + logs only the calls that actually attempted the * network request (`registered` / `failed`) — `already_registered` / `backoff` / `skipped` are silent no-ops - * so a healthy or intentionally-idle container does not spam logs/Sentry every tick. */ + * so a healthy or intentionally-idle container does not spam logs/Sentry every tick. `drainState` is the + * pull-mode drain loop's shared state (omitted/undefined in push mode, where there is no drain loop) -- its + * `lastDrainAtMs` feeds the no-progress-window half of {@link isOrbRelayRegistrationAlerting}. */ export async function registerOrbRelayWithMonitor(args: { env: OrbRelayRegisterEnv; state: OrbRelayRegistrationState; register: (env: OrbRelayRegisterEnv, state: OrbRelayRegistrationState) => Promise; + drainState?: OrbRelayDrainState; log?: (line: string) => void; + nowMs?: number; }): Promise { await withSentryMonitor("orb-relay-register", { jobType: "orb-relay-register" }, async () => { const result = await args.register(args.env, args.state); @@ -125,6 +167,7 @@ export async function registerOrbRelayWithMonitor(args: { // attempts === 1 means this succeeded on the very first try (parity with the original boot-only log); // a higher count means it recovered after one or more prior failures -- a distinct, more alertable event. if (args.state.attempts > 1) { + incr("gittensory_orb_relay_register_total", { mode, result: "recovered" }); log(JSON.stringify({ event: "selfhost_orb_relay_register_recovered", mode, attempts: args.state.attempts })); } else { log(JSON.stringify({ event: "selfhost_orb_relay_register", mode, attempts: args.state.attempts })); @@ -134,15 +177,24 @@ export async function registerOrbRelayWithMonitor(args: { incr("gittensory_orb_relay_register_total", { mode, result: "failed" }); // A failed registration is fatal for PUSH mode (the Orb can't reach our public relay URL → the container // looks alive but reviews NOTHING → error). In PULL mode the outbound drain loop delivers events once a - // later attempt succeeds, so a failed announce is only degraded telemetry → warn (not paged as deaf). + // later attempt succeeds, so a failed announce is only degraded telemetry -- UNLESS the streak/no-progress + // gate below says the relay link is actually stuck, not just having hiccuped once. const pull = mode === "pull"; - (pull ? console.warn : console.error)( + const alerting = + !pull || + isOrbRelayRegistrationAlerting({ + consecutiveFailures: args.state.consecutiveFailures, + drainLastAtMs: args.drainState?.lastDrainAtMs ?? null, + ...(args.nowMs !== undefined ? { nowMs: args.nowMs } : {}), + }); + (alerting ? console.error : console.warn)( JSON.stringify({ - level: pull ? "warn" : "error", + level: alerting ? "error" : "warn", event: "selfhost_orb_relay_register_failed", mode, error: result.reason ?? "unknown", attempts: args.state.attempts, + consecutiveFailures: args.state.consecutiveFailures, }), ); }); diff --git a/src/server.ts b/src/server.ts index 10ed6bbc82..789d4a104d 100644 --- a/src/server.ts +++ b/src/server.ts @@ -955,6 +955,12 @@ async function main(): Promise { setInterval(runOrbExport, 3_600_000); // then hourly /* v8 ignore stop */ + // Pull-mode relay drain state is declared here (ahead of registration below) so a failed registration + // attempt can consult `relayDrainState.lastDrainAtMs` -- a single registration timeout must not alert + // while the drain loop is still proving the relay connection itself is alive (#selfhost-runtime-drift + // follow-up). Stays undefined in push mode, where there is no drain loop. + const relayDrainState = process.env.ORB_RELAY_MODE === "pull" ? { pendingAck: [] as string[], lastDrainAtMs: null as number | null } : undefined; + // Brokered self-host: register our relay target with the central Orb (best-effort). PUSH mode (default) // registers a public relay URL the Orb POSTs to; PULL mode (ORB_RELAY_MODE=pull) registers no URL and the // drain loop below pulls events outbound — the right fit behind NAT/tailnet (no inbound endpoint exposed). @@ -975,19 +981,26 @@ async function main(): Promise { env: orbRelayEnv, state: orbRelayRegistrationState, register: registerOrbRelayTargetWithRetry, + ...(relayDrainState ? { drainState: relayDrainState } : {}), }).catch((error) => captureError(error, { kind: "orb_relay_register" })); void attemptOrbRelayRegistration(); setInterval(() => void attemptOrbRelayRegistration(), 60_000); + // Dashboard-visible counterparts to the streak/no-progress alert gate in isOrbRelayRegistrationAlerting: + // an operator staring at the registration-failures counter alone can't tell "one hiccup" from "actually + // stuck" -- these two gauges are the SAME two signals that gate, sampled live at scrape time. + gauge("gittensory_orb_relay_register_consecutive_failures", () => orbRelayRegistrationState.consecutiveFailures); + gauge("gittensory_orb_relay_drain_seconds_since_last", () => + relayDrainState?.lastDrainAtMs == null ? -1 : Math.floor((Date.now() - relayDrainState.lastDrainAtMs) / 1000), + ); /* v8 ignore stop */ // Pull-mode relay drain (#secure-relay): when ORB_RELAY_MODE=pull, the engine DRAINS its events from the Orb on a // timer instead of exposing an inbound endpoint — the right fit behind NAT/tailnet. Acks the previous batch so the // Orb deletes delivered events; best-effort (a failed tick retries next interval). Each event enqueues into the // same WEBHOOKS lane the push receiver uses. - if (process.env.ORB_RELAY_MODE === "pull" && process.env.ORB_ENROLLMENT_SECRET) { + if (process.env.ORB_RELAY_MODE === "pull" && process.env.ORB_ENROLLMENT_SECRET && relayDrainState) { const { drainOrbRelay } = await import("./orb/broker-client"); const { enqueueWebhookByEnv } = await import("./github/webhook"); - const relayDrainState = { pendingAck: [] as string[] }; /* v8 ignore start -- pull-mode relay loop is a live self-host timer; monitor semantics are covered in selfhost tests. */ const drainRelay = async (): Promise => { await drainOrbRelayWithMonitor({ diff --git a/test/unit/orb-broker-client.test.ts b/test/unit/orb-broker-client.test.ts index 42d74975b7..53411de215 100644 --- a/test/unit/orb-broker-client.test.ts +++ b/test/unit/orb-broker-client.test.ts @@ -5,6 +5,7 @@ import { fetchBrokeredInstallationToken, isOrbBrokerMode, ORB_RELAY_REGISTER_RETRY_BACKOFF_MS, + ORB_RELAY_REGISTER_UNHEALTHY_FAILURE_STREAK, registerOrbRelayTarget, registerOrbRelayTargetWithRetry, } from "../../src/orb/broker-client"; @@ -264,7 +265,7 @@ describe("registerOrbRelayTargetWithRetry", () => { it("skips outside broker mode without touching state", async () => { const state = createOrbRelayRegistrationState(); expect(await registerOrbRelayTargetWithRetry({}, state)).toEqual({ status: "skipped" }); - expect(state).toEqual({ registered: false, lastAttemptAtMs: null, attempts: 0 }); + expect(state).toEqual({ registered: false, lastAttemptAtMs: null, attempts: 0, consecutiveFailures: 0 }); }); it("attempts, marks registered on success, and never attempts again", async () => { @@ -274,7 +275,7 @@ describe("registerOrbRelayTargetWithRetry", () => { const first = await registerOrbRelayTargetWithRetry(cfg, state, 1_000, fetchImpl); expect(first).toEqual({ status: "registered" }); - expect(state).toEqual({ registered: true, lastAttemptAtMs: 1_000, attempts: 1 }); + expect(state).toEqual({ registered: true, lastAttemptAtMs: 1_000, attempts: 1, consecutiveFailures: 0 }); const second = await registerOrbRelayTargetWithRetry(cfg, state, 2_000, fetchImpl); expect(second).toEqual({ status: "already_registered" }); @@ -289,6 +290,7 @@ describe("registerOrbRelayTargetWithRetry", () => { const first = await registerOrbRelayTargetWithRetry(cfg, state, 0, failThenSucceed); expect(first).toEqual({ status: "failed", reason: "http_500" }); expect(state.attempts).toBe(1); + expect(state.consecutiveFailures).toBe(1); // Still inside the backoff window — must not re-attempt (no fetch call at all). const stillBackingOff = await registerOrbRelayTargetWithRetry( @@ -301,12 +303,13 @@ describe("registerOrbRelayTargetWithRetry", () => { ); expect(stillBackingOff).toEqual({ status: "backoff" }); expect(state.attempts).toBe(1); + expect(state.consecutiveFailures).toBe(1); // backoff never re-attempts, so the streak doesn't move // Backoff elapsed — retries and can now recover. const { fetchImpl: successFetch } = captureFetch(new Response("ok")); const recovered = await registerOrbRelayTargetWithRetry(cfg, state, ORB_RELAY_REGISTER_RETRY_BACKOFF_MS, successFetch); expect(recovered).toEqual({ status: "registered" }); - expect(state).toEqual({ registered: true, lastAttemptAtMs: ORB_RELAY_REGISTER_RETRY_BACKOFF_MS, attempts: 2 }); + expect(state).toEqual({ registered: true, lastAttemptAtMs: ORB_RELAY_REGISTER_RETRY_BACKOFF_MS, attempts: 2, consecutiveFailures: 0 }); }); it("passes through a skipped result from the underlying attempt (e.g. push mode with no public origin) without arming backoff", async () => { @@ -315,6 +318,42 @@ describe("registerOrbRelayTargetWithRetry", () => { expect(result).toEqual({ status: "skipped" }); // skipped still counts as an attempt (it went through the backoff gate), but never registers. expect(state.registered).toBe(false); + // A skip is an intentional no-op (e.g. push mode with no public origin yet), not a broker failure -- + // it must not move the consecutive-failure streak either direction. + expect(state.consecutiveFailures).toBe(0); + }); + + it("grows the consecutive-failure streak across repeated failures and resets it to 0 on the next success", async () => { + const state = createOrbRelayRegistrationState(); + const cfg = { ORB_ENROLLMENT_SECRET: "s", PUBLIC_API_ORIGIN: "https://me.example" }; + const failing = (async () => new Response("no", { status: 500 })) as typeof fetch; + + let nowMs = 0; + for (let i = 1; i <= ORB_RELAY_REGISTER_UNHEALTHY_FAILURE_STREAK; i++) { + const result = await registerOrbRelayTargetWithRetry(cfg, state, nowMs, failing); + expect(result).toEqual({ status: "failed", reason: "http_500" }); + expect(state.consecutiveFailures).toBe(i); + nowMs += ORB_RELAY_REGISTER_RETRY_BACKOFF_MS; + } + expect(state.consecutiveFailures).toBe(ORB_RELAY_REGISTER_UNHEALTHY_FAILURE_STREAK); + + const { fetchImpl: successFetch } = captureFetch(new Response("ok")); + const recovered = await registerOrbRelayTargetWithRetry(cfg, state, nowMs, successFetch); + expect(recovered).toEqual({ status: "registered" }); + expect(state.consecutiveFailures).toBe(0); + expect(state.attempts).toBe(ORB_RELAY_REGISTER_UNHEALTHY_FAILURE_STREAK + 1); + }); + + it("counts a thrown fetch (not just a non-ok response) towards the consecutive-failure streak", async () => { + const state = createOrbRelayRegistrationState(); + const cfg = { ORB_ENROLLMENT_SECRET: "s", PUBLIC_API_ORIGIN: "https://me.example" }; + const throwing = (async () => { + throw new Error("network down"); + }) as typeof fetch; + + const result = await registerOrbRelayTargetWithRetry(cfg, state, 0, throwing); + expect(result).toEqual({ status: "failed", reason: "network down" }); + expect(state.consecutiveFailures).toBe(1); }); }); diff --git a/test/unit/selfhost-grafana-dashboard.test.ts b/test/unit/selfhost-grafana-dashboard.test.ts index 2fde90d002..3a3ac922a9 100644 --- a/test/unit/selfhost-grafana-dashboard.test.ts +++ b/test/unit/selfhost-grafana-dashboard.test.ts @@ -165,6 +165,7 @@ describe("Gittensory Self-Host Grafana dashboard", () => { "Agent Permission-Denied Actions (total)", "Agent Permission-Denied Actions by Class (denied vs suppressed-repeat rate)", "Orb Relay Registration Attempts by Mode/Result (rate)", + "Orb Relay Registration: Streak vs Drain Progress (one hiccup vs actually stuck)", ]), ); // Every stat-panel counter is sum()-wrapped, matching its siblings -- a multi-instance self-host scrape @@ -179,6 +180,15 @@ describe("Gittensory Self-Host Grafana dashboard", () => { expect(targets.some((target) => target.expr === "sum by (actionClass) (rate(gittensory_agent_action_permission_denied_total[5m]))")).toBe(true); expect(targets.some((target) => target.expr === "sum by (actionClass) (rate(gittensory_agent_action_permission_denied_suppressed_total[5m]))")).toBe(true); expect(targets.some((target) => target.expr === "sum by (mode, result) (rate(gittensory_orb_relay_register_total[5m]))")).toBe(true); + // #selfhost-runtime-drift follow-up: the streak-vs-drain-progress panel is the dashboard-visible + // counterpart to isOrbRelayRegistrationAlerting's gate -- a lone registration timeout must not read as + // a dashboard error on its own as long as the drain loop is still making progress. + expect(targets.some((target) => target.expr === "gittensory_orb_relay_register_consecutive_failures or vector(0)")).toBe(true); + expect(targets.some((target) => target.expr === "gittensory_orb_relay_drain_seconds_since_last or vector(0)")).toBe(true); + + const alerts = readFileSync(selfhostAlertsPath, "utf8"); + expect(alerts).toContain("alert: GittensoryOrbRelayRegistrationStuck"); + expect(alerts).toContain("gittensory_orb_relay_register_consecutive_failures >= 3 or gittensory_orb_relay_drain_seconds_since_last > 1800"); }); it("surfaces the backlog-vs-fresh-intake lane fairness panels (#selfhost-lane-observability)", () => { diff --git a/test/unit/selfhost-monitored-work.test.ts b/test/unit/selfhost-monitored-work.test.ts index 161df61f1c..afb0aa22da 100644 --- a/test/unit/selfhost-monitored-work.test.ts +++ b/test/unit/selfhost-monitored-work.test.ts @@ -13,6 +13,8 @@ vi.mock("../../src/selfhost/sentry", () => ({ import { drainOrbRelayWithMonitor, + isOrbRelayRegistrationAlerting, + ORB_RELAY_DRAIN_NO_PROGRESS_WINDOW_MS, registerOrbRelayWithMonitor, runOrbExportWithMonitor, runScheduledLoopWithMonitor, @@ -66,7 +68,7 @@ describe("self-host monitored recurring work", () => { try { await runOrbExportWithMonitor(async () => 1); await drainOrbRelayWithMonitor({ - state: { pendingAck: [] }, + state: { pendingAck: [], lastDrainAtMs: null }, relayEnv: {}, env: {} as Env, drain: vi.fn().mockResolvedValue([ @@ -87,7 +89,7 @@ describe("self-host monitored recurring work", () => { }); it("drains Orb relay events and retains acks only for durably handled deliveries", async () => { - const state: OrbRelayDrainState = { pendingAck: ["previous-delivery"] }; + const state: OrbRelayDrainState = { pendingAck: ["previous-delivery"], lastDrainAtMs: null }; const relayEnv = { ORB_ENROLLMENT_SECRET: "secret", ORB_BROKER_URL: "https://orb.example", @@ -147,7 +149,7 @@ describe("self-host monitored recurring work", () => { }); it("clears previous Orb relay acks and stays quiet when the broker has no events", async () => { - const state: OrbRelayDrainState = { pendingAck: ["previous-delivery"] }; + const state: OrbRelayDrainState = { pendingAck: ["previous-delivery"], lastDrainAtMs: null }; const drain = vi.fn().mockResolvedValue([]); const enqueue = vi.fn(); const log = vi.fn(); @@ -159,16 +161,34 @@ describe("self-host monitored recurring work", () => { drain, enqueue, log, + nowMs: 5_000, }); expect(state.pendingAck).toEqual([]); expect(enqueue).not.toHaveBeenCalled(); expect(log).not.toHaveBeenCalled(); expect(await renderMetrics()).toContain('gittensory_orb_relay_drains_total{result="empty"} 1'); + // An empty poll still proves the broker round-trip succeeded -- stamped even with zero events. + expect(state.lastDrainAtMs).toBe(5_000); }); - it("preserves pending Orb relay acks when the broker drain throws before delivery state is known", async () => { - const state: OrbRelayDrainState = { pendingAck: ["previous-delivery"] }; + it("stamps lastDrainAtMs with the real clock when no nowMs override is given", async () => { + const state: OrbRelayDrainState = { pendingAck: [], lastDrainAtMs: null }; + const before = Date.now(); + + await drainOrbRelayWithMonitor({ + state, + relayEnv: {}, + env: {} as Env, + drain: vi.fn().mockResolvedValue([]), + enqueue: vi.fn(), + }); + + expect(state.lastDrainAtMs).toBeGreaterThanOrEqual(before); + }); + + it("preserves pending Orb relay acks and skips the drain-progress stamp when the broker drain throws", async () => { + const state: OrbRelayDrainState = { pendingAck: ["previous-delivery"], lastDrainAtMs: null }; const drain = vi.fn().mockRejectedValue(new Error("broker down")); await expect( @@ -182,10 +202,40 @@ describe("self-host monitored recurring work", () => { ).rejects.toThrow("broker down"); expect(state.pendingAck).toEqual(["previous-delivery"]); + expect(state.lastDrainAtMs).toBeNull(); + }); + + describe("isOrbRelayRegistrationAlerting", () => { + it("does not alert below the failure streak with no drain-progress evidence yet (a lone boot-time hiccup)", () => { + expect(isOrbRelayRegistrationAlerting({ consecutiveFailures: 1, drainLastAtMs: null, nowMs: 1_000 })).toBe(false); + expect(isOrbRelayRegistrationAlerting({ consecutiveFailures: 2, drainLastAtMs: null, nowMs: 1_000 })).toBe(false); + }); + + it("does not alert below the failure streak while a known drain is still fresh", () => { + expect( + isOrbRelayRegistrationAlerting({ consecutiveFailures: 1, drainLastAtMs: 1_000, nowMs: 1_000 + ORB_RELAY_DRAIN_NO_PROGRESS_WINDOW_MS }), + ).toBe(false); // exactly at the window boundary — not yet OVER it + }); + + it("alerts once the consecutive-failure streak reaches the threshold, regardless of drain freshness", () => { + expect(isOrbRelayRegistrationAlerting({ consecutiveFailures: 3, drainLastAtMs: Date.now(), nowMs: Date.now() })).toBe(true); + expect(isOrbRelayRegistrationAlerting({ consecutiveFailures: 4, drainLastAtMs: null, nowMs: 1_000 })).toBe(true); + }); + + it("alerts once a known last-drain timestamp goes stale past the no-progress window, even below the streak threshold", () => { + expect( + isOrbRelayRegistrationAlerting({ consecutiveFailures: 1, drainLastAtMs: 0, nowMs: ORB_RELAY_DRAIN_NO_PROGRESS_WINDOW_MS + 1 }), + ).toBe(true); + }); + + it("defaults nowMs to the real clock when omitted", () => { + expect(isOrbRelayRegistrationAlerting({ consecutiveFailures: 0, drainLastAtMs: Date.now() })).toBe(false); + expect(isOrbRelayRegistrationAlerting({ consecutiveFailures: 0, drainLastAtMs: Date.now() - ORB_RELAY_DRAIN_NO_PROGRESS_WINDOW_MS - 1 })).toBe(true); + }); }); describe("registerOrbRelayWithMonitor", () => { - const freshState = (): OrbRelayRegistrationState => ({ registered: false, lastAttemptAtMs: null, attempts: 0 }); + const freshState = (): OrbRelayRegistrationState => ({ registered: false, lastAttemptAtMs: null, attempts: 0, consecutiveFailures: 0 }); it("logs and records the registered metric on the first successful attempt", async () => { const log = vi.fn(); @@ -204,9 +254,11 @@ describe("self-host monitored recurring work", () => { JSON.stringify({ event: "selfhost_orb_relay_register", mode: "push", attempts: 1 }), ); expect(await renderMetrics()).toContain('gittensory_orb_relay_register_total{mode="push",result="registered"} 1'); + // A first-try success is not a recovery -- no recovered series at all. + expect(await renderMetrics()).not.toContain('result="recovered"'); }); - it("logs a distinct recovered event when registration succeeds after prior failures", async () => { + it("logs a distinct recovered event and records the recovered metric when registration succeeds after prior failures", async () => { const log = vi.fn(); const state = freshState(); state.attempts = 3; // two prior failed attempts before this one succeeded @@ -217,20 +269,22 @@ describe("self-host monitored recurring work", () => { expect(log).toHaveBeenCalledWith( JSON.stringify({ event: "selfhost_orb_relay_register_recovered", mode: "pull", attempts: 3 }), ); + expect(await renderMetrics()).toContain('gittensory_orb_relay_register_total{mode="pull",result="recovered"} 1'); }); - it("warns (not errors) on a pull-mode failure, and records the failed metric", async () => { + it("warns (not errors) on a single pull-mode failure below the streak threshold with no drain-progress evidence yet", async () => { const errorSpy = vi.spyOn(console, "error").mockImplementation(() => undefined); const warnSpy = vi.spyOn(console, "warn").mockImplementation(() => undefined); try { const state = freshState(); state.attempts = 1; + state.consecutiveFailures = 1; const register = vi.fn().mockResolvedValue({ status: "failed", reason: "http_500" }); await registerOrbRelayWithMonitor({ env: { ORB_RELAY_MODE: "pull" }, state, register }); expect(warnSpy).toHaveBeenCalledWith( - JSON.stringify({ level: "warn", event: "selfhost_orb_relay_register_failed", mode: "pull", error: "http_500", attempts: 1 }), + JSON.stringify({ level: "warn", event: "selfhost_orb_relay_register_failed", mode: "pull", error: "http_500", attempts: 1, consecutiveFailures: 1 }), ); expect(errorSpy).not.toHaveBeenCalled(); expect(await renderMetrics()).toContain('gittensory_orb_relay_register_total{mode="pull",result="failed"} 1'); @@ -240,18 +294,95 @@ describe("self-host monitored recurring work", () => { } }); + it("stays a warning while orb_relay_drained keeps firing, even across several failures under the streak threshold", async () => { + const warnSpy = vi.spyOn(console, "warn").mockImplementation(() => undefined); + const errorSpy = vi.spyOn(console, "error").mockImplementation(() => undefined); + try { + const state = freshState(); + state.attempts = 1; + state.consecutiveFailures = 1; // one hiccup, still under ORB_RELAY_REGISTER_UNHEALTHY_FAILURE_STREAK + const drainState: OrbRelayDrainState = { pendingAck: [], lastDrainAtMs: 1_000 }; // relay drained recently + const register = vi.fn().mockResolvedValue({ status: "failed", reason: "timeout" }); + + await registerOrbRelayWithMonitor({ + env: { ORB_RELAY_MODE: "pull" }, + state, + register, + drainState, + nowMs: 1_000 + 60_000, // well inside ORB_RELAY_DRAIN_NO_PROGRESS_WINDOW_MS + }); + + expect(warnSpy).toHaveBeenCalledTimes(1); + expect(errorSpy).not.toHaveBeenCalled(); + } finally { + warnSpy.mockRestore(); + errorSpy.mockRestore(); + } + }); + + it("escalates a pull-mode failure to an error once the consecutive-failure streak crosses the threshold", async () => { + const errorSpy = vi.spyOn(console, "error").mockImplementation(() => undefined); + const warnSpy = vi.spyOn(console, "warn").mockImplementation(() => undefined); + try { + const state = freshState(); + state.attempts = 3; + state.consecutiveFailures = 3; // == ORB_RELAY_REGISTER_UNHEALTHY_FAILURE_STREAK + const drainState: OrbRelayDrainState = { pendingAck: [], lastDrainAtMs: 1_000 }; // still draining fine + const register = vi.fn().mockResolvedValue({ status: "failed", reason: "http_500" }); + + await registerOrbRelayWithMonitor({ env: { ORB_RELAY_MODE: "pull" }, state, register, drainState, nowMs: 2_000 }); + + expect(errorSpy).toHaveBeenCalledWith( + JSON.stringify({ level: "error", event: "selfhost_orb_relay_register_failed", mode: "pull", error: "http_500", attempts: 3, consecutiveFailures: 3 }), + ); + expect(warnSpy).not.toHaveBeenCalled(); + } finally { + errorSpy.mockRestore(); + warnSpy.mockRestore(); + } + }); + + it("escalates a pull-mode failure to an error once the drain loop has gone quiet past the no-progress window", async () => { + const errorSpy = vi.spyOn(console, "error").mockImplementation(() => undefined); + const warnSpy = vi.spyOn(console, "warn").mockImplementation(() => undefined); + try { + const state = freshState(); + state.attempts = 1; + state.consecutiveFailures = 1; // below the streak threshold on its own + const drainState: OrbRelayDrainState = { pendingAck: [], lastDrainAtMs: 0 }; + const register = vi.fn().mockResolvedValue({ status: "failed", reason: "timeout" }); + + await registerOrbRelayWithMonitor({ + env: { ORB_RELAY_MODE: "pull" }, + state, + register, + drainState, + nowMs: ORB_RELAY_DRAIN_NO_PROGRESS_WINDOW_MS + 1, + }); + + expect(errorSpy).toHaveBeenCalledWith( + JSON.stringify({ level: "error", event: "selfhost_orb_relay_register_failed", mode: "pull", error: "timeout", attempts: 1, consecutiveFailures: 1 }), + ); + expect(warnSpy).not.toHaveBeenCalled(); + } finally { + errorSpy.mockRestore(); + warnSpy.mockRestore(); + } + }); + it("errors (not warns) on a push-mode failure, defaulting the reason to 'unknown' when absent", async () => { const errorSpy = vi.spyOn(console, "error").mockImplementation(() => undefined); const warnSpy = vi.spyOn(console, "warn").mockImplementation(() => undefined); try { const state = freshState(); state.attempts = 1; + state.consecutiveFailures = 1; const register = vi.fn().mockResolvedValue({ status: "failed" }); await registerOrbRelayWithMonitor({ env: {}, state, register }); expect(errorSpy).toHaveBeenCalledWith( - JSON.stringify({ level: "error", event: "selfhost_orb_relay_register_failed", mode: "push", error: "unknown", attempts: 1 }), + JSON.stringify({ level: "error", event: "selfhost_orb_relay_register_failed", mode: "push", error: "unknown", attempts: 1, consecutiveFailures: 1 }), ); expect(warnSpy).not.toHaveBeenCalled(); } finally {