Skip to content

Observability phases 0–1: health, alerting, structured logs, request-id correlation - #353

Open
disnet wants to merge 3 commits into
mainfrom
radial/impl-5e151668bb2d
Open

Observability phases 0–1: health, alerting, structured logs, request-id correlation#353
disnet wants to merge 3 commits into
mainfrom
radial/impl-5e151668bb2d

Conversation

@disnet

@disnet disnet commented Aug 13, 2026

Copy link
Copy Markdown
Owner

Implements Phases 0–1 of the observability plan. Phase 0 ("see breakage") landed in the first commit; this update adds Phase 1 and fixes the four review findings against Phase 0.


Phase 1 — structured logs + request-id correlation

Phase 0 made outages page. Phase 1 makes the aftermath legible: one id now finds every log line and every exception for the request, cron run, or poll cycle that caused an alert — across both runtimes.

  • backend/src/utils/logger.tslog.info('event', { … }) emits one object per line. Workers Logs indexes the fields of a logged object but treats a string (even a JSON one) as opaque text, so this turns "all errors on route X" and "everything for request Y" into queries instead of greps. The plan said "one-line JSON"; the object form is what actually gets indexed.
  • backend/src/utils/request-context.ts — request id, route class and DID in AsyncLocalStorage (nodejs_als was already on for Sentry). Ambient rather than threaded, so the id reaches a log line, a reportError() tag and an outbound header without changing every handler signature. Route classes collapse identifiers (/api/saved/:id) and cap depth, so logs aggregate by endpoint and a path scanner can't mint unbounded route values.
  • Converted the high-value paths only — request summary (route, status, durationMs), top-level catch, cron run + per-phase failures, Jetstream poll cycle. Leaf-level console.logs are left alone deliberately; a big-bang rewrite is churn.
  • Firehose lag is now logged every poll cycle, computed from the Jetstream cursors' microsecond timestamps. Phase 2's alert threshold has a source to read.
  • Cross-service: the id is returned as X-Request-Id (CORS-exposed, so a browser can quote it in a bug report) and sent on every feed-proxy call; the proxy adopts it, echoes it, and tags its own errors with it. It is minted, never accepted from a client — there's no trusted upstream, and a client sending a constant id would silently merge unrelated requests.

Review fixes on Phase 0

1. Deep health no longer reports the poller dead during normal operation (error). getAlarm() returns null while the alarm handler runs — 5–16s of every 60s cycle — so isRunning alone made a healthy poller look wedged on a large fraction of probes, the exact false page the runbook says to fix rather than ignore. /status now also returns lastAlarmStart, and the check mirrors the recency rule the DO's own /start branch already used (shared ALARM_ACTIVE_WINDOW_MS, so the two can't drift). lastPollAgeMs remains the real staleness signal; the body reports alarmScheduled and lastAlarmAgeMs separately so the distinction stays visible. 4 new tests drive the mid-alarm window deterministically.

2. Scrubbing now covers free text, not just structured fields (warning). Breadcrumb messages and data, exception messages, and event.message are scrubbed for tokenized URLs, Bearer …/DPoP …, and inline secret=… pairs. And the Console integration is dropped outright: call sites log raw session ids and OAuth state on failure paths, and no scrubber can reliably tell a credential from prose once it's been interpolated into a sentence — so the safe move is not to ship that channel. The defensive breadcrumb scrubbing stays for anything added another way. Fire drill #3 in the runbook now asks for the whole event, not just headers.

3. Pages deploys carry a version stamp after all (info). Each svelte.config.js stamps kit.version.name from $GITHUB_SHA, and all five smoke checks now assert the served /_app/version.json equals the SHA CI just built — the same proof the Workers get, so a deploy that silently didn't roll out goes red instead of passing a sniff against markup that never changes. The content sniff stays; it catches a different failure (deployed, but renders nothing). Verified by building all three apps with a fake SHA.

4. nodejs_als is now documented as a deliberate choice (info), narrower than the nodejs_compat the SDK's README asks for, with what to re-check on upgrade — plus its second consumer, the request context.

Docs

docs/RUNBOOK.md gains a "Reading the logs" section (the query patterns that pay for themselves, mapped to the events emitted), corrects the "Pages can't carry a version stamp" claim, and widens fire drill #3. backend/CLAUDE.md documents the logging convention.

Checks

  • backend: npm run check (tsc + prettier) clean; full vitest suite green — 46 files / 448 tests, run in batches of 6 because this sandbox can't host 46 concurrent workerd isolates. 21 of those tests are new.
  • feed-proxy: tsc --noEmit clean. bun test was not run — bun can't be installed in this container. The proxy delta is one middleware and the onError tags.
  • frontend / admin / linkblog-site: npm run check clean; all three build and emit _app/version.json with the injected SHA.

Not verified here

Anything needing real infrastructure: the uptime/heartbeat vendor setup and the fire drills; the staging soak for nodejs_als + global_fetch_strictly_public; whether Workers Logs' field indexing behaves as documented on the deployed Worker (first event = request query after deploy will tell). Playwright suites weren't run (no browsers in this container) — no frontend runtime code changed, only svelte.config.js.

Phases 2–4 (system-status table + admin ops panel, client signal, SLOs/alert pruning) are still open.

Radial artifact

claudebot.disnetdev.com (did:plc:n6ku5xddiuguwze3f356evla) added 3 commits August 13, 2026 23:40
…ecks

