diff --git a/zddc/cmd/zddc-server/main.go b/zddc/cmd/zddc-server/main.go index d0c3291..75fbb64 100644 --- a/zddc/cmd/zddc-server/main.go +++ b/zddc/cmd/zddc-server/main.go @@ -65,7 +65,19 @@ func main() { // HTTP handler mux := http.NewServeMux() - mux.Handle("/", handler.AccessLogMiddleware(handler.CORSMiddleware(cfg, handler.ACLMiddleware(cfg, http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + // Middleware chain (outermost → innermost): + // ACLMiddleware — extract email from cfg.EmailHeader, store in + // request context. Outermost so the email is + // available to AccessLogMiddleware (Go's context + // propagates DOWN the chain via r.WithContext, not + // UP — so AccessLog can't read a context value set + // by an inner middleware after next.ServeHTTP + // returns). + // AccessLogMiddleware — structured per-request log; reads email from + // the context the outer ACL middleware set. + // CORSMiddleware — Origin / preflight handling. + // dispatch — the actual request handler. + mux.Handle("/", handler.ACLMiddleware(cfg, handler.AccessLogMiddleware(handler.CORSMiddleware(cfg, http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { dispatch(cfg, idx, logRing, w, r) }))))) diff --git a/zddc/internal/handler/middleware_test.go b/zddc/internal/handler/middleware_test.go new file mode 100644 index 0000000..cdaceb4 --- /dev/null +++ b/zddc/internal/handler/middleware_test.go @@ -0,0 +1,106 @@ +package handler + +import ( + "bytes" + "log/slog" + "net/http" + "net/http/httptest" + "strings" + "testing" + + "codeberg.org/VARASYS/ZDDC/zddc/internal/config" +) + +// TestAccessLogReadsEmailFromACLContext is a regression test for a bug where +// the access-log middleware logged email=anonymous on every request because +// it sat OUTSIDE the ACL middleware in the chain — Go's context propagates +// down via r.WithContext, not back up through the call chain, so an outer +// middleware can't read a context value set by an inner one after +// next.ServeHTTP returns. Fix: ACLMiddleware must wrap AccessLogMiddleware +// (ACL outer), not the other way around. +func TestAccessLogReadsEmailFromACLContext(t *testing.T) { + // Capture slog output so we can assert on what AccessLogMiddleware logged. + var buf bytes.Buffer + prev := slog.Default() + slog.SetDefault(slog.New(slog.NewTextHandler(&buf, nil))) + defer slog.SetDefault(prev) + + cfg := config.Config{EmailHeader: "X-Auth-Request-Email"} + noop := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusOK) + }) + + // Correct order: ACL is outer, AccessLog is inner. AccessLog reads + // email from the context ACL populated. + chain := ACLMiddleware(cfg, AccessLogMiddleware(noop)) + + req := httptest.NewRequest(http.MethodGet, "/foo", nil) + req.Header.Set("X-Auth-Request-Email", "alice@example.com") + chain.ServeHTTP(httptest.NewRecorder(), req) + + got := buf.String() + if !strings.Contains(got, `email=alice@example.com`) { + t.Errorf("expected access log to contain email=alice@example.com, got: %s", got) + } + if strings.Contains(got, `email=anonymous`) { + t.Errorf("access log fell back to email=anonymous despite header being set; ACL/AccessLog order may have regressed: %s", got) + } +} + +// TestAccessLogAnonymousWhenNoEmail confirms that when the configured email +// header is absent, the access log still records email=anonymous as expected. +func TestAccessLogAnonymousWhenNoEmail(t *testing.T) { + var buf bytes.Buffer + prev := slog.Default() + slog.SetDefault(slog.New(slog.NewTextHandler(&buf, nil))) + defer slog.SetDefault(prev) + + cfg := config.Config{EmailHeader: "X-Auth-Request-Email"} + noop := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusOK) + }) + + chain := ACLMiddleware(cfg, AccessLogMiddleware(noop)) + + req := httptest.NewRequest(http.MethodGet, "/foo", nil) + // Note: no X-Auth-Request-Email header set. + chain.ServeHTTP(httptest.NewRecorder(), req) + + got := buf.String() + if !strings.Contains(got, `email=anonymous`) { + t.Errorf("expected access log to contain email=anonymous when header absent, got: %s", got) + } +} + +// TestAccessLogOuterDoesNotSeeInnerContext is a guard test that locks down +// the underlying Go behavior: putting AccessLog OUTER and ACL INNER produces +// the original bug (email=anonymous despite the header being set). If this +// test ever fails, Go's context propagation has changed in a way that lets +// inner-middleware context values flow back up — which would mean the +// reordering fix can be reverted. +func TestAccessLogOuterDoesNotSeeInnerContext(t *testing.T) { + var buf bytes.Buffer + prev := slog.Default() + slog.SetDefault(slog.New(slog.NewTextHandler(&buf, nil))) + defer slog.SetDefault(prev) + + cfg := config.Config{EmailHeader: "X-Auth-Request-Email"} + noop := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusOK) + }) + + // Inverted order — the ORIGINAL buggy chain. + chain := AccessLogMiddleware(ACLMiddleware(cfg, noop)) + + req := httptest.NewRequest(http.MethodGet, "/foo", nil) + req.Header.Set("X-Auth-Request-Email", "alice@example.com") + chain.ServeHTTP(httptest.NewRecorder(), req) + + got := buf.String() + if strings.Contains(got, `email=alice@example.com`) { + t.Fatalf("Go's context propagation behavior changed — AccessLog (outer) somehow saw the email ACL (inner) set. The middleware reordering in main.go is no longer required and could be reverted. Log: %s", got) + } + if !strings.Contains(got, `email=anonymous`) { + t.Errorf("expected the inverted (buggy) chain to fall back to email=anonymous, got: %s", got) + } +}