From d9d9b8180395128ad4b323dc26ab4dd5813ce302 Mon Sep 17 00:00:00 2001 From: JSONbored <49853598+JSONbored@users.noreply.github.com> Date: Sat, 27 Jun 2026 16:31:59 -0700 Subject: [PATCH] fix(orb): make self-host webhook-delivery loss visible to operators MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The self-host Sentry forwarder only forwards level:error/fatal, so delivery loss was silent or warn-only — the failure a self-host operator most needs to see (container looks alive, reviews nothing): - retryFailedRelays: a relay event abandoned after its TTL/retry budget logged at level:warn -> escalate to level:error (orb_relay_events_dropped). - pruneRelayPending: a pull-mode (tailnet) container offline past the 24h window lost queued webhooks with NO log -> add orb_relay_pending_dropped at level:error (distinct event from the push-path drop). - server.ts boot: registerOrbRelayTarget 'failed' logged at info + a swallowed .catch -> 'failed' now logs level:error and the catch routes to captureError. Consolidates the self-host delivery-integrity cluster from the 2026-06-27 audit. --- src/orb/relay.ts | 7 ++++++- src/server.ts | 13 ++++++++----- test/integration/orb-relay.test.ts | 16 ++++++++++------ 3 files changed, 24 insertions(+), 12 deletions(-) diff --git a/src/orb/relay.ts b/src/orb/relay.ts index 519663378a..6487cc2343 100644 --- a/src/orb/relay.ts +++ b/src/orb/relay.ts @@ -155,6 +155,11 @@ async function pruneRelayPending(env: Env): Promise { .prepare("DELETE FROM orb_relay_pending WHERE created_at < datetime('now', '-' || ? || ' hours')") .bind(RELAY_PENDING_TTL_HOURS) .run(); + // Make pull-mode loss VISIBLE too (parity with the push-path drop): a pruned row is a webhook a long-down tailnet + // container never drained — emit an alertable error-level log (distinct event name) so it leaves a Sentry trace. + if (pruned.meta.changes > 0) { + console.error(JSON.stringify({ level: "error", event: "orb_relay_pending_dropped", count: pruned.meta.changes })); + } return pruned.meta.changes; } @@ -244,7 +249,7 @@ export async function retryFailedRelays(env: Env, opts?: { fetchImpl?: typeof fe // retries exhausted) — e.g. a container down for over an hour. Emit an alertable structured log so the loss // leaves a trace instead of vanishing silently. if (pruned.meta.changes > 0) { - console.warn(JSON.stringify({ level: "warn", event: "orb_relay_events_dropped", count: pruned.meta.changes })); + console.error(JSON.stringify({ level: "error", event: "orb_relay_events_dropped", count: pruned.meta.changes })); } const { results } = await env.DB .prepare( diff --git a/src/server.ts b/src/server.ts index 8c1f363ec0..eed679f2ce 100644 --- a/src/server.ts +++ b/src/server.ts @@ -743,12 +743,15 @@ async function main(): Promise { PUBLIC_API_ORIGIN: process.env.PUBLIC_API_ORIGIN, }) .then((r) => { - if (r !== "skipped") - console.log( - JSON.stringify({ event: "selfhost_orb_relay_register", result: r }), - ); + if (r === "registered") { + console.log(JSON.stringify({ event: "selfhost_orb_relay_register", result: r })); + } else if (r === "failed") { + // A failed registration means the central Orb won't forward this install's webhooks here — the container + // looks alive but reviews NOTHING. Surface at error level so the operator sees a deaf container. + console.error(JSON.stringify({ level: "error", event: "selfhost_orb_relay_register_failed" })); + } }) - .catch(() => {}); + .catch((error) => captureError(error, { kind: "orb_relay_register" })); // Graceful shutdown: stop accepting HTTP, let the queue finish, close the backend. let shuttingDown = false; diff --git a/test/integration/orb-relay.test.ts b/test/integration/orb-relay.test.ts index 23f9f63ece..65b4fa6376 100644 --- a/test/integration/orb-relay.test.ts +++ b/test/integration/orb-relay.test.ts @@ -344,17 +344,17 @@ describe("retryFailedRelays", () => { expect(untouched?.n).toBe(5); }); - it("PRUNES rows that have exhausted their attempt budget (attempts >= 5) and logs the drop (#5)", async () => { + it("PRUNES rows that have exhausted their attempt budget (attempts >= 5) and logs the drop at error level (#5)", async () => { const e = brokeredEnv(); - const warn = vi.spyOn(console, "warn").mockImplementation(() => undefined); + const errLog = vi.spyOn(console, "error").mockImplementation(() => undefined); // Manually insert a row at the attempt ceiling. await db(e).prepare("INSERT INTO orb_relay_failures (delivery_id, event_name, installation_id, raw_body, attempts) VALUES (?, ?, ?, ?, ?)").bind("exhausted-1", "pull_request", 9300, "{}", 5).run(); await retryFailedRelays(e); const row = await db(e).prepare("SELECT delivery_id FROM orb_relay_failures WHERE delivery_id='exhausted-1'").first(); expect(row ?? null).toBeNull(); // pruned on the DELETE pass before the SELECT - // The drop is no longer silent — an alertable structured log records the lost event count. - expect(warn.mock.calls.some(([line]) => String(line).includes("orb_relay_events_dropped"))).toBe(true); - warn.mockRestore(); + // The drop is no longer silent OR warn-only — an alertable level:error log reaches the Sentry forwarder. + expect(errLog.mock.calls.some(([line]) => String(line).includes("orb_relay_events_dropped") && String(line).includes('"level":"error"'))).toBe(true); + errLog.mockRestore(); }); it("PRUNES expired rows (expires_at in the past) without attempting to forward", async () => { @@ -468,14 +468,18 @@ describe("pullRelayPending", () => { expect((await pullRelayPending(e, 9705, { limit: 5 })).length).toBe(5); // a smaller requested limit is honoured }); - it("PRUNES rows older than the TTL before returning the batch", async () => { + it("PRUNES rows older than the TTL before returning the batch, and logs the drop at error level", async () => { const e = brokeredEnv(); + const errLog = vi.spyOn(console, "error").mockImplementation(() => undefined); await db(e).prepare("INSERT INTO orb_relay_pending (delivery_id, installation_id, event_name, raw_body, created_at) VALUES (?, ?, ?, ?, datetime('now', '-25 hours'))").bind("stale-1", 9706, "pull_request", "{}").run(); await enqueueRelayPending(e, { deliveryId: "fresh-1", installationId: 9706, eventName: "pull_request", rawBody: "{}" }); const events = await pullRelayPending(e, 9706); expect(events.map((ev) => ev.deliveryId)).toEqual(["fresh-1"]); // the 25h-old row was pruned (TTL 24h) const stale = await db(e).prepare("SELECT delivery_id FROM orb_relay_pending WHERE delivery_id='stale-1'").first(); expect(stale ?? null).toBeNull(); + // Pull-mode loss is now traced for the operator at error level (parity with the push-path drop). + expect(errLog.mock.calls.some(([line]) => String(line).includes("orb_relay_pending_dropped") && String(line).includes('"level":"error"'))).toBe(true); + errLog.mockRestore(); }); });