|
| 1 | +# Plan 004: Surface swallowed write failures on the ingest path (log-or-justify every bare `.catch(() => {})`) |
| 2 | + |
| 3 | +> **Executor instructions**: Follow this plan step by step. Run every |
| 4 | +> verification command and confirm the expected result before moving to the |
| 5 | +> next step. If anything in the "STOP conditions" section occurs, stop and |
| 6 | +> report — do not improvise. When done, update the status row for this plan |
| 7 | +> in `plans/README.md` — unless a reviewer dispatched you and told you they |
| 8 | +> maintain the index. |
| 9 | +> |
| 10 | +> **Drift check (run first)**: `git diff --stat 3238d540..HEAD -- workers/api/src/cron/poll-fetch.ts workers/api/src/routes/search.ts workers/api/src/org-actor.ts` |
| 11 | +> If any in-scope file changed since this plan was written, compare the |
| 12 | +> "Current state" excerpts against the live code before proceeding; on a |
| 13 | +> mismatch, treat it as a STOP condition. Line numbers below are from commit |
| 14 | +> `3238d540` — always re-locate sites with the grep commands given, never by |
| 15 | +> raw line number. |
| 16 | +
|
| 17 | +## Status |
| 18 | + |
| 19 | +- **Priority**: P1 |
| 20 | +- **Effort**: S |
| 21 | +- **Risk**: LOW |
| 22 | +- **Depends on**: none |
| 23 | +- **Category**: bug (observability / silent failure) |
| 24 | +- **Planned at**: commit `3238d540`, 2026-07-02 |
| 25 | + |
| 26 | +## Why this matters |
| 27 | + |
| 28 | +The cron ingest path (`poll-fetch.ts`) persists two kinds of state with |
| 29 | +fire-and-forget D1 writes wrapped in bare `.catch(() => {})`: `fetch_log` rows |
| 30 | +(the observability trail operators use to see whether a source was fetched) and |
| 31 | +`sources` backoff state (`consecutive_errors`, `next_fetch_after`, |
| 32 | +`feed4xxStreak`). When one of those writes fails — a transient D1 error, a |
| 33 | +constraint violation, a bind-count bug — the failure vanishes: the fetch |
| 34 | +attempt is missing from the log, or worse, the backoff never lands and the |
| 35 | +next cron tick re-fetches a rate-limiting origin at full cadence. The same |
| 36 | +pattern hides FTS query errors in `/v1/search` (a failed query is |
| 37 | +indistinguishable from zero results) and malformed JSON from the discovery |
| 38 | +worker in the OrgActor. This plan keeps every site fail-open (no behavior |
| 39 | +change on the happy path) but makes every swallowed error visible in Workers |
| 40 | +Logs. |
| 41 | + |
| 42 | +This plan deliberately does NOT make any of these writes fail-closed — the |
| 43 | +current fail-open semantics are correct for a cron path (one lost log row must |
| 44 | +not abort a fetch cycle). Visibility only. |
| 45 | + |
| 46 | +## Current state |
| 47 | + |
| 48 | +Relevant files: |
| 49 | + |
| 50 | +- `workers/api/src/cron/poll-fetch.ts` — the cron fetch/parse/upsert pipeline; contains 8 bare `.catch(() => {})` sites. |
| 51 | +- `workers/api/src/routes/search.ts` — `/v1/search`; one `.catch(() => [] as RawSearchReleaseRow[])` site that hides FTS errors. |
| 52 | +- `workers/api/src/org-actor.ts` — OrgActor Durable Object (drain dispatch, #1777); one `.catch(() => ({}))` on the discovery response JSON parse. |
| 53 | +- `packages/lib/src/log-event.ts` — the worker logging helper. Worker code MUST log via `logEvent()` from `@releases/lib/log-event` (structured JSON; `warn` level dispatches to `console.warn`). It already unwraps `Error` values via a replacer, so you can pass the raw error as a payload field. |
| 54 | + |
| 55 | +Find the poll-fetch sites (at `3238d540` these are lines 1038, 1619, 1680, 1988, 2020, 2062, 2069, 2090): |
| 56 | + |
| 57 | +``` |
| 58 | +grep -n 'catch(() => {})' workers/api/src/cron/poll-fetch.ts |
| 59 | +``` |
| 60 | + |
| 61 | +Classify them in two groups: |
| 62 | + |
| 63 | +**Group A — `fetch_log` inserts (observability-only): lines 1038, 1619, 1680, 1988.** Shape: |
| 64 | + |
| 65 | +```ts |
| 66 | +// poll-fetch.ts:1610-1619 (video-source misconfig branch; the others are identical in shape) |
| 67 | +await db |
| 68 | + .insert(fetchLog) |
| 69 | + .values({ |
| 70 | + sourceId: source.id, |
| 71 | + sessionId, |
| 72 | + releasesFound: 0, |
| 73 | + releasesInserted: 0, |
| 74 | + durationMs: dur, |
| 75 | + status: "error", |
| 76 | + error: "Missing feedUrl or video.provider in source metadata", |
| 77 | + }) |
| 78 | + .catch(() => {}); |
| 79 | +``` |
| 80 | + |
| 81 | +**Group B — `sources` state writes (behavioral): lines 2020, 2062, 2069, 2090.** These persist backoff/streak state; a silent failure here means no backoff. Shape: |
| 82 | + |
| 83 | +```ts |
| 84 | +// poll-fetch.ts:2084-2090 (error-backoff write; 2020 is the transient-feed variant, |
| 85 | +// 2062/2069 are the feed4xxStreak metadata writes) |
| 86 | +await db |
| 87 | + .update(sources) |
| 88 | + .set({ |
| 89 | + consecutiveErrors: newErrors, |
| 90 | + nextFetchAfter: nextFetch, |
| 91 | + }) |
| 92 | + .where(eq(sources.id, source.id)) |
| 93 | + .catch(() => {}); |
| 94 | +``` |
| 95 | + |
| 96 | +Do NOT touch the `.catch(() => null)` fallbacks near lines 1000–1021 |
| 97 | +(`getSecret(...)`/`fetchCloudflareMarkdown(...)`) — those feed explicitly |
| 98 | +handled `null` paths and are intentional. |
| 99 | + |
| 100 | +`poll-fetch.ts` already imports and uses `logEvent` with |
| 101 | +`component: "cron-poll-fetch"` (see the `feed-rate-limited` warn near line 2022) — match that convention. |
| 102 | + |
| 103 | +The search site (`workers/api/src/routes/search.ts:645` at `3238d540`; find it |
| 104 | +with `grep -n 'catch(() => \[\]' workers/api/src/routes/search.ts`): |
| 105 | + |
| 106 | +```ts |
| 107 | +// search.ts:641-647 — a thrown FTS error silently becomes "no results" |
| 108 | + }).catch(() => [] as RawSearchReleaseRow[]); |
| 109 | + let rawReleases = ftsRows; |
| 110 | + if (rawReleases.length === 0 && (orgs.length > 0 || catalog.length > 0)) { |
| 111 | +``` |
| 112 | +
|
| 113 | +`search.ts` does NOT currently import `logEvent` — add the import |
| 114 | +(`import { logEvent } from "@releases/lib/log-event";`) and use |
| 115 | +`component: "search"`. |
| 116 | +
|
| 117 | +The OrgActor site (`workers/api/src/org-actor.ts:149`): |
| 118 | +
|
| 119 | +```ts |
| 120 | +// org-actor.ts:149 — malformed discovery JSON becomes {}, so the subsequent |
| 121 | +// log reports sessionId: null instead of the real cause |
| 122 | +const { sessionId } = (await res.json().catch(() => ({}))) as { sessionId?: string }; |
| 123 | +``` |
| 124 | +
|
| 125 | +`org-actor.ts` uses `logEvent` with `component: "org-actor"` throughout — match it. |
| 126 | +
|
| 127 | +## Commands you will need |
| 128 | +
|
| 129 | +| Purpose | Command | Expected on success | |
| 130 | +| ------------ | ------------------------------------------------------- | ------------------- | |
| 131 | +| Install | `bun install` (repo root; only if node_modules missing) | exit 0 | |
| 132 | +| Lint + types | `bun run check` | exit 0 | |
| 133 | +| API tests | `bun test workers/api` | all pass | |
| 134 | +| Full suite | `bun run test` | all pass | |
| 135 | +
|
| 136 | +Note: `bun run test` is a three-invocation chain (deliberate process isolation |
| 137 | +for module mocks) — run it exactly via the script, not by hand-rolling the |
| 138 | +directory list. |
| 139 | +
|
| 140 | +## Scope |
| 141 | +
|
| 142 | +**In scope** (the only files you should modify): |
| 143 | +
|
| 144 | +- `workers/api/src/cron/poll-fetch.ts` |
| 145 | +- `workers/api/src/routes/search.ts` |
| 146 | +- `workers/api/src/org-actor.ts` |
| 147 | +- `workers/api/src/lib/log-swallowed.ts` (create) |
| 148 | +- `workers/api/test/log-swallowed.test.ts` (create) |
| 149 | +
|
| 150 | +**Out of scope** (do NOT touch, even though they look related): |
| 151 | +
|
| 152 | +- The `.catch(() => null)` fallbacks in `poll-fetch.ts` (~lines 1000–1021) — handled-null paths, intentional. |
| 153 | +- `workers/api/src/lib/feed-cache.ts`, `routes/feed.ts`, `routes/firecrawl.ts`, `routes/admin-emails.ts`, `routes/changelog.ts` — their catch sites were audited and are documented-intentional or feed handled fallbacks. Leave them. |
| 154 | +- `workers/api/src/auth/index.ts` — its best-effort catches are commented by design. |
| 155 | +- Any change to fail-open vs fail-closed semantics: every site must still swallow the error after logging. Do not rethrow anywhere. |
| 156 | +
|
| 157 | +## Git workflow |
| 158 | +
|
| 159 | +- Branch: `advisor/004-log-swallowed-ingest-writes` |
| 160 | +- Conventional commits, e.g. `fix(api): log swallowed fetch-log and backoff write failures (#advisor-004)` — match the style visible in `git log --oneline -10`. |
| 161 | +- Do NOT push or open a PR unless the operator instructed it. |
| 162 | +
|
| 163 | +## Steps |
| 164 | +
|
| 165 | +### Step 1: Create the shared catch-handler helper |
| 166 | +
|
| 167 | +Create `workers/api/src/lib/log-swallowed.ts`: |
| 168 | +
|
| 169 | +```ts |
| 170 | +import { logEvent } from "@releases/lib/log-event"; |
| 171 | + |
| 172 | +/** |
| 173 | + * `.catch()` handler for best-effort writes: keeps fail-open semantics |
| 174 | + * (resolves to undefined, never rethrows) but surfaces the failure in |
| 175 | + * Workers Logs instead of dropping it. |
| 176 | + */ |
| 177 | +export function logSwallowed( |
| 178 | + component: string, |
| 179 | + event: string, |
| 180 | + context: Record<string, unknown> = {}, |
| 181 | +): (err: unknown) => undefined { |
| 182 | + return (err) => { |
| 183 | + logEvent("warn", { component, event, ...context, error: err }); |
| 184 | + return undefined; |
| 185 | + }; |
| 186 | +} |
| 187 | +``` |
| 188 | +
|
| 189 | +**Verify**: `bun run check` → exit 0. |
| 190 | +
|
| 191 | +### Step 2: Instrument the poll-fetch sites |
| 192 | +
|
| 193 | +In `workers/api/src/cron/poll-fetch.ts`, import the helper and replace each of |
| 194 | +the 8 bare `.catch(() => {})` with a call that names the site. Event names: |
| 195 | +
|
| 196 | +- Group A (fetch_log inserts, 4 sites): `.catch(logSwallowed("cron-poll-fetch", "fetch-log-write-failed", { sourceSlug: source.slug }))` |
| 197 | +- Group B backoff writes (lines 2020, 2090): `event: "backoff-write-failed"` — same shape, include `sourceSlug: source.slug`. |
| 198 | +- Group B metadata/streak writes (lines 2062, 2069): `event: "source-metadata-write-failed"`, include `sourceSlug: source.slug`. |
| 199 | +
|
| 200 | +Use the enclosing scope's actual source identifier variable (it is |
| 201 | +`source.slug` in all eight enclosing scopes at `3238d540`; if a site's scope |
| 202 | +differs after drift, use whatever slug/id is in scope — never a token or URL |
| 203 | +with credentials). |
| 204 | +
|
| 205 | +**Verify**: `grep -c 'catch(() => {})' workers/api/src/cron/poll-fetch.ts` → `0`, and `bun test workers/api` → all pass. |
| 206 | +
|
| 207 | +### Step 3: Instrument the search FTS fallback |
| 208 | +
|
| 209 | +In `workers/api/src/routes/search.ts`, replace the `.catch(() => [] as RawSearchReleaseRow[])` with: |
| 210 | +
|
| 211 | +```ts |
| 212 | +.catch((err) => { |
| 213 | + logEvent("warn", { component: "search", event: "fts-query-failed", error: err }); |
| 214 | + return [] as RawSearchReleaseRow[]; |
| 215 | +}); |
| 216 | +``` |
| 217 | +
|
| 218 | +(Direct inline here rather than the helper, because the site needs a typed |
| 219 | +array fallback, not `undefined`.) Add the `logEvent` import at the top of the |
| 220 | +file. |
| 221 | +
|
| 222 | +**Verify**: `bun run check` → exit 0; `bun test workers/api` → all pass (search route tests exist and must stay green). |
| 223 | +
|
| 224 | +### Step 4: Instrument the OrgActor JSON parse |
| 225 | +
|
| 226 | +In `workers/api/src/org-actor.ts`, replace the `res.json().catch(() => ({}))` with: |
| 227 | +
|
| 228 | +```ts |
| 229 | +const { sessionId } = (await res.json().catch((err) => { |
| 230 | + logEvent("warn", { component: "org-actor", event: "drain-response-bad-json", orgId, error: err }); |
| 231 | + return {}; |
| 232 | +})) as { sessionId?: string }; |
| 233 | +``` |
| 234 | +
|
| 235 | +(`orgId` is in scope in the alarm handler.) |
| 236 | +
|
| 237 | +**Verify**: `bun test workers/api/test/org-actor.test.ts` → all 7 existing tests pass. |
| 238 | +
|
| 239 | +### Step 5: Unit-test the helper |
| 240 | +
|
| 241 | +Create `workers/api/test/log-swallowed.test.ts` using `bun:test` (`describe`/`it`/`expect`, `spyOn`): |
| 242 | +
|
| 243 | +- `logEvent`'s `warn` level writes one line via `console.warn` (see `packages/lib/src/log-event.ts`). Use `spyOn(console, "warn")`, call `logSwallowed("test-comp", "test-event", { sourceSlug: "x" })(new Error("boom"))`, and assert: the handler returns `undefined`, does not throw, and the logged JSON line parses to an object containing `component: "test-comp"`, `event: "test-event"`, `sourceSlug: "x"`, and an `error` field whose `message` is `"boom"` (logEvent's replacer unwraps Errors into `{ name, message, stack }`). |
| 244 | +- Restore the spy (`mockRestore()`) in `afterEach` — do NOT use `mock.module` anywhere in this test (process-global in bun, leaks across files). |
| 245 | +
|
| 246 | +**Verify**: `bun test workers/api/test/log-swallowed.test.ts` → new tests pass. |
| 247 | +
|
| 248 | +## Test plan |
| 249 | +
|
| 250 | +- New: `workers/api/test/log-swallowed.test.ts` — handler returns undefined, never throws, emits a parseable warn line with component/event/context/error.message (2–3 cases: Error input, string input). |
| 251 | +- Regression: the existing suites already exercise every touched code path (`workers/api/test/org-actor.test.ts`, the search route tests, `appstore-poll-fetch.test.ts`). They must all stay green — `bun test workers/api`. |
| 252 | +
|
| 253 | +## Done criteria |
| 254 | +
|
| 255 | +Machine-checkable. ALL must hold: |
| 256 | +
|
| 257 | +- [ ] `bun run check` exits 0 |
| 258 | +- [ ] `bun test workers/api` exits 0, including the new `log-swallowed.test.ts` |
| 259 | +- [ ] `grep -c 'catch(() => {})' workers/api/src/cron/poll-fetch.ts` → 0 |
| 260 | +- [ ] `grep -c 'catch(() => \[\]' workers/api/src/routes/search.ts` → 0 |
| 261 | +- [ ] `grep -c 'catch(() => ({}))' workers/api/src/org-actor.ts` → 0 |
| 262 | +- [ ] `git status` shows no modified files outside the in-scope list |
| 263 | +- [ ] `plans/README.md` status row updated |
| 264 | +
|
| 265 | +## STOP conditions |
| 266 | +
|
| 267 | +Stop and report back (do not improvise) if: |
| 268 | +
|
| 269 | +- The grep in Step 2 finds a different number of sites than 8, or a site's |
| 270 | + enclosing scope has no source slug/id variable — the file has drifted; |
| 271 | + re-confirm each site's group (A vs B) before instrumenting, and report if |
| 272 | + any site looks like it became load-bearing (its result is now awaited into |
| 273 | + a variable that is used). |
| 274 | +- Any existing test fails after a change and the failure is not obviously a |
| 275 | + log-line assertion — that means one of these catches was masking a real |
| 276 | + error that a test now surfaces. That is a genuine bug find: report it, do |
| 277 | + not paper over it. |
| 278 | +- You find yourself wanting to rethrow or change control flow at any site. |
| 279 | +
|
| 280 | +## Maintenance notes |
| 281 | +
|
| 282 | +- If `fetch-log-write-failed` or `backoff-write-failed` shows up recurrently |
| 283 | + in Axiom (dataset `releases-cloudflare-logs`, filter on the `event` field), |
| 284 | + that is the signal to revisit fail-open — particularly the backoff writes, |
| 285 | + where repeated failure means a source is hammering a rate-limiting origin. |
| 286 | +- Reviewers should scrutinize: no site changed from swallow to rethrow, and no |
| 287 | + logged payload carries a URL with embedded credentials or a token. |
| 288 | +- Deferred (deliberately): the same sweep for `workers/discovery` — its catch |
| 289 | + sites were not audited in this pass. |
0 commit comments