From 6de2833984f96bce94ebd96c47cd7a86568191e3 Mon Sep 17 00:00:00 2001 From: JSONbored <49853598+JSONbored@users.noreply.github.com> Date: Mon, 6 Jul 2026 12:41:31 -0700 Subject: [PATCH] obs(selfhost): detect and alert on GitHub App JWT clock skew (#3811) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit edge-us-01's system clock silently drifted ~3 minutes off true time because its sole configured NTP source was dead (Reach: 0, no redundant fallback), breaking GitHub App JWT auth ("Bad credentials") for a window before anyone noticed. Adds a gittensory_clock_skew_seconds gauge sampled from the Date header of the GitHub App's own JWT-authenticated installation-token mint response — no extra network round-trip, sampled at exactly the cadence the vulnerable code path itself runs. Wires in Prometheus warning/critical alert rules (60s/120s, both well under the 3-minute drift actually observed) and a Grafana panel, plus docs/docker-compose guidance on configuring redundant host NTP sources. --- .../routes/docs.self-hosting-operations.tsx | 21 ++++++++ docker-compose.yml | 7 +++ grafana/dashboards/gittensory.json | 43 +++++++++++++++ prometheus/rules/alerts.yml | 31 +++++++++++ src/github/app.ts | 11 ++-- src/selfhost/clock-skew.ts | 34 ++++++++++++ src/selfhost/metrics.ts | 1 + src/server.ts | 2 + test/unit/clock-skew.test.ts | 54 +++++++++++++++++++ test/unit/github-app.test.ts | 25 ++++++++- 10 files changed, 225 insertions(+), 4 deletions(-) create mode 100644 src/selfhost/clock-skew.ts create mode 100644 test/unit/clock-skew.test.ts diff --git a/apps/gittensory-ui/src/routes/docs.self-hosting-operations.tsx b/apps/gittensory-ui/src/routes/docs.self-hosting-operations.tsx index 11830cf899..a037dfbf00 100644 --- a/apps/gittensory-ui/src/routes/docs.self-hosting-operations.tsx +++ b/apps/gittensory-ui/src/routes/docs.self-hosting-operations.tsx @@ -97,6 +97,27 @@ selfhost_webhook_enqueue_binding_missing`} docker compose --profile postgres --profile observability --profile backup up -d`} /> +

Host clock sync (NTP)

+ + GitHub App JWTs are signed with a timestamp from this process's clock, backdated 60 seconds + for skew tolerance. If the host clock drifts past that margin, GitHub starts rejecting the + JWT as not-yet-valid — every GitHub App request fails with a generic{" "} + Bad credentials error, with no obvious link back to the clock. Configure at + least two independent NTP sources on the host (not just in the container) so a single dead + source can't silently take the whole clock out from under you. + +

+ Check sync health with chronyc sources (or ntpq -p on an{" "} + ntpd host) — every configured source should show a nonzero Reach{" "} + value; Reach: 0 means that source has never successfully synced. The{" "} + gittensory_clock_skew_seconds gauge on the Clock Sync (NTP){" "} + row of the main Grafana dashboard tracks the live drift between this process and GitHub's + server time, sampled from the Date header of the GitHub App's own + installation-token mint calls — no extra network probe required. The bundled Prometheus + rules alert at 60s (warning) and 120s (critical) drift, both well under the margin that + actually breaks JWT auth. +

+

Alerting — required for a 24/7 deployment

Alertmanager ships with a valid but silent default: every alert routes to a diff --git a/docker-compose.yml b/docker-compose.yml index c33c5aaa51..4aa8a931b0 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -30,6 +30,13 @@ # docker compose --profile observability up -d # metrics + logs + dashboards # docker compose --profile rees up -d # local REES review enrichment # docker compose --profile tailscale --profile runners up -d # tailnet + CI runners +# +# HOST CLOCK (#3811): containers share the HOST kernel clock, so this compose file cannot fix a +# drifting clock for you -- configure at least two independent NTP sources on the host itself +# (chrony/ntpd), not just one. A single dead NTP source silently drifts the clock with no local +# symptom until GitHub App JWT auth starts failing ("Bad credentials") once the drift exceeds the +# JWT's 60s skew tolerance. See docs/self-hosting/operations → "Host clock sync (NTP)" and the +# gittensory_clock_skew_seconds Grafana panel/alert (--profile observability) for live drift. # Bounded container logging (#audit-rate-headroom): every service below defaults to Docker's # json-file driver, which has NO size cap on its own -- a long-running 24/7 stack can fill the diff --git a/grafana/dashboards/gittensory.json b/grafana/dashboards/gittensory.json index a78f376600..9d0751dca6 100644 --- a/grafana/dashboards/gittensory.json +++ b/grafana/dashboards/gittensory.json @@ -3016,6 +3016,49 @@ } } ] + }, + { + "collapsed": false, + "gridPos": { "h": 1, "w": 24, "x": 0, "y": 204 }, + "id": 159, + "title": "Clock Sync (NTP, #3811)", + "type": "row" + }, + { + "datasource": { "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, + "fieldConfig": { + "defaults": { + "color": { "mode": "thresholds" }, + "thresholds": { + "mode": "absolute", + "steps": [ + { "color": "green", "value": null }, + { "color": "yellow", "value": 60 }, + { "color": "red", "value": 120 } + ] + }, + "unit": "s" + } + }, + "gridPos": { "h": 4, "w": 4, "x": 0, "y": 205 }, + "id": 160, + "options": { + "colorMode": "background", + "graphMode": "none", + "justifyMode": "auto", + "orientation": "auto", + "reduceOptions": { "calcs": ["lastNotNull"], "fields": "", "values": false }, + "textMode": "auto" + }, + "title": "Clock Skew (|value| > 60s warns, > 120s critical)", + "type": "stat", + "targets": [ + { + "datasource": { "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, + "expr": "abs(gittensory_clock_skew_seconds)", + "legendFormat": "skew" + } + ] } ], "refresh": "30s", diff --git a/prometheus/rules/alerts.yml b/prometheus/rules/alerts.yml index 24ccfa43d3..3c4d6c261e 100644 --- a/prometheus/rules/alerts.yml +++ b/prometheus/rules/alerts.yml @@ -479,3 +479,34 @@ groups: summary: "gittensory AI provider {{ $labels.provider }} circuit breaker is open" description: "Provider {{ $labels.provider }} has failed repeatedly and its circuit breaker is skipping calls fast during its cooldown (sustained 5m)." runbook: "Check that provider's credentials/reachability (CLI auth for claude-code/codex, or the configured API key/base URL for HTTP providers) via gittensory_ai_provider_failures_total{provider=\"...\"} and recent selfhost_ai_provider_failed logs." + + # ── Host clock sync (#3811) ─────────────────────────────────────────────── + - name: gittensory-system-health + rules: + - alert: GittensoryClockSkewWarning + # GitHub App JWTs are signed with iat backdated 60s for skew tolerance and exp at now+540s + # (createAppJwt, src/github/app.ts). A local clock running ahead erodes that backdate; once skew + # approaches it, GitHub can reject the JWT as not-yet-valid ("Bad credentials"), breaking ALL + # GitHub App auth fleet-wide -- exactly what happened when edge-us-01's sole NTP source died and + # its clock drifted ~3 minutes unnoticed. 60s is well under that 3-minute drift, so this fires long + # before auth actually breaks. + expr: abs(gittensory_clock_skew_seconds) > 60 + for: 5m + labels: + severity: warning + annotations: + summary: "gittensory host clock has drifted {{ $value | printf \"%.0f\" }}s from GitHub's server time" + description: "Clock skew has been over 60s (sustained 5m). GitHub App JWT auth starts failing once skew approaches the 60s iat backdate margin." + runbook: "Check `chronyc sources` / `chronyc tracking` on the host. Confirm at least one NTP source shows a nonzero Reach (Reach: 0 means that source has never successfully synced). Configure redundant NTP sources -- a single dead source is a silent single point of failure." + + - alert: GittensoryClockSkewCritical + # 120s is comfortably past the 60s JWT backdate margin -- GitHub App auth is very likely already + # failing fleet-wide by this point. + expr: abs(gittensory_clock_skew_seconds) > 120 + for: 2m + labels: + severity: critical + annotations: + summary: "gittensory host clock skew is CRITICAL ({{ $value | printf \"%.0f\" }}s) -- GitHub App auth is likely failing" + description: "Clock skew has exceeded 120s (sustained 2m), well past the point GitHub App JWT auth (\"Bad credentials\") is expected to start failing fleet-wide." + runbook: "Same as GittensoryClockSkewWarning, but treat as urgent: fix NTP sync immediately (chronyc sources, chronyc makestep, restart chrony if every source stays at Reach: 0). Check for github_app_jwt_rejected logs to confirm auth impact." diff --git a/src/github/app.ts b/src/github/app.ts index d5c039dd37..d506b92d42 100644 --- a/src/github/app.ts +++ b/src/github/app.ts @@ -4,6 +4,7 @@ import { isOrbBrokerMode, } from "../orb/broker-client"; import { updateInstallationPermissions } from "../db/repositories"; +import { recordClockSkewFromResponse } from "../selfhost/clock-skew"; import { clearGitHubResponseCacheForTest, githubRateLimitAdmissionKeyForInstallation, @@ -203,18 +204,22 @@ export async function withInstallationTokenRetry( } /** POST the App-installations access-token endpoint with a given JWT. Extracted so mintInstallationToken can - * issue the same request twice — once with the cached JWT, once with a freshly-signed one on a 401 (#2453). */ -function requestInstallationTokenWithJwt( + * issue the same request twice — once with the cached JWT, once with a freshly-signed one on a 401 (#2453). + * Also samples clock skew (#3811) from the response's Date header: this JWT-authenticated mint is exactly + * the call that fails first when the local clock drifts, so no extra network round-trip is needed to check it. */ +async function requestInstallationTokenWithJwt( jwt: string, installationId: number, ): Promise { - return timeoutFetch( + const response = await timeoutFetch( `https://api.github.com/app/installations/${installationId}/access_tokens`, { method: "POST", headers: githubHeaders(`Bearer ${jwt}`), }, ); + recordClockSkewFromResponse(response); + return response; } /** Mint a fresh installation token (broker or local App-JWT) and cache it. `cached` is the expired/absent prior diff --git a/src/selfhost/clock-skew.ts b/src/selfhost/clock-skew.ts new file mode 100644 index 0000000000..90ef04d529 --- /dev/null +++ b/src/selfhost/clock-skew.ts @@ -0,0 +1,34 @@ +// System clock-drift detection (#3811). edge-us-01's system clock silently drifted ~3 minutes off true +// time because its sole configured NTP source was dead (`chronyc sources` showed Reach: 0 the whole +// time, no redundant fallback), breaking GitHub App JWT auth ("Bad credentials") for a window before +// anyone noticed. GitHub App JWTs are signed with iat/exp derived from the local clock (createAppJwt, +// src/github/app.ts), so drift shows up there first. Rather than spend a network round-trip just to +// check the clock, this piggybacks on the `Date` response header of the JWT-authenticated +// installation-token mint call that's ALREADY made whenever a token needs (re-)minting -- no new +// outbound request, sampled at exactly the cadence the vulnerable code path itself runs. + +let lastSkewSeconds = 0; + +/** + * Update the last-observed clock-skew sample from a GitHub response's `Date` header. Positive means + * this process's clock is AHEAD of GitHub's; negative means it's BEHIND. A missing or unparseable + * header is ignored (the previous sample is left in place) rather than reset to 0, so one malformed + * response can never mask real drift until the next successful sample. + */ +export function recordClockSkewFromResponse(response: Response): void { + const dateHeader = response.headers.get("date"); + if (!dateHeader) return; + const remoteMs = Date.parse(dateHeader); + if (!Number.isFinite(remoteMs)) return; + lastSkewSeconds = (Date.now() - remoteMs) / 1000; +} + +/** The most recently observed clock-skew sample in seconds (0 until the first successful sample). */ +export function clockSkewSecondsSample(): number { + return lastSkewSeconds; +} + +/** Test-only: reset the module-level sample between tests. */ +export function resetClockSkewForTest(): void { + lastSkewSeconds = 0; +} diff --git a/src/selfhost/metrics.ts b/src/selfhost/metrics.ts index 7849138214..25b2a21a74 100644 --- a/src/selfhost/metrics.ts +++ b/src/selfhost/metrics.ts @@ -51,6 +51,7 @@ const DEFAULT_METRIC_META: readonly (readonly [string, MetricMeta])[] = [ ["gittensory_jobs_claimed_by_lane_total", { help: "Foreground jobs claimed via the backlog-vs-fresh-intake fairness lane.", type: "counter" }], ["gittensory_github_rest_rate_limit_remaining", { help: "Newest observed GitHub REST rate-limit remaining count, by key scope.", type: "gauge" }], ["gittensory_host_load_avg1_per_core", { help: "One-minute host load average normalized by CPU core count.", type: "gauge" }], + ["gittensory_clock_skew_seconds", { help: "Clock skew in seconds between this process and GitHub's server time (positive = ahead), sampled from GitHub App JWT-mint response Date headers.", type: "gauge" }], ["gittensory_uptime_seconds", { help: "Self-host process uptime in seconds.", type: "gauge" }], ["gittensory_backup_acknowledged", { help: "1 when SQLite backup is acknowledged or Postgres is in use; 0 when the boot backup advisory would fire.", type: "gauge" }], ["gittensory_http_requests_total", { help: "HTTP app requests by response status class.", type: "counter" }], diff --git a/src/server.ts b/src/server.ts index 7d707e515c..bb25698c64 100644 --- a/src/server.ts +++ b/src/server.ts @@ -51,6 +51,7 @@ import { sqliteBackupAdvisory, type ReadinessProbe, } from "./selfhost/health"; +import { clockSkewSecondsSample } from "./selfhost/clock-skew"; import { gauge, gaugeVector, incr, observe, renderMetrics, setSelfHostedMetricsMode } from "./selfhost/metrics"; import { runSelfHostMigrations } from "./selfhost/migrate"; import { createPgAdapter, tuneGithubRateLimitObservationsAutovacuum } from "./selfhost/pg-adapter"; @@ -671,6 +672,7 @@ async function main(): Promise { // -1 (not 0) when unavailable -- a genuine idle host reads 0, so a dashboard can tell "known idle" apart // from "no signal on this platform" (see host-pressure.ts). gauge("gittensory_host_load_avg1_per_core", async () => (await maintenancePressure()).hostLoadAvg1PerCore ?? -1); + gauge("gittensory_clock_skew_seconds", () => clockSkewSecondsSample()); // Backlog-vs-fresh-intake fairness lanes (#selfhost-lane-observability, see queue-fairness.ts): the SAME // `foreground_lane` classification the claim-time fairness mechanism itself consults, so an operator can see // whether a stuck-looking queue is actually a real, unresolved PR-review backlog (high backlog-convergence diff --git a/test/unit/clock-skew.test.ts b/test/unit/clock-skew.test.ts new file mode 100644 index 0000000000..b3ad6ff2a5 --- /dev/null +++ b/test/unit/clock-skew.test.ts @@ -0,0 +1,54 @@ +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; +import { clockSkewSecondsSample, recordClockSkewFromResponse, resetClockSkewForTest } from "../../src/selfhost/clock-skew"; + +beforeEach(() => resetClockSkewForTest()); +afterEach(() => vi.useRealTimers()); + +describe("clock-skew", () => { + it("defaults to 0 before any sample is recorded", () => { + expect(clockSkewSecondsSample()).toBe(0); + }); + + it("records a positive skew when the local clock is ahead of the response's Date header", () => { + vi.useFakeTimers(); + vi.setSystemTime(new Date("2026-07-06T12:05:00.000Z")); + const response = new Response(null, { headers: { date: "Mon, 06 Jul 2026 12:00:00 GMT" } }); + recordClockSkewFromResponse(response); + expect(clockSkewSecondsSample()).toBe(300); // 5 minutes ahead + }); + + it("records a negative skew when the local clock is behind the response's Date header", () => { + vi.useFakeTimers(); + vi.setSystemTime(new Date("2026-07-06T12:00:00.000Z")); + const response = new Response(null, { headers: { date: "Mon, 06 Jul 2026 12:02:00 GMT" } }); + recordClockSkewFromResponse(response); + expect(clockSkewSecondsSample()).toBe(-120); // 2 minutes behind + }); + + it("ignores a response with no Date header, leaving the prior sample in place", () => { + vi.useFakeTimers(); + vi.setSystemTime(new Date("2026-07-06T12:05:00.000Z")); + recordClockSkewFromResponse(new Response(null, { headers: { date: "Mon, 06 Jul 2026 12:00:00 GMT" } })); + expect(clockSkewSecondsSample()).toBe(300); + + recordClockSkewFromResponse(new Response(null)); + expect(clockSkewSecondsSample()).toBe(300); // unchanged, not reset to 0 + }); + + it("ignores an unparseable Date header, leaving the prior sample in place", () => { + vi.useFakeTimers(); + vi.setSystemTime(new Date("2026-07-06T12:05:00.000Z")); + recordClockSkewFromResponse(new Response(null, { headers: { date: "Mon, 06 Jul 2026 12:00:00 GMT" } })); + expect(clockSkewSecondsSample()).toBe(300); + + recordClockSkewFromResponse(new Response(null, { headers: { date: "not-a-date" } })); + expect(clockSkewSecondsSample()).toBe(300); // unchanged, not reset to 0 + }); + + it("resetClockSkewForTest restores the sample to 0", () => { + recordClockSkewFromResponse(new Response(null, { headers: { date: new Date(Date.now() - 60_000).toUTCString() } })); + expect(clockSkewSecondsSample()).not.toBe(0); + resetClockSkewForTest(); + expect(clockSkewSecondsSample()).toBe(0); + }); +}); diff --git a/test/unit/github-app.test.ts b/test/unit/github-app.test.ts index 60d9b6ceb0..520595941d 100644 --- a/test/unit/github-app.test.ts +++ b/test/unit/github-app.test.ts @@ -27,8 +27,12 @@ import { import type { Advisory } from "../../src/types"; import { createTestEnv } from "../helpers/d1"; import { getInstallation, upsertInstallation } from "../../src/db/repositories"; +import { clockSkewSecondsSample, resetClockSkewForTest } from "../../src/selfhost/clock-skew"; -beforeEach(() => clearInstallationTokenCacheForTest()); +beforeEach(() => { + clearInstallationTokenCacheForTest(); + resetClockSkewForTest(); +}); describe("GitHub check runs", () => { afterEach(() => { @@ -193,6 +197,25 @@ describe("GitHub check runs", () => { expect(mints).toBe(1); }); + it("(#3811) samples clock skew from the installation-token mint response's Date header", async () => { + const privateKey = await generatePrivateKeyPem(); + vi.useFakeTimers(); + vi.setSystemTime(new Date("2026-07-06T12:05:00.000Z")); // 5 minutes ahead of the stubbed response's Date + vi.stubGlobal("fetch", async (input: RequestInfo | URL) => { + const url = input.toString(); + if (url.includes("/access_tokens")) { + return new Response(JSON.stringify({ token: "installation-token", expires_at: new Date(Date.now() + 60 * 60_000).toISOString() }), { + headers: { "content-type": "application/json", date: "Mon, 06 Jul 2026 12:00:00 GMT" }, + }); + } + return new Response("not found", { status: 404 }); + }); + + await createInstallationToken(createTestEnv({ GITHUB_APP_PRIVATE_KEY: privateKey }), 4242); + expect(clockSkewSecondsSample()).toBe(300); + vi.useRealTimers(); + }); + it("REGRESSION (#2453): evicts a rejected App JWT and retries the mint once instead of failing outright", async () => { // Unlike installation tokens (evicted + retried once by withInstallationTokenRetry), the App JWT itself had // no eviction path before #2453: mintInstallationToken threw straight through on the first non-ok response,