diff --git a/apps/bot/src/delivery-policy.test.ts b/apps/bot/src/delivery-policy.test.ts new file mode 100644 index 0000000..eac9cad --- /dev/null +++ b/apps/bot/src/delivery-policy.test.ts @@ -0,0 +1,62 @@ +import { describe, expect, it } from "vitest"; + +import { + isExhausted, + isTerminalDmCode, + MAX_DELIVERY_ATTEMPTS, + nextAttemptAt, + retryDelayMs, +} from "./delivery-policy.js"; + +describe("terminal DM codes", () => { + it("treats both 'cannot DM this user' codes as permanent", () => { + expect(isTerminalDmCode(50007)).toBe(true); + // The one that was missing and caused rows to be retried forever. + expect(isTerminalDmCode(50278)).toBe(true); + }); + + it("accepts the string form discord.js sometimes hands back", () => { + expect(isTerminalDmCode("50278")).toBe(true); + }); + + it("leaves genuinely transient failures retryable", () => { + expect(isTerminalDmCode(500)).toBe(false); + expect(isTerminalDmCode(undefined)).toBe(false); + expect(isTerminalDmCode(null)).toBe(false); + }); +}); + +describe("backoff", () => { + it("grows with each failure", () => { + expect(retryDelayMs(0)).toBe(30_000); + expect(retryDelayMs(1)).toBe(60_000); + expect(retryDelayMs(2)).toBe(120_000); + }); + + it("is capped so a stuck row cannot drift years into the future", () => { + expect(retryDelayMs(50)).toBe(30 * 60_000); + }); + + it("never returns a negative or NaN delay for junk input", () => { + expect(retryDelayMs(-5)).toBe(30_000); + expect(retryDelayMs(1.7)).toBe(60_000); + }); + + it("offsets from the given clock", () => { + const now = new Date("2026-08-18T00:00:00.000Z"); + expect(nextAttemptAt(0, now).toISOString()).toBe("2026-08-18T00:00:30.000Z"); + }); +}); + +describe("exhaustion", () => { + it("retires a row only after the last attempt", () => { + expect(isExhausted(MAX_DELIVERY_ATTEMPTS - 1)).toBe(false); + expect(isExhausted(MAX_DELIVERY_ATTEMPTS)).toBe(true); + }); + + it("keeps the whole retry window under a few hours", () => { + let total = 0; + for (let i = 0; i < MAX_DELIVERY_ATTEMPTS; i++) total += retryDelayMs(i); + expect(total).toBeLessThan(3 * 60 * 60_000); + }); +}); diff --git a/apps/bot/src/delivery-policy.ts b/apps/bot/src/delivery-policy.ts new file mode 100644 index 0000000..d967bf7 --- /dev/null +++ b/apps/bot/src/delivery-policy.ts @@ -0,0 +1,48 @@ +// When to stop trying to deliver an outbox row. +// +// Kept free of discord.js and Prisma so the policy itself is unit-testable: +// getting this wrong is not loud. A row that can never succeed and is never +// retired simply stays at the head of the queue, and since the poller takes a +// fixed batch ordered by age, enough of them starve every newer notification. + +/** + * Discord error codes that mean "this DM will never arrive", as opposed to + * "not right now". Both are 403s and both look alike in a log: + * + * 50007 Cannot send messages to this user (DMs closed) + * 50278 Cannot send messages to this user due to having no mutual guilds + * + * 50278 was missing here until 2026-08-18, so applicants who left the guild + * left behind a row that was retried every 15 seconds indefinitely. + */ +export const TERMINAL_DM_CODES = [50007, 50278] as const; + +export function isTerminalDmCode(code: unknown): boolean { + return (TERMINAL_DM_CODES as readonly number[]).includes(Number(code)); +} + +/** + * Give up after this many failed attempts. The backoff below spreads them over + * roughly two hours, which outlasts a normal Discord incident without letting a + * permanently broken row live forever. + */ +export const MAX_DELIVERY_ATTEMPTS = 8; + +const BASE_DELAY_MS = 30_000; +const MAX_DELAY_MS = 30 * 60_000; + +/** Exponential backoff, capped. `attempts` is the number of failures so far. */ +export function retryDelayMs(attempts: number): number { + const n = Math.min(Math.max(0, Math.trunc(attempts)), 20); + return Math.min(MAX_DELAY_MS, BASE_DELAY_MS * 2 ** n); +} + +/** When a row that just failed for the `attempts`-th time may be tried again. */ +export function nextAttemptAt(attempts: number, now: Date): Date { + return new Date(now.getTime() + retryDelayMs(attempts)); +} + +/** True once a row has burned through its attempts and should be retired. */ +export function isExhausted(attempts: number): boolean { + return attempts >= MAX_DELIVERY_ATTEMPTS; +} diff --git a/apps/bot/src/notifications.ts b/apps/bot/src/notifications.ts index 0faecea..a96f2f2 100644 --- a/apps/bot/src/notifications.ts +++ b/apps/bot/src/notifications.ts @@ -17,6 +17,7 @@ import { } from "discord.js"; import { config } from "./config.js"; +import { isExhausted, isTerminalDmCode, nextAttemptAt } from "./delivery-policy.js"; import { fmt, guildStrings } from "./guild-i18n.js"; import { dmStrings, localizedStatus } from "./i18n.js"; import { postBranded } from "./posting.js"; @@ -27,19 +28,32 @@ const MSK_GREEN = 0x00e676; const LOG_RED = 0xff5252; const LOG_BLURPLE = 0x5865f2; const BATCH = 25; -/** Discord error code: "Cannot send messages to this user" (DMs closed / no mutual guild). */ -const CANNOT_DM = 50007; /** Permanent channel errors: Unknown Channel / Missing Access / Missing Permissions. */ const CHANNEL_GONE = [10003, 50001, 50013]; /** Guards against overlapping ticks if a batch outlives the poll interval. */ let running = false; +/** + * What to do with a row after an attempt. `true` retires it — delivered, or + * permanently undeliverable, which for an outbox amounts to the same thing. + * Anything else is transient and carries the reason, so a row that keeps + * failing can be diagnosed from the table instead of from a log that has + * long since rotated away. + */ +type Outcome = true | { retry: string }; + +const retry = (err: unknown): Outcome => ({ + retry: err instanceof Error ? err.message.slice(0, 500) : String(err).slice(0, 500), +}); + type PendingRow = { id: string; type: string; payload: unknown; guildId: string | null; + /** Failed deliveries so far. Drives the backoff and the give-up threshold. */ + attempts: number; user: { discordId: string; locale: string } | null; }; @@ -82,7 +96,7 @@ function buildMessage( * channel. Drops (marks read) when there's no guild, no configured channel, or * the channel is permanently unreachable; retries on transient errors. */ -async function deliverReview(client: Client, row: PendingRow): Promise { +async function deliverReview(client: Client, row: PendingRow): Promise { if (!row.guildId) return true; const payload = row.payload as Partial; if (!payload?.submissionId) return true; @@ -137,7 +151,7 @@ async function deliverReview(client: Client, row: PendingRow): Promise return true; } console.error(`[bot] failed to post review embed to ${channelId}:`, err); - return false; + return retry(err); } } @@ -166,7 +180,7 @@ const LOG_PRESENTATION: Record { +async function deliverLog(client: Client, row: PendingRow): Promise { if (!row.guildId) return true; const payload = row.payload as Partial; if (!payload?.action) return true; @@ -236,7 +250,7 @@ async function deliverLog(client: Client, row: PendingRow): Promise { return true; } console.error(`[bot] failed to post log entry to ${channelId}:`, err); - return false; + return retry(err); } } @@ -245,7 +259,7 @@ async function deliverLog(client: Client, row: PendingRow): Promise { * read — on success, when there's no recipient, or on a permanent "can't DM" * error. Returns false for transient failures so the next tick retries. */ -async function deliverOne(client: Client, row: PendingRow): Promise { +async function deliverOne(client: Client, row: PendingRow): Promise { if (row.type === "submission_review") return deliverReview(client, row); if (row.type === "log") return deliverLog(client, row); @@ -298,12 +312,14 @@ async function deliverOne(client: Client, row: PendingRow): Promise { await user.send(message); return true; } catch (err) { - if (err instanceof DiscordAPIError && Number(err.code) === CANNOT_DM) { - console.warn(`[bot] can't DM user ${discordId} — dropping notification ${row.id}.`); + if (err instanceof DiscordAPIError && isTerminalDmCode(err.code)) { + console.warn( + `[bot] can't DM user ${discordId} (${err.code}) — dropping notification ${row.id}.`, + ); return true; } console.error(`[bot] failed to DM user ${discordId}:`, err); - return false; + return retry(err); } } @@ -312,9 +328,11 @@ export async function deliverPendingNotifications(client: Client): Promise if (running) return; running = true; try { + const now = new Date(); const pending = (await prisma.notification.findMany({ where: { readAt: null, + nextAttemptAt: { lte: now }, type: { in: ["status_change", "message", "submission_review", "log"] }, }, orderBy: { createdAt: "asc" }, @@ -324,6 +342,7 @@ export async function deliverPendingNotifications(client: Client): Promise type: true, payload: true, guildId: true, + attempts: true, user: { select: { discordId: true, locale: true } }, }, })) as PendingRow[]; @@ -331,11 +350,21 @@ export async function deliverPendingNotifications(client: Client): Promise // Deliver each row independently (one failure must not abort the batch), // collect the ones to retire, then mark them all read in a single write. const deliveredIds: string[] = []; + const failures: { id: string; attempts: number; error: string }[] = []; for (const row of pending) { try { - if (await deliverOne(client, row)) deliveredIds.push(row.id); + const outcome = await deliverOne(client, row); + if (outcome === true) deliveredIds.push(row.id); + else failures.push({ id: row.id, attempts: row.attempts + 1, error: outcome.retry }); } catch (err) { + // A throw escaping deliverOne is transient by definition: the row never + // reached a verdict, so it must not be retired on the strength of it. console.error(`[bot] delivery failed for notification ${row.id}:`, err); + failures.push({ + id: row.id, + attempts: row.attempts + 1, + error: err instanceof Error ? err.message.slice(0, 500) : String(err).slice(0, 500), + }); } } if (deliveredIds.length > 0) { @@ -344,6 +373,27 @@ export async function deliverPendingNotifications(client: Client): Promise data: { readAt: new Date() }, }); } + // Record each failure with its own backoff, and retire the ones that have + // run out of attempts. Without this a row that can never succeed sits at + // the head of the queue forever and, once enough of them pile up, starves + // every newer notification out of the batch. + for (const f of failures) { + const done = isExhausted(f.attempts); + if (done) { + console.warn( + `[bot] giving up on notification ${f.id} after ${f.attempts} attempts: ${f.error}`, + ); + } + await prisma.notification.update({ + where: { id: f.id }, + data: { + attempts: f.attempts, + lastError: f.error, + nextAttemptAt: nextAttemptAt(f.attempts, new Date()), + ...(done ? { readAt: new Date() } : {}), + }, + }); + } } catch (err) { console.error("[bot] notification delivery error:", err); } finally { diff --git a/packages/db/prisma/migrations/20260818003000_notification_retry_bounds/migration.sql b/packages/db/prisma/migrations/20260818003000_notification_retry_bounds/migration.sql new file mode 100644 index 0000000..e394024 --- /dev/null +++ b/packages/db/prisma/migrations/20260818003000_notification_retry_bounds/migration.sql @@ -0,0 +1,25 @@ +-- Bound the outbox retry loop. +-- +-- Until now a notification that failed to deliver was simply left unread and +-- picked up again on the next 15s tick, forever. Discord returns 50278 ("no +-- mutual guilds") for applicants who left the server, and the bot only treated +-- 50007 as permanent, so those rows never retired. Because the poller takes a +-- fixed batch ordered by age, enough of them at the head of the queue would +-- have starved every newer notification. +ALTER TABLE "notifications" + ADD COLUMN "attempts" INTEGER NOT NULL DEFAULT 0, + ADD COLUMN "last_error" TEXT, + ADD COLUMN "next_attempt_at" TIMESTAMP(3) NOT NULL DEFAULT CURRENT_TIMESTAMP; + +-- The poller now scans: +-- WHERE read_at IS NULL AND next_attempt_at <= now() ORDER BY created_at ASC +-- so the pending partial index gains the new column. It supersedes +-- notifications_pending_idx from 20260620180000, which is dropped rather than +-- kept alongside: two partial indexes over the same rows would both have to be +-- maintained on every insert into a hot table. (Partial indexes aren't +-- expressible in the Prisma schema, hence the hand-written migration.) +CREATE INDEX IF NOT EXISTS "notifications_due_idx" + ON "notifications" ("next_attempt_at", "created_at") + WHERE "read_at" IS NULL; + +DROP INDEX IF EXISTS "notifications_pending_idx"; diff --git a/packages/db/prisma/schema.prisma b/packages/db/prisma/schema.prisma index 34f7b80..32d58b3 100644 --- a/packages/db/prisma/schema.prisma +++ b/packages/db/prisma/schema.prisma @@ -331,6 +331,13 @@ model Notification { readAt DateTime? @map("read_at") createdAt DateTime @default(now()) @map("created_at") + // Retry bounds, same shape as WebhookDelivery. `readAt` marks a row as + // retired, which covers both "delivered" and "will never be deliverable"; + // `lastError` is what tells the two apart afterwards. + attempts Int @default(0) + lastError String? @map("last_error") + nextAttemptAt DateTime @default(now()) @map("next_attempt_at") + user User? @relation(fields: [userId], references: [id], onDelete: Cascade) guild Guild? @relation(fields: [guildId], references: [id], onDelete: Cascade)