A request whose handler panics is logged, and counted in the metrics, as 200 though it is answered 500 #125

Closed
opened 2026-10-14 11:01:00 +02:00 by clawbot · 1 comment
Collaborator

The panic recovery is the outermost middleware, so it writes the 500 only after the panic has passed through the request log and the metrics middleware. Both record the status they saw, their default of 200 since nothing was written yet, so the request log line and the metrics' code label say 200 for a request answered 500.

Where, on next at b1eefe0: backend/internal/server/routes.go uses Recoverer (line 34) before Logging (line 36) and Metrics (line 66). In backend/internal/middleware/middleware.go, Logging (line 201) logs a status that starts at 200 (line 115), and Recoverer (line 302) writes the 500.

How to see it: a test wraps a handler that panics in Recoverer, RequestID and Logging, in the order routes.go uses: the response is 500 and the request log line says 200. With Metrics in place of Logging, http_request_duration_seconds and http_response_size_bytes get code 200.

What is right: backend/README.md, Sentry: a request whose handler panics "still gets 500 from the server's panic recovery"; Metrics: each request is recorded "labelled with its path, method and status". The log and the metrics should give the status the client got.

Severity: low. Only a request whose handler panics is affected.

Definition of done

  • A request whose handler panics is logged with status 500 and counted with code 500 in the metrics.
  • The panic recovery stays the first middleware, as GO_HTTP_SERVER_CONVENTIONS.md requires.
  • A test sends a request to a handler that panics through the middleware in the order routes.go uses, and checks the log line's status and the metrics' code.
  • TODO.md updated in the same commit; commit title ends (closes #N).

Model: opus-5-5

The panic recovery is the outermost middleware, so it writes the 500 only after the panic has passed through the request log and the metrics middleware. Both record the status they saw, their default of 200 since nothing was written yet, so the request log line and the metrics' `code` label say 200 for a request answered 500. **Where**, on `next` at `b1eefe0`: `backend/internal/server/routes.go` uses `Recoverer` (line 34) before `Logging` (line 36) and `Metrics` (line 66). In `backend/internal/middleware/middleware.go`, `Logging` (line 201) logs a status that starts at 200 (line 115), and `Recoverer` (line 302) writes the 500. **How to see it**: a test wraps a handler that panics in `Recoverer`, `RequestID` and `Logging`, in the order `routes.go` uses: the response is 500 and the `request` log line says 200. With `Metrics` in place of `Logging`, `http_request_duration_seconds` and `http_response_size_bytes` get `code` 200. **What is right**: `backend/README.md`, Sentry: a request whose handler panics "still gets 500 from the server's panic recovery"; Metrics: each request is recorded "labelled with its path, method and status". The log and the metrics should give the status the client got. **Severity**: low. Only a request whose handler panics is affected. ## Definition of done - [ ] A request whose handler panics is logged with status 500 and counted with `code` 500 in the metrics. - [ ] The panic recovery stays the first middleware, as `GO_HTTP_SERVER_CONVENTIONS.md` requires. - [ ] A test sends a request to a handler that panics through the middleware in the order `routes.go` uses, and checks the log line's status and the metrics' `code`. - [ ] `TODO.md` updated in the same commit; commit title ends ` (closes #N)`. Model: opus-5-5
clawbot self-assigned this 2026-10-14 11:01:00 +02:00
Author
Collaborator

Built in #133: a new middleware, placed right after the request log and right after the metrics middleware, writes the 500 when a handler panics and lets the panic go on, so the log line and the metrics say 500, Sentry still gets the panic, and the panic recovery stays first.

Model: opus-5-5

Built in https://git.eeqj.de/sneak/netwatch/pulls/133: a new middleware, placed right after the request log and right after the metrics middleware, writes the 500 when a handler panics and lets the panic go on, so the log line and the metrics say 500, Sentry still gets the panic, and the panic recovery stays first. Model: opus-5-5
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: sneak/netwatch#125