Ships the "see breakage" phase of the observability plan. Skyreader had no
alerting of any kind: every signal was pull-based and required already
suspecting a problem. This makes the outage-class failures push.

- Health: `GET /api/health` (shallow, dependency-free, version-stamped) and
  `GET /api/health/deep` (D1 + JetstreamPoller lag + feed-proxy, secret-gated
  and rate-limited, 503 on any degraded dependency). Both answer before session
  resolution so an uptime poller costs nothing.
- Version stamping: `GIT_COMMIT_SHA` passed at deploy time to the Worker
  (`--var`) and to the proxy (Docker build arg), surfaced on both health
  endpoints.
- Dead-man's switches: the every-minute cron pings `HEARTBEAT_URL` only after a
  clean run — which also guards the firehose, since that cron is what keeps the
  poller alive — and the feed-proxy warmer pings `WARM_HEARTBEAT_URL` after each
  completed tick, catching a wedge that throws nothing.
- Sentry on the backend Workers via `withSentry` (fetch + scheduled) plus
  `instrumentDurableObjectWithSentry` on the JetstreamPoller. Errors-only, with
  a `beforeSend` scrubber that strips credentials and keeps DIDs. Both runtimes
  report through a `reportError()` wrapper so the vendor stays a one-file
  decision. The SDK's Fetch integration is disabled: with tracing off it only
  adds a wrapper in front of every outbound call, and it took a background
  extraction fetch from 124ms to ~17s in the test suite.
- Post-deploy smoke checks in all five deploy workflows via
  `scripts/smoke-check.mjs`: Workers/proxy assert 200 *and* the version equals
  the SHA just deployed; Pages apps assert 200 + a content sniff.
- `docs/RUNBOOK.md`: the external check list and thresholds (0.2 is
  configuration, not code), secrets, per-alert response procedures, and fire
  drills.

Co-Authored-By: claudebot.disnetdev.com (did:plc:n6ku5xddiuguwze3f356evla) <claudebot.disnetdev.com@noreply.radial>
…w fixes

Phase 0 shipped alerting on outages. This makes the aftermath legible: when an
alert fires, one id now finds every line and every exception for the request,
run, or poll cycle that caused it — across two runtimes.

Phase 1 (structured logging + correlation):

- `src/utils/logger.ts`: `log.info('event', { … })` emits one object per line.
  Workers Logs indexes object fields but treats a string — even a JSON one — as
  opaque text, so this makes "all errors on route X" and "everything for request
  Y" queries instead of greps.
- `src/utils/request-context.ts`: request id, route class and DID in
  AsyncLocalStorage (`nodejs_als` was already on for Sentry). Ambient rather than
  threaded, so the id reaches a log line, a `reportError()` tag and an outbound
  header without touching every handler's signature. Route classes are collapsed
  (`/api/saved/:id`) and capped, so logs aggregate by endpoint and a path scanner
  can't mint unbounded route values.
- One summary line per request (route, status, durationMs), the top-level catch,
  the cron run and the Jetstream poll cycle now log structured events. The poll
  cycle also logs firehose lag, computed from the cursors' microsecond timestamps.
- The id is returned as `X-Request-Id` (CORS-exposed) and sent to the feed proxy,
  which adopts it, echoes it, and tags its own errors with it. It's minted, never
  accepted from a client: there's no trusted upstream, and a client sending a
  constant id would silently merge unrelated requests.

Review fixes on phase 0:

- `/api/health/deep` no longer reports the poller dead during normal operation.
  `getAlarm()` returns null while the alarm handler runs — 5–16s of every 60s
  cycle — so `isRunning` alone made a healthy poller look wedged on 8–27% of
  probes. `/status` now also returns `lastAlarmStart` and the check mirrors the
  recency rule the DO's own `/start` branch uses. Staleness is still caught by
  `lastPollAgeMs`.
- Sentry scrubbing now covers free text, not just structured fields: breadcrumb
  messages and data, exception messages, and `event.message` (tokenized URLs,
  `Bearer …`, inline `secret=…` pairs). The Console integration is dropped
  outright — call sites log raw ids on failure paths and no scrubber can tell a
  credential from prose once it's been interpolated into a sentence.
- Pages deploys now carry a version stamp after all: each `svelte.config.js`
  stamps `kit.version.name` from `$GITHUB_SHA`, and all five smoke checks assert
  the served `/_app/version.json` is the SHA CI just built. The content sniff
  stays — it catches a different failure (deployed but renders nothing).
- `wrangler.toml` documents `nodejs_als` as a deliberately narrower choice than
  the `nodejs_compat` the SDK's README asks for, with what to re-check on upgrade.

Checks: backend `npm run check` clean, full vitest suite green (46 files / 448
tests, run in batches of 6 — this sandbox can't host 46 concurrent workerd
isolates); 21 of those tests are new. feed-proxy `tsc --noEmit` clean (`bun test`
not run: bun can't be installed here). frontend/admin/linkblog-site `npm run
check` clean, and all three build with a stamped `_app/version.json`.

Co-Authored-By: claudebot.disnetdev.com (did:plc:n6ku5xddiuguwze3f356evla) <claudebot.disnetdev.com@noreply.radial>
@disnet disnet changed the title Observability phase 0: health endpoints, heartbeats, Sentry, post-deploy smoke checks Observability phases 0–1: health, alerting, structured logs, request-id correlation Aug 14, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant