minstrel/internal/server/requestlog_test.go

package server

import (
	"bytes"
	"context"
	"encoding/json"
	"log/slog"
	"net/http"
	"net/http/httptest"
	"strings"
	"testing"
)

// captureLogger is a slog.Handler that records each Record emitted, so
// requestLog tests can assert level + attrs without parsing JSON.
type capturedRecord struct {
	Level slog.Level
	Msg   string
	Attrs map[string]any
}

type captureHandler struct {
	records *[]capturedRecord
}

func (h *captureHandler) Enabled(_ context.Context, _ slog.Level) bool { return true }

func (h *captureHandler) Handle(_ context.Context, r slog.Record) error {
	rec := capturedRecord{Level: r.Level, Msg: r.Message, Attrs: map[string]any{}}
	r.Attrs(func(a slog.Attr) bool { rec.Attrs[a.Key] = a.Value.Any(); return true })
	*h.records = append(*h.records, rec)
	return nil
}

func (h *captureHandler) WithAttrs(_ []slog.Attr) slog.Handler { return h }
func (h *captureHandler) WithGroup(_ string) slog.Handler      { return h }

func newCaptureLogger() (*slog.Logger, *[]capturedRecord) {
	records := &[]capturedRecord{}
	return slog.New(&captureHandler{records: records}), records
}

func TestRequestLog_StatusToSeverity(t *testing.T) {
	cases := []struct {
		name      string
		status    int
		wantLevel slog.Level
	}{
		{"2xx is Info", http.StatusOK, slog.LevelInfo},
		{"4xx is Warn", http.StatusNotFound, slog.LevelWarn},
		{"5xx is Error", http.StatusInternalServerError, slog.LevelError},
	}
	for _, tc := range cases {
		t.Run(tc.name, func(t *testing.T) {
			logger, records := newCaptureLogger()
			h := requestLog(logger)(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
				w.WriteHeader(tc.status)
			}))
			req := httptest.NewRequest(http.MethodGet, "/something", nil)
			h.ServeHTTP(httptest.NewRecorder(), req)

			if len(*records) != 1 {
				t.Fatalf("len(records) = %d, want 1", len(*records))
			}
			rec := (*records)[0]
			if rec.Level != tc.wantLevel {
				t.Errorf("level = %v, want %v", rec.Level, tc.wantLevel)
			}
			if rec.Attrs["status"] != int64(tc.status) {
				t.Errorf("status = %v, want %d", rec.Attrs["status"], tc.status)
			}
		})
	}
}

func TestRequestLog_SkipsHealthz(t *testing.T) {
	logger, records := newCaptureLogger()
	h := requestLog(logger)(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
		w.WriteHeader(http.StatusOK)
	}))
	req := httptest.NewRequest(http.MethodGet, "/healthz", nil)
	h.ServeHTTP(httptest.NewRecorder(), req)

	if len(*records) != 0 {
		t.Errorf("expected /healthz to be skipped, got %d records", len(*records))
	}
}

// Sanity that other paths produce a useful structured payload.
func TestRequestLog_AttributesPresent(t *testing.T) {
	// Use a real slog text handler buffer so we also exercise the
	// formatter (catches WithAttrs/WithGroup integration regressions).
	var buf bytes.Buffer
	logger := slog.New(slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelInfo}))
	h := requestLog(logger)(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
		w.WriteHeader(http.StatusOK)
	}))
	req := httptest.NewRequest(http.MethodPost, "/api/something", strings.NewReader(""))
	h.ServeHTTP(httptest.NewRecorder(), req)

	var got map[string]any
	if err := json.Unmarshal(buf.Bytes(), &got); err != nil {
		t.Fatalf("decode log line: %v\nraw: %s", err, buf.String())
	}
	for _, key := range []string{"method", "path", "status", "duration_ms"} {
		if _, ok := got[key]; !ok {
			t.Errorf("expected key %q in log entry, got %v", key, got)
		}
	}
}