Day 100 — Per-Request Structured Logging¶

Month 4 · Week 3 · ⬅ Day 099 · Day 101 ➡ · Journal index

🎯 Learning Objective¶

Emit one structured log line per HTTP request — method, path, status, duration, request id — using log/slog, and thread the request id through context.

📚 Topics¶

slog.Logger, JSON handler, LogAttrs
A ResponseWriter wrapper to capture status/bytes; request-id in context

📖 Reading / Sources¶

📝 Notes¶

slog is stdlib (Go 1.21+). A Logger wraps a Handler; NewJSONHandler emits one machine-parseable object per line — filter by status>=500 later.
ResponseWriter exposes no status getter. Wrap it: embed the interface, override WriteHeader/Write to record status and bytes. → [[responsewriter-wrap]]
Default the recorded status to 200. A handler that writes a body without calling WriteHeader still sends 200; if you default to 0 you'll mislog it.
Log on defer/after next.ServeHTTP so status and duration are final.
Request id rides in context under an unexported key type so no other package can collide. Never use a bare string as a context key. → [[context-keys]]
context.Context is the first arg of slog's *Context methods (InfoContext, LogAttrs), matching the wider context-first convention.
LogAttrs avoids allocation vs the variadic key, value... form — it takes pre-built slog.Attr values. Prefer it on hot paths. → [[slog-attrs]]

💻 Code Examples¶

type statusRecorder struct {
    http.ResponseWriter
    status int
    bytes  int
}

func (r *statusRecorder) WriteHeader(code int) { r.status = code; r.ResponseWriter.WriteHeader(code) }
func (r *statusRecorder) Write(b []byte) (int, error) {
    n, err := r.ResponseWriter.Write(b)
    r.bytes += n
    return n, err
}

func Logging(logger *slog.Logger, next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        start := time.Now()
        rec := &statusRecorder{ResponseWriter: w, status: http.StatusOK} // default 200!
        next.ServeHTTP(rec, r)
        logger.LogAttrs(r.Context(), slog.LevelInfo, "http_request",
            slog.String("method", r.Method),
            slog.Int("status", rec.status),
            slog.Duration("duration", time.Since(start)))
    })
}

Full code: examples/month-04/reqlog/main.go · Run: go run ./examples/month-04/reqlog

🏋️ Exercises / Practice¶

Exercise	Status	Link
Wrap `ResponseWriter` to capture status (reused in week-1 tests)	✅	examples/month-04/reqlog

🐛 Mistakes Made¶

Logged before ServeHTTP returned → every request showed status 0.
Used a string context key and shadowed another package's value. Switched to an unexported type ctxKey int.

❓ Open Questions¶

How do I propagate the request id to a downstream service? (Trace headers like traceparent; revisit with distributed tracing.)

🧠 Active Recall (answer without looking)¶

Q: Why default the wrapped recorder's status to 200?

A
A handler that writes a body without ever calling `WriteHeader` still emits a `200` on the wire. Defaulting to 0 would mislabel every such response.
Q: Why use an unexported type for the context key?

A
Context keys are compared by value AND type. An unexported key type makes collisions with other packages impossible; a bare `string` key can clash.

🪶 Feynman Reflection¶

The HTTP package hands me a write-only ResponseWriter, so to know what status I sent I slip a small recorder in front of it. After the handler finishes I emit one tidy JSON line a machine can grep. A short random id ties that line to any deeper logs the handler produced.

🕳️ Knowledge Gaps¶

slog groups, WithGroup, and per-request child loggers via logger.With.

✅ Summary¶

I can build a logging middleware that records status/bytes/duration and a request id, and emit it as structured JSON with slog.

⏭️ Next Steps / Prep for Tomorrow¶

Day 101: pagination & filtering of list endpoints.

Time spent	Difficulty	Confidence
90 min	🟦🟦⬜⬜⬜	🟦🟦🟦⬜⬜

Suggested commit: feat(examples): per-request slog middleware with request id (day 100)