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, nil, nil, AccessLogMiddleware(cfg, nil, 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, nil, nil, AccessLogMiddleware(cfg, nil, 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(cfg, nil, ACLMiddleware(cfg, nil, nil, 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) } } // TestAccessLogMiddleware_AuditLoggerReceivesSameFields verifies the // optional audit-logger argument: when non-nil, it gets a parallel copy // of every access record. Used by main.go to tee access logs to a // rotating file in addition to stderr. func TestAccessLogMiddleware_AuditLoggerReceivesSameFields(t *testing.T) { var auditBuf bytes.Buffer auditLogger := slog.New(slog.NewJSONHandler(&auditBuf, &slog.HandlerOptions{Level: slog.LevelInfo})) noop := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusTeapot) _, _ = w.Write([]byte("hi")) }) cfg := config.Config{EmailHeader: "X-Auth-Request-Email"} chain := ACLMiddleware(cfg, nil, nil, AccessLogMiddleware(cfg, auditLogger, noop)) req := httptest.NewRequest(http.MethodGet, "/some/path", nil) req.Header.Set("X-Auth-Request-Email", "bob@example.com") chain.ServeHTTP(httptest.NewRecorder(), req) out := auditBuf.String() if !strings.Contains(out, `"email":"bob@example.com"`) { t.Errorf("audit log missing email field; got: %s", out) } if !strings.Contains(out, `"path":"/some/path"`) { t.Errorf("audit log missing path; got: %s", out) } if !strings.Contains(out, `"status":418`) { t.Errorf("audit log missing status code; got: %s", out) } }