fix(api): panic log carries trace_id — tracing ahead of recoverer (OC-0346)

recoverer snapshots telemetry.TraceIDFromContext before dispatch, so it
needs the otelhttp span to exist already; it was mounted two slots ahead
of telemetry.HTTPMiddleware and the trace_id attribute was always dropped.
Move the tracing middleware above it; request-id binding, security headers
and the body cap keep their relative positions.

Test (otel build only — the default build hard-wires TraceIDFromContext to
""): go test -tags otel -run TestRecoverer_PanicLogCarriesTraceID ./api/

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01A17Uq3d2C36rN82Jitf3wo
This commit is contained in:
J3vb
2026-08-30 10:13:04 +02:00
co-authored by Claude Fable 5
parent 3b7716e27b
commit 775eba50ae
2 changed files with 82 additions and 4 deletions
+75
View File
@@ -0,0 +1,75 @@
//go:build otel
package api
// OC-0346: the recovered-panic log record must carry the request's trace_id.
// Only the otel build can produce one (telemetry_default.go's
// TraceIDFromContext is hard-wired to ""), so this file is tagged and CI's
// untagged test run does not see it. Run it with
//
// go test -tags otel -count=1 -run TestRecoverer_PanicLogCarriesTraceID ./api/
import (
"bytes"
"context"
"encoding/json"
"log/slog"
"net/http"
"net/http/httptest"
"regexp"
"strings"
"testing"
"github.com/go-chi/chi/v5"
"github.com/J3vb/OwnCord/Server/config"
"github.com/J3vb/OwnCord/Server/telemetry"
)
// TestRecoverer_PanicLogCarriesTraceID drives a panicking handler through the
// real routerMiddleware stack with tracing on and asserts the panic record
// carries the span's trace id. Before the fix recoverer was mounted ahead of
// telemetry.HTTPMiddleware, so it captured the trace id from a context that
// had no span yet and the attribute was always dropped.
func TestRecoverer_PanicLogCarriesTraceID(t *testing.T) {
shutdown, err := telemetry.Init(context.Background(), config.TelemetryConfig{
Enabled: true,
Exporter: "prometheus", // a real tracer provider, no network exporter
ServiceName: "recoverer-test",
})
if err != nil {
t.Fatalf("telemetry.Init: %v", err)
}
t.Cleanup(func() { _ = shutdown(context.Background()) })
var logs bytes.Buffer
prev := slog.Default()
slog.SetDefault(slog.New(slog.NewJSONHandler(&logs, nil)))
t.Cleanup(func() { slog.SetDefault(prev) })
r := chi.NewRouter()
routerMiddleware(r, &config.Config{})
r.Get("/boom", func(http.ResponseWriter, *http.Request) { panic("boom") })
rr := httptest.NewRecorder()
r.ServeHTTP(rr, httptest.NewRequest(http.MethodGet, "/boom", nil))
if rr.Code != http.StatusInternalServerError {
t.Fatalf("status = %d, want 500 (panic not recovered)", rr.Code)
}
var rec map[string]any
for _, line := range strings.Split(strings.TrimSpace(logs.String()), "\n") {
var m map[string]any
if json.Unmarshal([]byte(line), &m) == nil && m["msg"] == "http handler panic recovered" {
rec = m
break
}
}
if rec == nil {
t.Fatalf("no recovered-panic record in logs:\n%s", logs.String())
}
traceID, _ := rec["trace_id"].(string)
if !regexp.MustCompile(`^[0-9a-f]{32}$`).MatchString(traceID) {
t.Fatalf("panic record trace_id = %q, want the span's 32-hex trace id; record = %v", traceID, rec)
}
}
+7 -4
View File
@@ -271,7 +271,8 @@ func routerHealthDeps(cfg *config.Config, database *db.DB, getOnlineUsers *func(
} }
// routerMiddleware installs NewRouter's global middleware stack. The order is a // routerMiddleware installs NewRouter's global middleware stack. The order is a
// security property (request-id binding before the logger reads it, security // security property (request-id binding before the logger reads it, tracing
// before panic recovery so the panic log carries the trace id, security
// headers and the body cap before any handler runs) — keep it exactly as // headers and the body cap before any handler runs) — keep it exactly as
// written. // written.
func routerMiddleware(r chi.Router, cfg *config.Config) { func routerMiddleware(r chi.Router, cfg *config.Config) {
@@ -282,12 +283,14 @@ func routerMiddleware(r chi.Router, cfg *config.Config) {
// NOTE: middleware.RealIP is intentionally omitted — trusting X-Real-IP from // NOTE: middleware.RealIP is intentionally omitted — trusting X-Real-IP from
// any source allows IP spoofing for rate-limit bypass. IP header trust is now // any source allows IP spoofing for rate-limit bypass. IP header trust is now
// handled explicitly in clientIPWithProxies using the trusted_proxies config. // handled explicitly in clientIPWithProxies using the trusted_proxies config.
r.Use(recoverer) // slog-routing panic recovery (replaces chi's stderr-only Recoverer)
r.Use(requestLogger) // structured request/response logging
// Phase B Step 8 — OpenTelemetry HTTP tracing. No-op when telemetry is // Phase B Step 8 — OpenTelemetry HTTP tracing. No-op when telemetry is
// disabled or the otel build tag is not set, so this is safe to mount // disabled or the otel build tag is not set, so this is safe to mount
// unconditionally. // unconditionally. Mounted ahead of recoverer, which snapshots the trace
// id before dispatch: the span must already exist for the panic record to
// carry trace_id (OC-0346).
r.Use(telemetry.HTTPMiddleware()) r.Use(telemetry.HTTPMiddleware())
r.Use(recoverer) // slog-routing panic recovery (replaces chi's stderr-only Recoverer)
r.Use(requestLogger) // structured request/response logging
r.Use(SecurityHeadersWithTLS(cfg.TLS.Mode)) r.Use(SecurityHeadersWithTLS(cfg.TLS.Mode))
r.Use(MaxBodySizeUnless(defaultMaxBodySize, bodyCapExemptPrefixes...)) r.Use(MaxBodySizeUnless(defaultMaxBodySize, bodyCapExemptPrefixes...))