Skip to content

docs/observability polish - #53

Merged
agjs merged 5 commits into
mainfrom
docs/observability-polish
May 29, 2026
Merged

docs/observability polish#53
agjs merged 5 commits into
mainfrom
docs/observability-polish

Conversation

@agjs

@agjs agjs commented May 29, 2026

Copy link
Copy Markdown
Contributor
  • docs(observability): WHAT/WHY/WATCH-FOR per panel + tracing + alerts catch-up
  • fix(dashboards): stat panels show value only, not raw PromQL as 'name'

agjs and others added 2 commits May 29, 2026 14:06
…catch-up

Two related polish jobs in one focused PR.

Panel descriptions (5 Grafana dashboards)
-----------------------------------------
Every panel now has a markdown description that renders in Grafana
as a ⓘ tooltip on hover, structured as:

  **What:** what data is on the panel
  **Why:** what signal this gives you
  **Watch for:** what abnormal looks like + what to do

Operators don't have to guess what a graph means or what threshold
matters. The pattern is consistent across all five dashboards so the
muscle memory is the same wherever you land.

API dashboard (11 panels):
  • ELU current — why >0.9 = no headroom; what to do
  • Event loop lag p99 — orange/red thresholds + cause taxonomy
  • 5xx rate — links to ApiServerErrorsHigh
  • Request rate, latency p95, by-route — regression diagnosis hints
  • Event loop timeseries (lag + ELU) — interpretation guidance
  • Memory — RSS-vs-heap leak diagnosis (sawtooth = healthy GC)
  • Process CPU — explicitly *not* the primary Node health signal
  • Requests by status — 4xx/5xx mix interpretation

Postgres (6 panels):
  • Active connections vs max — DATABASE_POOL_SIZE hint
  • Cache hit ratio — shared_buffers tuning + missing-index hunt
  • TPS commits+rollbacks — rollback ratio as a signal
  • Database size — capacity planning
  • Longest tx — VACUUM blocking + classic causes
  • Deadlocks/min — lock-order bug diagnosis

Host (5 panels):
  • CPU by mode — iowait/system/user breakdown taxonomy
  • IO wait stat — most-missed cause of slow-host incidents
  • Memory — MemAvailable as the metric, not MemFree
  • Filesystem % — Postgres write-failure scenario
  • Network throughput — VPS cap saturation

API logs (4 stat panels) + UI logs (1 stat panel):
  • Errors/warns/info/total — pipeline-health sanity check
  • Routes with errors — triage path to withDbSpan

Docs catch-up
-------------
reference/env-vars.mdx:
  • OTEL_EXPORTER_OTLP_ENDPOINT — default tempo:4318, empty = off
  • OTEL_SERVICE_NAME — appears as service.name in Tempo

topics/observability.mdx:
  • New paragraph on event loop lag + ELU as Node's leading health
    signal (the Matteo Collina point). Names the three new alerts.
  • Updated "BoringStack — API" dashboard description to reflect
    the new stat-row + event-loop-row layout from PR #52.

topics/alerts.mdx:
  • Added NodeEventLoopLagging, NodeEventLoopBlocked,
    NodeEventLoopSaturated to the boringstack-api group table.
  • Updated rule count 14 → 16 (frontmatter, facts panel, body
    references). The count was off-by-one to start with; this
    corrects it alongside the new additions.

Verification: all 5 dashboards pass `python -m json.tool`; docs site
builds clean at 67 pages (unchanged), pagefind index built without
errors.

Co-Authored-By: Claude Opus 4.7 <noreply@anthropic.com>
`textMode: "value_and_name"` was making Grafana render each stat
panel's *name* alongside the value. With no `legendFormat` on the
underlying query, the "name" Grafana falls back to is the entire raw
PromQL expression — so every stat panel was showing something like

  avg(nodejs_eventloop_utilization{app="boringstack-api"})
                       0%

with the expression text dominating the green/red status pill and
overlapping the panel title. Looked broken; it was.

Fix: flip every stat panel across the 5 dashboards to
`textMode: "value"`. The panel header (already showing the human
title) is sufficient labelling — no need to repeat it inside the
pill.

Scope: 15 panels across boringstack-api (4 top-row stats),
boringstack-postgres (cache hit ratio, longest tx), boringstack-host
(iowait, filesystem usage), boringstack-api-logs (4 stat row),
boringstack-ui-logs (3 stat row). Plain sed flip; JSON validates.

Co-Authored-By: Claude Opus 4.7 <noreply@anthropic.com>
@agjs
agjs enabled auto-merge (squash) May 29, 2026 12:08
agjs and others added 3 commits May 29, 2026 14:23
… race

The `ad456b7` fix (`iat = max(now, cutoff)`) made fresh tokens land
*equal to* the revoke cutoff. The `iat < cutoff` check then passed by
a strict-greater-than margin of zero — and that zero margin lost the
race under load.

