Skip to content

🪦 feat: Request Tombstones, Memory Watermarks & Server Error Logging - #102

Open
dustinhealy wants to merge 1 commit into
mainfrom
request-observability
Open

🪦 feat: Request Tombstones, Memory Watermarks & Server Error Logging#102
dustinhealy wants to merge 1 commit into
mainfrom
request-observability

Conversation

@dustinhealy

Copy link
Copy Markdown
Contributor

Summary

The bun server's only log output is its two startup lines, which leaves crashes and OOMKills undiagnosable: the HTTP metrics increment on completion, so a request that kills the process mid-flight is invisible to them, an uncaught handler throw produces no output at all, and nothing captures memory growth between metric scrapes.

Adds three narrow instruments to the serve path (server.ts, pure helpers in src/server/logging.ts):

  • Request tombstones[req] GET /path at arrival (before the handler runs, so a fatal request leaves its method and path as the process's last words) plus [req] GET /path 200 12ms on completion. An arrival line with no matching completion identifies the request a process died holding. Paths log without query strings (they can carry OAuth exchange codes) and truncate at 200 chars. Kubelet probes (kube-probe/ user-agent) are skipped so steady-state logs stay near-silent. A per-window cap (200 requests / 10s) stops a request flood from amplifying into a log flood, surfacing [req] suppressed N requests in prior window instead.
  • Memory watermarks — a 10s tick logs [mem] rss=391Mi heapUsed=213Mi (crossed 384Mi) on each upward threshold crossing (defaults 256/384/448 MiB, configurable via ADMIN_PANEL_MEMORY_LOG_THRESHOLDS_MB), re-arming when memory drops back below a threshold. This timestamps allocation bursts even when no request is in flight — the deciding evidence between a pathological request and runtime GC behavior.
  • Error hookBun.serve had no error() handler, so an uncaught throw in the SSR handler produced no log line at all. It now logs the message and stack and returns a plain 500.

On by default; disable with ADMIN_PANEL_REQUEST_LOG=false. Prometheus metrics, /metrics, and /health behavior unchanged.

Change Type

  • New feature (non-breaking change which adds functionality)

Testing

22 new unit tests (probe detection, truncation, flood-guard windows, watermark hysteresis); full suite (821 tests) passing; tsc --noEmit, eslint, and a from-scratch production build clean.

Verified live against the production build (bun run build + bun run start):

  • GET /login?redirect=/... logs as [req] GET /login — query string never appears
  • kube-probe/1.29 requests produce zero lines
  • a 300-char path truncates at 200 with a ...(truncated) marker
  • a 230-request burst logs exactly 200 requests, then [req] suppressed 30 requests in prior window when the next window opens
  • watermark fires on threshold crossing with env-configured thresholds and reports the highest threshold crossed
  • ADMIN_PANEL_REQUEST_LOG=false produces zero request lines under real traffic

Test Configuration:

  • Bun 1.3.11, production build served locally with SESSION_SECRET set
  • Watermark exercised via ADMIN_PANEL_MEMORY_LOG_THRESHOLDS_MB=50,80 so thresholds sit below the server's baseline RSS

Checklist

  • My code adheres to this project's style guidelines
  • I have performed a self-review of my own code
  • I have commented in any complex areas of my code
  • My changes do not introduce new warnings
  • I have written tests demonstrating that my changes are effective or that my feature works
  • Local unit tests pass with my changes

… bun server

The server's only log output is its two startup lines. The HTTP metrics
increment on completion, so a request that kills the process mid-flight
is invisible to them, an uncaught handler throw produces no output at
all, and there is no signal for memory growth between metric scrapes.
Diagnosing a crash or an OOMKill from this is guesswork.

Adds three narrow instruments to the serve path. Request lines log at
arrival (before the handler) and completion, so a fatal request leaves
its method and path as the process's last words; paths are logged
without query strings, truncated, kubelet probes are skipped, and a
per-window cap stops a request flood from amplifying into a log flood
while still surfacing the suppressed count. A memory watermark logs RSS
threshold crossings on a 10s tick to timestamp allocation bursts even
when no request is in flight. An error hook on Bun.serve logs unhandled
handler throws.

On by default; disable with ADMIN_PANEL_REQUEST_LOG=false. Thresholds
configurable via ADMIN_PANEL_MEMORY_LOG_THRESHOLDS_MB.

@cursor cursor Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Cursor Bugbot has reviewed your changes using high effort and found 1 potential issue.

Fix All in Cursor

❌ Bugbot Autofix is OFF. To automatically fix reported issues with cloud agents, have a team admin enable autofix in the Cursor dashboard.

Reviewed by Cursor Bugbot for commit 1637d38. Configure here.

Comment thread src/server/logging.ts
if (lastRssMb < threshold && rssMb >= threshold) crossed = threshold;
}
lastRssMb = rssMb;
return crossed;

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Watermark false crossing at startup

Medium Severity

createMemoryWatermark treats the previous RSS sample as zero until the first check call. On the initial 10s tick, a process whose RSS already sits above configured thresholds (common after boot) logs an upward crossing even when memory did not grow since startup, which can misread deploy baselines as allocation bursts.

Additional Locations (1)
Fix in Cursor Fix in Web

Reviewed by Cursor Bugbot for commit 1637d38. Configure here.

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