Skip to content

[audit] Do we log all failures? Five verified holes — transient infra and pre-auth failures are never recorded, and 97% of the log is one bug #424

Description

@serge-ivo

Answer: mostly yes, and better than I expected — but there are five verified holes, and one of them is exactly the failure class the reporter hit

Audited every failure path I could reach, in response to "we have to log all failures to be able to investigate". Below is what is genuinely covered (do not rebuild it) and what is not.

What IS covered — verified, leave it alone

Mechanism Where Verdict
Durable write, never throws, bounded field sizes, mirrors into agent_events so failures appear inline in agent_trace lib/error-log.ts:25-64 Solid
Global app.onErrorlogUnhandled, with stack, attributed to the signed-in user index.ts:187-201, lib/on-error.ts:33-63 Solid
Client api() reports network errors and all 5xx to the durable log packages/sdk/src/client.ts:84, 101-103 Solid
Browser window.error + unhandledrejectionreportClientError store/console/src/main.tsx:10, 21 Solid
React ErrorBoundary.componentDidCatch — needed because window.onerror does not fire for exceptions React catches components/ErrorBoundary.tsx:39 Solid
Signature aggregation with count / firstSeen / lastSeen GET /v1/admin/errors/summary Excellent — this is what made #423 findable in one call
30-day retention, opportunistic (2% of writes), never blocks error-log.ts:55-61 Fine

agents/coder/web has no handlers of its own, but it is imported into the console (store/console/src/lib/surfaces.tsx:2), so it runs inside the console's boundary. Not a gap.

Server-side bare catch {} is down to 2 real sites (agent-think.ts:474, 550). The server is in good shape.

The five holes

H1 — Transient infra failures are never logged server-side

lib/on-error.ts:38:

if (isTransientInfraError(err)) return;   // ← before any logError

isTransientInfraError (:11-19) matches "Durable Object reset because its code was updated", "Durable Object is overloaded", "Network connection lost". Those return 503 {"error":"The service is updating…"} to the client and write zero server rows.

Consequence, from today: the 03:56:40Z chat failure — 13s after a Deploy API Worker run — exists in the log only because the browser reported it (client:api … → 503). Had that user been on a flaky connection, or a runner, or the MCP server, there would be no record at all. The question "how often does a deploy break a live request?" is currently unanswerable, and it is precisely the question that was asked.

The skip is deliberate and the reasoning (:24 "not a bug, self-heals") is sound for error severity. It is wrong for visibility. Fix: log it under a distinct source (transient) or level:"warn", excluded from error counts but countable.

H2 — Client failures before sign-in are dropped entirely

packages/sdk/src/client.ts:42:

const token = getToken();
if (!token) return;   // the log is per-user; nothing to attribute it to

So every sign-in, OAuth-callback and pre-auth failure is invisible — the exact class you cannot debug from the user's side. The premise is also wrong: migration 0034 declares user_id TEXT, -- nullable: some failures have no user context, and the server already writes null-user rows (every #423 cron row has user_id = null). Fix: allow an unauthenticated report to /v1/errors/client, rate-limited by IP.

H3 — 4xx never reaches the durable log from either side

  • Server: on-error.ts:39-40HttpError with status < 500 returns without logging.
  • Client: client.ts:101 — reports only res.status >= 500; the comment says ordinary 4xx "would just be noise".

Broadly right, but it makes some genuinely diagnostic failures invisible: 402 (no API key connected), 403, 409, and 429 (rate limited). A user repeatedly hitting a limit generates no evidence anywhere. Note the log does contain a 402 today — but only because chat logs it explicitly at its own call site, not through either path above. Fix: an allowlist of interesting 4xx at warn level, not all of them.

H4 — 61 bare catch {} remain, and #291 was closed saying they would not

Counted with grep -rnE "catch\s*(\([a-zA-Z_]*\))?\s*\{\s*\}", excluding tests:

workers/api/src            :  3   (2 real)
packages/sdk/src           : 10
store/console/src          : 38
agents/coder/web/src       :  8
packages/browser-runner/src:  2

#291 (CLOSED) reported "64 empty catch blocks" and its acceptance criteria said they would be "replaced with explicit benign comments only where failure is truly ignorable, or with structured logging/user-visible state where it is not." 64 → 61 is not that. This should be reopened or superseded rather than left looking done.