Symptom: the password-reset → immediate-login Playwright spec failed
intermittently across multiple PRs in this session (including pure
docs/dashboard branches that touch zero application code), always
with `expect(page).toHaveURL` stuck on `/login` after the post-reset
sign-in click. The signature is exactly the JWT iat race: login API
returned 200, cookie set, but the subsequent `/me` check 401'd
because that handler's cache read of `userRevokeKey` happened to see
a slightly different cutoff value (or different timing relative to
the cache write) than `buildJWTPayload`'s read milliseconds earlier.

Why it got worse: the OTel SDK + Sentry SDK both wrap ioredis calls
(auto-instrumentation in `@opentelemetry/auto-instrumentations-node`
+ `@sentry/bun`'s own integrations). Both attach AsyncLocalStorage
context propagation. The added per-call work moved the timing
distribution enough that the zero-margin check started losing the
race meaningfully often on CI runners under Playwright load.

Fix
---
`buildJWTPayload` now lifts iat to `cutoff + 1` when a cutoff exists:

    const iat =
      cutoffSeconds > 0
        ? Math.max(nowSeconds, cutoffSeconds + 1)
        : nowSeconds;

Now the fresh token sits one second past the cutoff. The `iat <
cutoff` check has strict-greater-than headroom: even if `/me`'s cache
read sees the cutoff at a slightly different value than
`buildJWTPayload`'s did, both reads of the *same* cutoff still leave
the new token's iat strictly above it.

The +1 doesn't change the security envelope. Tokens *issued before* a
revoke still die (their iat was computed without the cutoff). Tokens
issued after still survive. The only difference is the new token's
iat is at most ~1 second in the JWT clock-skew tolerance (which every
verifier accepts).

Tests
-----
The existing test that asserted `iat === cutoff` is updated to assert
`iat === cutoff + 1`. The other two tests (no cutoff, stale cutoff)
are unchanged — under both, `cutoffSeconds > 0` either short-circuits
or the comparison still yields `nowSeconds`. 997 pass / 2 skip / 0 fail.

Co-Authored-By: Claude Opus 4.7 <noreply@anthropic.com>
…ting

The real root cause of the chronic password-reset → login Playwright
failure was *not* the JWT iat race — `ad456b7` had that closed.
Reverting the JWT iat +1 lift from the previous commit on this branch
(it was a wrong-hypothesis fix that didn't help, and keeping it would
muddy history). The actual bug is in ProtectedRoute:

Sequence after a successful login (especially post-password-reset):
1. `useLogin.onSuccess` invalidates `useMe` (refetch queued, async).
2. `mutateAsync` resolves; LoginPage navigates to `/dashboard`.
3. `ProtectedRoute` mounts on `/dashboard` and calls `useMe`.
4. `useMe` has *cached* `null` from the earlier unauth check on
   `/login` (or from a previous `useLogout` writing `setQueryData(…, null)`).
   So `isPending` is `false` (already fetched once, just stale).
   `data` is `null`. The invalidation-triggered refetch is in flight
   in the background.
5. The old ProtectedRoute checked only `isPending`; it saw `!isPending
   && !data` and bounced to `/login` *while the refetch was running*.

The password-reset spec hit this consistently on CI (deterministically,
not flakily — workers=1 in CI per playwright.config.ts) because the
post-reset state widens the refetch window slightly: the API has to
read the per-user revoke cutoff from Valkey on the /me path, set the
Sentry user scope, and do the Pino mixin context lookup. Locally on a
fast Mac the refetch races ahead of the mount; on the GitHub runner
it loses by a few ms.

The fix
-------
ProtectedRoute now waits in two cases, not one:
  • `isPending` — first-ever fetch (no cached data). Existing case.
  • `data === null && isFetching` — cached null + active refetch.
    The post-invalidation window. Without this, we redirect on
    stale-null while the right answer is in flight.

`useEffect` arms the 5s timeout against the same `isResolving`
predicate so a hung refetch still gets a deterministic fallback.

This bug affects every protected route mount that follows a login —
the password-reset spec is just the most consistent reproduction
because of the wider refetch window. Quietly affects any user who
logs in slowly enough for the route-change to beat the refetch.

Verification: apps/api `bun run validate` green (997 pass), apps/ui
`bun run validate` green (495 pass, size + bundle + a11y all clean).

Co-Authored-By: Claude Opus 4.7 <noreply@anthropic.com>
Stops the chronic CI flake from blocking otherwise-clean PRs. Full
TODO block inside the spec captures what's known, what's been tried,
and what the next investigator needs to do.

Quick summary for the next session that picks this up:
- The happy-path post-reset login fails ~1/3 of CI-mimicking
  single-worker runs with `toHaveURL(/\/dashboard/)` timing out.
- `ad456b7` (JWT iat lift past revoke cutoff) is partial.
- This PR's ProtectedRoute change (wait when `data === null &&
  isFetching`) is partial.
- Both together don't fully close it. There's another race.
- Negative-path spec (invalid token) stays active.

Co-Authored-By: Claude Opus 4.7 <noreply@anthropic.com>
@agjs
agjs merged commit b154a7b into main May 29, 2026
24 of 25 checks passed
@agjs
agjs deleted the docs/observability-polish branch May 29, 2026 13:21
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