fix(api): bound the logged request id and path (F8)

Unbounded client-controlled values reached the 2000-entry admin log ring
buffer and its SSE fan-out, letting an unauthenticated burst pin large amounts
of heap. A boundRequestID middleware now drops an inbound X-Request-Id over
128 bytes or outside printable ASCII, so chi generates its own, and the logged
request path is capped at 256 bytes. Both hunks are needed: a raw-socket probe
showed a 1MB r.URL.Path reaches the same sink independently of the header.

Verified by a panel of agents; an unpatched-tree reproduction fails 3 of the 4
added tests with the attacker bytes visible in the log record. UUID, 32-hex,
W3C traceparent and chi's own generated id format all still pass unchanged.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
J3vb
2026-07-30 15:13:48 +02:00
co-authored by Claude Opus 5
parent 4b56631a1b
commit a21628531c
3 changed files with 170 additions and 2 deletions
+15
View File
@@ -147,4 +147,19 @@ const (
// maxAvatarURLLen is the maximum length of a user avatar URL.
maxAvatarURLLen = 512
// maxRequestIDLen bounds a client-supplied X-Request-Id. chi's
// middleware.RequestID adopts that header verbatim, and the value then
// reaches every log record for the request (logctx, requestLogger,
// recoverer) and the echoed response header — while the admin ring buffer
// retains 2000 records, so an unbounded id becomes long-lived heap.
// 128 bytes fits every common correlation-id format (UUID, 32-hex,
// W3C traceparent, chi's own "host/prefix-000001").
maxRequestIDLen = 128
// maxLoggedPathLen bounds the request path attached to a log record. The
// URL is client-controlled and net/http accepts one up to MaxHeaderBytes
// (~1 MiB), so an unbounded path fills the ring buffer the same way an
// unbounded request id does. Well past the longest real route.
maxLoggedPathLen = 256
)
+109
View File
@@ -0,0 +1,109 @@
package api
// White-box tests for the bounds placed on client-controlled values before
// they enter a log record (and hence the admin ring buffer, which retains
// 2000 entries and captures DEBUG regardless of the configured log level).
// They live in package api (not api_test) so they can reach the unexported
// middleware.
import (
"bytes"
"log/slog"
"net/http"
"net/http/httptest"
"strings"
"testing"
"github.com/go-chi/chi/v5/middleware"
)
// loggedRequest runs req through the production request-id + logging chain and
// returns the captured log output and the response recorder.
func loggedRequest(t *testing.T, req *http.Request) (string, *httptest.ResponseRecorder) {
t.Helper()
var logs bytes.Buffer
prev := slog.Default()
slog.SetDefault(slog.New(slog.NewTextHandler(&logs, &slog.HandlerOptions{Level: slog.LevelDebug})))
t.Cleanup(func() { slog.SetDefault(prev) })
h := boundRequestID(middleware.RequestID(setRequestIDHeader(requestLogger(
http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
w.WriteHeader(http.StatusOK)
})))))
rr := httptest.NewRecorder()
h.ServeHTTP(rr, req)
return logs.String(), rr
}
// TestBoundRequestID_OverLongHeaderNeverReachesLog locks the bound: an inbound
// X-Request-Id past maxRequestIDLen is dropped, so none of the attacker's bytes
// land in the log record the ring buffer retains — nor in the response header.
// The request still gets a server-generated id.
func TestBoundRequestID_OverLongHeaderNeverReachesLog(t *testing.T) {
filler := strings.Repeat("A", maxRequestIDLen+1)
req := httptest.NewRequest(http.MethodGet, "/api/v1/health", nil)
req.Header.Set("X-Request-Id", filler)
out, rr := loggedRequest(t, req)
if strings.Contains(out, filler) {
t.Errorf("over-long X-Request-Id reached the log record: %q", out)
}
if !strings.Contains(out, "req_id=") {
t.Errorf("no request id was logged at all — correlation lost: %q", out)
}
if got := rr.Header().Get("X-Request-Id"); strings.Contains(got, filler) {
t.Errorf("over-long X-Request-Id echoed in response header: %q", got)
}
}
// TestBoundRequestID_ControlBytesRejected covers the charset half of the bound:
// a short id carrying control bytes is dropped too.
func TestBoundRequestID_ControlBytesRejected(t *testing.T) {
req := httptest.NewRequest(http.MethodGet, "/api/v1/health", nil)
req.Header.Set("X-Request-Id", "abc\x00def\tghi")
out, _ := loggedRequest(t, req)
if strings.Contains(out, "abc") {
t.Errorf("ill-formed X-Request-Id reached the log record: %q", out)
}
}
// TestBoundRequestID_NormalIDPreserved proves the bound does not break the
// req_id correlation feature: an ordinary client-supplied id still flows into
// the log record and back out in the response header.
func TestBoundRequestID_NormalIDPreserved(t *testing.T) {
const id = "3f8b1c2e-7a11-4c9d-9f0b-2b6f2f1c9a55"
req := httptest.NewRequest(http.MethodGet, "/api/v1/health", nil)
req.Header.Set("X-Request-Id", id)
out, rr := loggedRequest(t, req)
if !strings.Contains(out, "req_id="+id) {
t.Errorf("client request id was dropped: %q", out)
}
if got := rr.Header().Get("X-Request-Id"); got != id {
t.Errorf("response X-Request-Id = %q, want %q", got, id)
}
}
// TestRequestLogger_LongPathTruncated locks the same bound on the other
// unbounded client-controlled value in the record: net/http accepts a URL up to
// MaxHeaderBytes, and requestLogger logs the path on every request (404s
// included, at Warn).
func TestRequestLogger_LongPathTruncated(t *testing.T) {
filler := strings.Repeat("B", maxLoggedPathLen+50)
req := httptest.NewRequest(http.MethodGet, "/"+filler, nil)
out, _ := loggedRequest(t, req)
if strings.Contains(out, filler) {
t.Errorf("unbounded request path reached the log record: %q", out)
}
if !strings.Contains(out, "(truncated)") {
t.Errorf("expected a truncation marker in the logged path: %q", out)
}
}
+46 -2
View File
@@ -36,6 +36,7 @@ func NewRouter(cfg *config.Config, database *db.DB, ver string, logBuf *admin.Ri
r := chi.NewRouter()
// Middleware stack.
r.Use(boundRequestID) // must precede RequestID — it reads the header verbatim
r.Use(middleware.RequestID)
r.Use(setRequestIDHeader) // echo request ID into response header
// NOTE: middleware.RealIP is intentionally omitted — trusting X-Real-IP from
@@ -351,6 +352,49 @@ func handleLiveKitHealth(hub *ws.Hub) http.HandlerFunc {
}
}
// boundRequestID drops a client-supplied X-Request-Id that is over
// maxRequestIDLen bytes or is not plain printable ASCII, so the
// middleware.RequestID mounted straight after it generates a server-side id
// instead. Without this, chi adopts the header verbatim and the value is
// retained by the admin ring buffer (2000 entries) and echoed back in the
// response header — a one-shot burst of ~1 MiB ids pins hundreds of MB of heap.
//
// The value is dropped rather than truncated: a truncated id is not the
// client's id, so it correlates with nothing while still parking
// attacker-chosen bytes in the log. The request is served either way, and the
// server-generated id is still returned in the X-Request-Id response header.
func boundRequestID(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
if id := r.Header.Get(middleware.RequestIDHeader); id != "" && !validRequestID(id) {
r.Header.Del(middleware.RequestIDHeader)
}
next.ServeHTTP(w, r)
})
}
// validRequestID reports whether id is short enough and printable enough to
// carry through logs and the response header.
func validRequestID(id string) bool {
if len(id) > maxRequestIDLen {
return false
}
for i := range len(id) {
if id[i] < '!' || id[i] > '~' {
return false
}
}
return true
}
// truncateForLog bounds a client-controlled string before it becomes a log
// attribute, so it cannot inflate the retained ring-buffer entries.
func truncateForLog(s string, max int) string {
if len(s) <= max {
return s
}
return s[:max] + "...(truncated)"
}
// setRequestIDHeader copies the request ID from context into the response header.
func setRequestIDHeader(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
@@ -382,7 +426,7 @@ func recoverer(next http.Handler) http.Handler {
}
attrs := []any{
"method", r.Method,
"path", r.URL.Path,
"path", truncateForLog(r.URL.Path, maxLoggedPathLen),
"panic", rec,
"stack", stackutil.Capture(),
}
@@ -415,7 +459,7 @@ func requestLogger(next http.Handler) http.Handler {
reqID := middleware.GetReqID(r.Context())
attrs := []any{
"method", r.Method,
"path", path,
"path", truncateForLog(path, maxLoggedPathLen),
"status", status,
"duration_ms", elapsed.Milliseconds(),
"bytes", ww.BytesWritten(),