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(); }); });