Important nuance, so this is not overstated: most of these wrap await api(...), and api() has already written the durable row for a 5xx or network error before throwing. So they are primarily a user-visible feedback failure, not a logging one — KnowledgeTab.tsx:92-112 silently renders an empty Documents/Credentials/Rules list when the load fails, which reads as "you have nothing" rather than "this didn't load". They become a logging failure only where the status is 4xx (H3).

H5 — A failure with no error object cannot be logged by any of the above

This is the one the reporter actually hit. In #421 the transcription fetch (stt.ts:344) has no signal, and there is no AbortController anywhere in packages/sdk/src/voice/ (grep -c → 0). A request that never settles produces no throw, no non-OK response, no rejection — so api(), window.onerror, unhandledrejection, ErrorBoundary and app.onError all have nothing to fire on. It is not under-logging; it is a failure the logging model cannot represent.

So "log all failures" is necessary but not sufficient. Anything that waits on a network must carry a deadline, or its failure mode is silence by construction. Tracked in #421; noted here because it is the structural answer to the question.

And the counterweight: volume already defeats the instrument

#4231780 of ~1845 rows (97%) are one repeating cron failure. My own first pass at this investigation queried the log, got 4 voice rows, and I reported "the logs show nothing". That conclusion was wrong and the log's own volume caused it.

So the answer to "log all failures" must include collapse at write time: for an identical signature repeating within a window, increment a count rather than insert a row. The read side already models this correctly (/v1/admin/errors/summary); the write side does not.

What to do — cheapest first

  1. H1 — log transient infra under source:"transient" instead of returning early. ~3 lines. Makes deploy disruption countable, which is the specific thing asked for.
  2. H2 — accept unauthenticated /v1/errors/client reports (IP rate-limited), and drop the if (!token) return. Unblocks all auth debugging.
  3. Write-side repeat collapse — bounded volume, and it is what makes (1) and (3) safe to add without recreating [bug] The stats rollup has failed on every cron tick since it shipped — 1780 identical D1 compound-SELECT errors in 29h, and it is 97% of the error log #423.
  4. H3 — allowlist 402/403/409/429 at warn level.
  5. H4 — reopen or supersede [bug] Stop swallowing runtime errors across voice, coder, and worker paths #291 with the real count; triage the 38 console sites by whether they wrap a read (show "couldn't load — Retry") or a write (never silent — a swallowed save tells the user their edit persisted when it did not). Worth grepping the writes first; that is where the harm is.
  6. H5 — timeouts, per [bug] A stalled transcription hangs on "Transcribing…" forever and locks the composer — no timeout, no retry, no dismiss, reload is the only escape #421. Not a logging change.

Alternatives considered and rejected

  • Remove the isTransientInfraError skip so these log as 500 errors. Rejected: it was added because these were being logged as bogus 500s and the 503 response is correct. Log them at a different severity, do not un-classify them.
  • Log all 4xx. Rejected: 401/404 on an SPA are constant background traffic and would recreate the [bug] The stats rollup has failed on every cron tick since it shipped — 1780 identical D1 compound-SELECT errors in 29h, and it is 97% of the error log #423 flood at higher volume than the cron did.
  • Ban catch {} with a lint rule and let it fail CI. Rejected as the first step: it forces 61 mechanical edits with no judgement about which are reads and which are writes, and the write ones need a real user-facing behaviour, not a console.warn. Worth adding after the triage, to hold the line.

Acceptance criteria

  • A deploy-time 503 produces a server-side row without a browser present.
  • A failed sign-in produces a durable row with user_id = null.
  • A signature repeating every minute for an hour produces bounded rows, and its count is still visible in /errors/summary.
  • No swallowed write in the console: a failed save shows the user that it failed.
  • /v1/admin/errors is readable — no single signature exceeds a large share of the recent feed.

Related: #291 (closed, empty catches — count essentially unchanged), #325 (closed, triage empty catches/silent rejections), #421 (the failure class logging cannot catch), #423 (the flood that makes the log unreadable), #387 (a giving-up path that produced no evidence — the same family, already fixed).

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions