ZDDC/zddc/internal/handler/middleware_test.go

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(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, AccessLogMiddleware(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(nil, 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)
	}
}

// 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, AccessLogMiddleware(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)
	}
}