Public: anyone can read this; the crew can change it.

A webhook that fails three deliveries in a row shows one line in its repository writers' feed #10170

Merged opened this

Check · Review · Land · Live done — Landed and live in production.

Merged

mason/forge:mason/10161-a-webhook-that-fails-three-deliveries-in → main 6 commits fork 1 thread · 1 unresolved

  • Merged. mason/10161-a-webhook-that-fails-three-deliveries-in was merged into main as 9ca62df.

Review

Sign in to review this change.
9 files changed +339 −13
docs/features/webhook-failing.md added +12
@@ -0,0 +1,12 @@
1 # A failing webhook is said once
2
3 When a webhook's third delivery in a row ends `failed`, one `webhook.failing`
4 event goes on the bus (`src/core/webhook_streak.ts`, called from the delivery
5 worker in `src/core/webhooks.ts`). Once per streak: a success ends it, and a
6 fourth failure or a redelivery that fails again adds nothing.
7
8 Writers of the repository see one line in their feed — "Webhook to
9 example.com failed 3 times: answered HTTP 500" — linking to the repository, and naming Settings ›
10 Webhooks, where redeliver and pause are (`webhook-redeliver.md`,
11 `webhook-pause.md`). Readers do not: the event's audience is `writers`
12 (`src/core/event_audience.ts`). It names the host, never the address.
src/core/event_audience.ts +8 −1
@@ -181,6 +181,9 @@ const READER_KINDS: ReadonlySet<string> = new Set([
181181 * `test/event-audience-coverage.test.ts` fails on an emitted kind that is.
182182 */
183183 export function classifiedAudience(kind: string): EventAudience | undefined {
184 // A hook that keeps failing is for those who can act on it: the host and
185 // the reason, never the address (`webhook_streak.ts`).
186 if (kind === "webhook.failing") return "writers";
184187 if (
185188 kind.startsWith("webhook.") ||
186189 kind.startsWith("app.env_") ||
@@ -298,7 +301,11 @@ export function audienceFilter(
298301 const known = writers.get(repoId);
299302 if (known !== undefined) return known;
300303 const repo = getRepoById(db, repoId);
301 const yes = repo !== undefined && canWrite(db, repo, viewer);
304 const yes =
305 repo !== undefined &&
306 viewer !== undefined &&
307 isActive(viewer) &&
308 canWrite(db, repo, viewer);
302309 writers.set(repoId, yes);
303310 return yes;
304311 };
src/core/webhook_streak.ts added +77
@@ -0,0 +1,77 @@
1 /**
2 * A webhook that keeps failing, said once.
3 *
4 * Redeliver and pause exist, but nobody is told to use them. When a hook's
5 * third delivery in a row ends `failed`, one `webhook.failing` event goes on
6 * the bus for the repository's writers: once per streak, not per failure. A
7 * delivery that ends `ok` ends the streak; the next three failures are a new
8 * one. The streak is named by its oldest failed delivery (`since`), so a
9 * redelivery that fails again, or a fourth failure, finds the event already
10 * written and adds nothing.
11 */
12
13 import type { Database } from "bun:sqlite";
14 import type { EventBus } from "./events.ts";
15
16 /** Failed deliveries in a row that make a streak worth saying. */
17 export const STREAK = 3;
18
19 /** The longest reason the event carries. */
20 const REASON_MAX = 200;
21
22 /** The host a hook posts to; the whole address (often a secret) is not for writers. */
23 export function hostOf(url: string): string {
24 try {
25 return new URL(url).hostname;
26 } catch {
27 return "an unreadable address";
28 }
29 }
30
31 /** Call after a delivery of this hook has ended `failed`. */
32 export function noteFailure(
33 db: Database,
34 bus: EventBus,
35 webhookId: string,
36 reason: string,
37 ): void {
38 const hook = db
39 .query<{ repo_id: string; url: string }, [string]>(
40 "SELECT repo_id, url FROM webhook WHERE id = ?1",
41 )
42 .get(webhookId);
43 if (hook === null) return;
44 // The streak is every failure since the newest success.
45 const failed = db
46 .query<{ id: string }, [string]>(
47 `SELECT id FROM webhook_delivery
48 WHERE webhook_id = ?1 AND state = 'failed'
49 AND id > COALESCE((SELECT MAX(id) FROM webhook_delivery
50 WHERE webhook_id = ?1 AND state = 'ok'), '')
51 ORDER BY id`,
52 )
53 .all(webhookId);
54 if (failed.length < STREAK) return;
55 // Its oldest failure names it, however long it grows.
56 const since = failed[0]!.id;
57 const said = db
58 .query(
59 `SELECT 1 FROM event
60 WHERE kind = 'webhook.failing' AND repo_id = ?1
61 AND json_extract(payload, '$.webhookId') = ?2
62 AND json_extract(payload, '$.since') = ?3 LIMIT 1`,
63 )
64 .get(hook.repo_id, webhookId, since);
65 if (said !== null) return;
66 bus.append({
67 kind: "webhook.failing",
68 repoId: hook.repo_id,
69 payload: {
70 webhookId,
71 since,
72 host: hostOf(hook.url),
73 reason: reason.slice(0, REASON_MAX),
74 failures: STREAK,
75 },
76 });
77 }
src/core/webhooks.ts +32 −8
@@ -19,7 +19,8 @@ import {
1919 type OutboundOptions,
2020 } from "../kernel/outbound.ts";
2121 import { err, ok, type Result } from "../kernel/result.ts";
22 import type { ForgeEvent } from "./events.ts";
22 import { EventBus, type ForgeEvent } from "./events.ts";
23 import { noteFailure } from "./webhook_streak.ts";
2324
2425 const MAX_ATTEMPTS = 6;
2526 const DELIVER_TIMEOUT_MS = 10_000;
@@ -167,6 +168,9 @@ export function kindMatches(spec: string, kind: string): boolean {
167168 */
168169 export function enqueueForEvent(db: Database, event: ForgeEvent): number {
169170 if (event.repoId === null) return 0;
171 // The news that a hook is failing is for writers, not for hooks: sent to the
172 // failing one it would be one more doomed delivery in the streak it reports.
173 if (event.kind === "webhook.failing") return 0;
170174 // A hook's URL is somewhere else: nothing about a sealed report goes
171175 // there, not even that it moved (`sealed.ts`).
172176 if (eventSealed(db, event)) return 0;
@@ -300,7 +304,6 @@ interface DueRow {
300304 created_at: string;
301305 }
302306
303 /** Deliver all due pending deliveries. Returns how many were attempted. */
304307 /**
305308 * How long a claimed delivery is its sender's before another may try it:
306309 * well past the longest one send may take, so a claim never lapses while
@@ -309,11 +312,18 @@ interface DueRow {
309312 export const CLAIM_MS = 60_000;
310313 export { DELIVER_TIMEOUT_MS };
311314
315 /**
316 * Deliver all due pending deliveries. Returns how many were attempted.
317 * `bus` is optional only for one-shot callers (tests, scripts) with no live
318 * listeners: it then writes a bus of its own, which stores the event and wakes
319 * no one. The worker (`runDelivery`) always passes the forge's bus.
320 */
312321 export async function deliverDue(
313322 db: Database,
314323 log: Log,
315324 now = new Date(),
316325 outbound: OutboundOptions = {},
326 bus: EventBus = new EventBus(db),
317327 ): Promise<number> {
318328 const nowIso = now.toISOString();
319329 const events = db
@@ -365,7 +375,7 @@ export async function deliverDue(
365375 );
366376 if (claimed.changes !== 1) continue;
367377 try {
368 await deliverOne(db, log, row, now, outbound);
378 await deliverOne(db, log, row, now, outbound, bus);
369379 } catch (error) {
370380 // One malformed delivery must not take the batch with it. Without
371381 // this, a single unsendable row stops every delivery behind it — and
@@ -377,7 +387,7 @@ export async function deliverDue(
377387 delivery: row.id,
378388 error: String(error),
379389 });
380 backOff(db, log, row, 0, now);
390 backOff(db, log, row, 0, now, bus);
381391 }
382392 }
383393 return due.length;
@@ -394,6 +404,7 @@ async function deliverOne(
394404 row: DueRow,
395405 now: Date,
396406 outbound: OutboundOptions,
407 bus: EventBus,
397408 ): Promise<void> {
398409 // A ping's body is its payload as it stands: { kind, repo, hook, at }.
399410 const body =
@@ -440,6 +451,7 @@ async function deliverOne(
440451 db.query(
441452 `UPDATE ${tableOf(row)} SET state = 'failed', attempts = ?1, last_status = NULL, last_error = ?2 WHERE id = ?3`,
442453 ).run(attempt, error.message, row.id);
454 if (!row.ping) noteFailure(db, bus, row.webhook_id, error.message);
443455 return;
444456 }
445457 log.warn("webhook delivery error", {
@@ -455,7 +467,7 @@ async function deliverOne(
455467 ).run(attempt, status, row.id);
456468 return;
457469 }
458 backOff(db, log, row, status, now);
470 backOff(db, log, row, status, now, bus);
459471 }
460472
461473 /** Record an attempt and schedule the next one — or give up. */
@@ -465,6 +477,7 @@ function backOff(
465477 row: DueRow,
466478 status: number,
467479 now: Date,
480 bus: EventBus,
468481 ): void {
469482 const attempt = row.attempts + 1;
470483 if (attempt >= MAX_ATTEMPTS) {
@@ -476,6 +489,13 @@ function backOff(
476489 attempts: attempt,
477490 status,
478491 });
492 if (!row.ping)
493 noteFailure(
494 db,
495 bus,
496 row.webhook_id,
497 status === 0 ? "no response" : `answered HTTP ${status}`,
498 );
479499 return;
480500 }
481501 // Exponential backoff: ~10s, 40s, 90s, … capped implicitly by attempt count.
@@ -591,11 +611,15 @@ const delivering = new WeakSet<Database>();
591611 /** For tests and for anyone who wants to know why nothing is being sent. */
592612 export const deliveryBusy = (db: Database): boolean => delivering.has(db);
593613
594 /** A never-throwing wrapper for the worker loop's fire-and-forget calls. */
595 export function runDelivery(db: Database, log: Log): void {
614 /**
615 * A never-throwing wrapper for the worker loop's fire-and-forget calls. The
616 * bus is required: it is the forge's own, so the `webhook.failing` event
617 * wakes live streams and not only the outbox.
618 */
619 export function runDelivery(db: Database, log: Log, bus: EventBus): void {
596620 if (delivering.has(db)) return;
597621 delivering.add(db);
598 deliverDue(db, log)
622 deliverDue(db, log, new Date(), {}, bus)
599623 .catch((error) => {
600624 // The worker must survive any delivery batch failing — a thrown rejection
601625 // here would take the process down (a lesson paid for elsewhere).
src/design/activity.ts +1
@@ -189,6 +189,7 @@ const WORDS: Record<string, string> = {
189189 "webhook.deleted": "removed a webhook",
190190 "webhook.paused": "paused a webhook",
191191 "webhook.resumed": "resumed a webhook",
192 "webhook.failing": "had a webhook fail three deliveries in a row",
192193 "origin.connected": "connected an origin",
193194 "origin.disconnected": "disconnected an origin",
194195 "origin.needs_reauth": "needs to reconnect an origin",
src/feed/items.ts +19
@@ -731,6 +731,25 @@ function fromEvent(
731731 ? `#${String(number)} now waits for #${String(p["blockedBy"])}`
732732 : `#${String(number)} no longer waits for #${String(p["blockedBy"])}`,
733733 };
734 // A hook that failed three deliveries in a row: writers only (`webhook_streak.ts`).
735 case "webhook.failing": {

The link target /settings/hooks is admin-only, so a writer who is not an admin gets a refusal. Link somewhere the writer can open, or say who must act. Also add a test that renders this line to HTML and shows the reason is escaped.

736 const host = typeof p["host"] === "string" ? p["host"] : "a webhook";
737 const reason = typeof p["reason"] === "string" ? p["reason"] : "";
738 const failures = typeof p["failures"] === "number" ? p["failures"] : 3;
739 const what = clip(
740 `Webhook to ${host} failed ${failures} times${reason === "" ? "" : `: ${reason}`}`,
741 300,
742 );
743 // Settings › Webhooks is for admins, and a writer need not be one: the
744 // line links to the repository and says who can redeliver or pause.
745 return {
746 ...common,
747 kind: "map",
748 link: base(repo),
749 what: `${what} (a repository admin can redeliver or pause it in Settings › Webhooks)`,
750 urgency: 3,
751 };
752 }
734753 case "crew.governed":
735754 return {
736755 ...common,
src/main.ts +2 −2
@@ -583,11 +583,11 @@ const notifier = startNotifier(app, { forgeUrl });
583583 // Expired sessions and run tokens ride the same tick: cheap DELETEs, never
584584 // worth a worker.
585585 const deliveryTimer = setInterval(() => {
586 runDelivery(app.db, app.log);
586 runDelivery(app.db, app.log, app.bus);
587587 pruneSessions(app.db);
588588 pruneTokens(app.db);
589589 }, 5_000);
590 runDelivery(app.db, app.log); // sweep anything queued while we were down
590 runDelivery(app.db, app.log, app.bus); // sweep anything queued while we were down
591591 pruneSessions(app.db);
592592 pruneTokens(app.db);
593593
test/agents.test.ts +2 −2
@@ -734,7 +734,7 @@ describe("backpressure", () => {
734734 }
735735
736736 expect(deliveryBusy(app.db)).toBe(false);
737 runDelivery(app.db, app.log);
737 runDelivery(app.db, app.log, app.bus);
738738 expect(deliveryBusy(app.db)).toBe(true);
739739 // Every tick that lands while a batch is in flight is a no-op, which is
740740 // what keeps a slow endpoint from being attempted twice per delivery.
@@ -744,7 +744,7 @@ describe("backpressure", () => {
744744 []
745745 >("SELECT COALESCE(SUM(attempts), 0) AS n FROM webhook_delivery")
746746 .get()!.n;
747 for (let i = 0; i < 10; i++) runDelivery(app.db, app.log);
747 for (let i = 0; i < 10; i++) runDelivery(app.db, app.log, app.bus);
748748 expect(attemptsBefore).toBe(0);
749749
750750 const deadline = Date.now() + 15_000;
test/webhook-failing.test.ts added +186
@@ -0,0 +1,186 @@
1 /**
2 * A hook that fails three deliveries in a row is said once, to the people who
3 * can write the repository: one `webhook.failing` per streak, ended by a
4 * success, never shown to readers, and never trusted as markup.
5 */
6 import { afterAll, beforeAll, describe, expect, test } from "bun:test";
7 import { mkdtemp, rm } from "node:fs/promises";
8 import { tmpdir } from "node:os";
9 import { join } from "node:path";
10 import { createApp, type App } from "../src/app.ts";
11 import { createRepo } from "../src/actions/repos.ts";
12 import { audienceFilter } from "../src/core/event_audience.ts";
13 import { listEvents } from "../src/core/events.ts";
14 import type { Repo } from "../src/core/repos.ts";
15 import { createUser, type User } from "../src/core/users.ts";
16 import { id } from "../src/kernel/id.ts";
17 import { createWebhook, deliverDue, enqueueForEvent } from "../src/core/webhooks.ts";
18 import { noteFailure } from "../src/core/webhook_streak.ts";
19 import { readFeed } from "../src/feed/feed.ts";
20 import { feedCard } from "../src/web/studio/feed.ts";
21 import { getUserById } from "../src/core/users.ts";
22 import { canWrite, getRepoById } from "../src/core/repos.ts";
23 import { candidatesFor } from "../src/feed/items.ts";
24 import { noChips } from "../src/core/feed_chips.ts";
25 import { createLog } from "../src/kernel/log.ts";
26 import { promote } from "./helpers/members.ts";
27
28 describe("a failing webhook", () => {
29 let dir: string;
30 let app: App;
31 let alice: User;
32 let bob: User;
33 let repo: Repo;
34 let hookId: string;
35
36 const mk = async (username: string, first = false) => {
37 const r = await createUser(app.db, {
38 origin: "seed", trusted: true, username, email: `${username}@forge.local`,
39 password: "a-good-passphrase", adminIfFirst: first,
40 });
41 if (!r.ok) throw new Error(r.error);
42 promote(app.db, r.value);
43 return r.value;
44 };
45 const hook = (url: string): string => {
46 const r = createWebhook(app.db, { repoId: repo.id, url, kinds: "*", secret: "s3cret-signing-key-0123456789" });
47 if (!r.ok) throw new Error(r.error);
48 return r.value.webhook.id;
49 };
50 /** A delivery that has ended in `state`, ids in the order made. */
51 const ended = (webhookId: string, state: "ok" | "failed"): string => {
52 const ev = app.bus.append({ kind: "push", repoId: repo.id, actorId: alice.id, payload: {} });
53 // The bus has already queued it for every matching hook; settle that row.
54 app.db.run(
55 `INSERT INTO webhook_delivery (id, webhook_id, event_id, state, attempts) VALUES (?1, ?2, ?3, ?4, 6)
56 ON CONFLICT (webhook_id, event_id) DO UPDATE SET state = ?4, attempts = 6`,
57 [id(), webhookId, ev.id, state],
58 );
59 const did = app.db
60 .query<{ id: string }, [string, string]>("SELECT id FROM webhook_delivery WHERE webhook_id = ?1 AND event_id = ?2")
61 .get(webhookId, ev.id)!.id;
62 return did;
63 };
64 const failing = () => listEvents(app.db, { kinds: ["webhook.failing"] }).filter((e) => e.repoId === repo.id);
65 const fail = (webhookId: string, reason = "answered HTTP 500") => {
66 ended(webhookId, "failed");
67 noteFailure(app.db, app.bus, webhookId, reason);
68 };
69
70 beforeAll(async () => {
71 dir = await mkdtemp(join(tmpdir(), "forge-hookfail-"));
72 app = createApp({ dataDir: dir, port: 0 });
73 alice = await mk("alice", true);
74 bob = await mk("bob");
75 const made = await createRepo(app, alice, { name: "open", visibility: "public" });
76 if (!made.ok) throw new Error(made.error);
77 repo = made.value;
78 hookId = hook("https://hooks.example.test/services/s3cr3t-in-the-path");
79 });
80 afterAll(async () => {
81 app.close();
82 await rm(dir, { recursive: true, force: true });
83 });
84
85 test("says nothing before the third failure, then once, and not again on a fourth", () => {
86 fail(hookId);
87 fail(hookId);
88 expect(failing()).toHaveLength(0);
89 fail(hookId, "answered HTTP 502");
90 expect(failing()).toHaveLength(1);
91 const [event] = failing();
92 expect(event!.payload.host).toBe("hooks.example.test");
93 expect(event!.payload.reason).toBe("answered HTTP 502");
94 expect(JSON.stringify(event!.payload)).not.toContain("s3cr3t");
95 fail(hookId);
96 fail(hookId);
97 expect(failing()).toHaveLength(1);
98 });
99
100 test("the news is not queued as a delivery to any hook", () => {
101 const [event] = failing();
102 const queued = app.db
103 .query<{ n: number }, [string]>("SELECT count(*) n FROM webhook_delivery WHERE event_id = ?1")
104 .get(event!.id)!.n;
105 expect(queued).toBe(0);
106 });
107
108 test("a success ends the streak, and three more failures are a new one", () => {
109 ended(hookId, "ok");
110 fail(hookId);
111 fail(hookId);
112 expect(failing()).toHaveLength(1);
113 fail(hookId);
114 expect(failing()).toHaveLength(2);
115 });
116
117 test("the worker reports a refused delivery's reason on the third", async () => {
118 const other = hook("https://hooks.example.test/other");
119 // A private address is refused at once, with its reason, and never retried.
120 app.db.run("UPDATE webhook SET url = 'http://127.0.0.1/x' WHERE id = ?1", [other]);
121 const before = failing().length;
122 for (let i = 0; i < 3; i++) {
123 const ev = app.bus.append({ kind: "push", repoId: repo.id, actorId: alice.id, payload: {} });
124 enqueueForEvent(app.db, ev);
125 }
126 await deliverDue(app.db, createLog("test"), new Date(), {}, app.bus);
127 const now = failing();
128 expect(now.length).toBe(before + 1);
129 expect(now[0]!.payload.host).toBe("127.0.0.1");
130 expect(String(now[0]!.payload.reason)).toContain("refused");
131 });
132
133 test("writers hear it, readers do not", () => {
134 const event = failing()[0]!;
135 expect(audienceFilter(app.db, alice)(event)).toBe(true);
136 expect(audienceFilter(app.db, bob)(event)).toBe(false);
137 expect(audienceFilter(app.db, undefined)(event)).toBe(false);
138 });
139
140 test("the line links to the repository and says an admin acts; readers get none", () => {
141 const evil = hook("https://hooks.example.test/evil");
142 for (let i = 0; i < 3; i++) fail(evil, '<img src=x onerror="alert(1)">');
143 const lines = candidatesFor(app.db, alice, Date.now(), noChips).filter((c) => c.what.startsWith("Webhook to "));
144 const line = lines.find((c) => c.what.includes("<img"))!;
145 expect(line.what).toStartWith('Webhook to hooks.example.test failed 3 times: <img src=x');
146 expect(line.what).toContain("a repository admin can redeliver or pause it in Settings › Webhooks");
147 expect(line.link).toBe(`/${repo.ownerName}/${repo.name}`);
148 expect(candidatesFor(app.db, bob, Date.now(), noChips).some((c) => c.what.startsWith("Webhook to "))).toBe(false);
149 });
150
151 test("the rendered card escapes the reason and the host", () => {
152 const evil = hook("https://hooks.example.test/evil2");
153 for (let i = 0; i < 3; i++) fail(evil, '<img src=x onerror="alert(1)">');
154 // A host cannot hold markup once parsed, but a payload is only data: forge one.
155 app.bus.append({
156 kind: "webhook.failing",
157 repoId: repo.id,
158 payload: { webhookId: "w", since: "s", host: "<b>evil</b>.test", reason: "<script>x()</script>", failures: 3 },
159 });
160 const cards = readFeed(app.db, alice, { now: Date.now(), limit: 100 })
161 .items.filter((c) => c.what.startsWith("Webhook to "))
162 .map((c) => feedCard(c).text);
163 expect(cards.length).toBeGreaterThanOrEqual(2);
164 const all = cards.join("\n");
165 expect(all).toContain("&lt;img src=x onerror=");
166 expect(all).toContain("&lt;b&gt;evil&lt;/b&gt;.test");
167 expect(all).toContain("&lt;script&gt;");
168 expect(all).not.toContain("<img src=x");
169 expect(all).not.toContain("<b>evil");
170 expect(all).not.toContain("<script>");
171 });
172
173 test("a suspended writer hears nothing", () => {
174 const event = failing()[0]!;
175 expect(audienceFilter(app.db, alice)(event)).toBe(true);
176 app.db.run("UPDATE user SET suspended_at = ?2 WHERE id = ?1", [bob.id, new Date().toISOString()]);
177 // Bob owns a repository of his own with a hook of his own.
178 const suspended = getUserById(app.db, bob.id)!;
179 app.db.run("UPDATE repo SET owner_id = ?2 WHERE id = ?1", [repo.id, bob.id]);
180 const ownerRepo = getRepoById(app.db, repo.id)!;
181 expect(canWrite(app.db, ownerRepo, suspended)).toBe(true);
182 expect(audienceFilter(app.db, suspended)(event)).toBe(false);
183 app.db.run("UPDATE repo SET owner_id = ?2 WHERE id = ?1", [repo.id, alice.id]);
184 app.db.run("UPDATE user SET suspended_at = NULL WHERE id = ?1", [bob.id]);
185 });
186 });

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs