[codex] log XFCC auth failure headers

app/auth/logging.go

@@ -0,0 +1,32 @@
+package authplugins
+
+import (
+	"io"
+	"log/slog"
+	"sync"
+)
+
+var (
+	discardLogger = slog.New(slog.NewTextHandler(io.Discard, nil))
+	loggerMu      sync.RWMutex
+	logger        = discardLogger
+)
+
+// SetLogger sets the logger used by auth plugins and returns the previous one.
+func SetLogger(l *slog.Logger) *slog.Logger {
+	if l == nil {
+		l = discardLogger
+	}
+	loggerMu.Lock()
+	defer loggerMu.Unlock()
+	prev := logger
+	logger = l
+	return prev
+}
+
+// Logger returns the logger used by auth plugins.
+func Logger() *slog.Logger {
+	loggerMu.RLock()
+	defer loggerMu.RUnlock()
+	return logger
+}

app/auth/plugins/envoy_xfcc/envoy_xfcc_test.go

@@ -1,10 +1,16 @@
 package envoy_xfcc
 
 import (
+	"bytes"
 	"context"
 	"encoding/json"
+	"log/slog"
 	"net/http"
+	"net/http/httptest"
+	"strings"
 	"testing"
+
+	authplugins "github.com/winhowes/AuthTranslator/app/auth"
 )
 
 func TestEnvoyXFCCSingleElementAllowed(t *testing.T) {
@@ -43,6 +49,82 @@ func TestEnvoyXFCCDisallowedURIFails(t *testing.T) {
 	}
 }
 
+func TestEnvoyXFCCAuthenticateFailureLogsHeaders(t *testing.T) {
+	var buf bytes.Buffer
+	oldLogger := authplugins.SetLogger(slog.New(slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})))
+	t.Cleanup(func() { authplugins.SetLogger(oldLogger) })
+
+	p := EnvoyXFCCAuth{}
+	cfg, err := p.ParseParams(map[string]interface{}{"allowed_uris": []string{"spiffe://allowed"}})
+	if err != nil {
+		t.Fatal(err)
+	}
+	r := httptest.NewRequest(http.MethodGet, "https://internal.example/resource", nil)
+	r.Header.Add("X-Forwarded-Client-Cert", "URI=spiffe://denied")
+	r.Header.Add("X-Forwarded-Client-Cert", "URI=spiffe://also-denied")
+	r.Header.Set("X-Debug-Header", "debug-value")
+
+	if p.Authenticate(context.Background(), r, cfg) {
+		t.Fatal("expected authentication to fail")
+	}
+
+	got := buf.String()
+	for _, want := range []string{
+		`"msg":"envoy_xfcc authentication failed"`,
+		`"reason":"authentication_failed"`,
+		`"configured_header":"X-Forwarded-Client-Cert"`,
+		"X-Forwarded-Client-Cert",
+		"spiffe://denied",
+		"spiffe://also-denied",
+		"X-Debug-Header",
+		"debug-value",
+	} {
+		if !strings.Contains(got, want) {
+			t.Fatalf("expected log to contain %q; got %s", want, got)
+		}
+	}
+}
+
+func TestEnvoyXFCCAuthenticateSuccessDoesNotLogHeaders(t *testing.T) {
+	var buf bytes.Buffer
+	oldLogger := authplugins.SetLogger(slog.New(slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelDebug})))
+	t.Cleanup(func() { authplugins.SetLogger(oldLogger) })
+
+	p := EnvoyXFCCAuth{}
+	cfg, err := p.ParseParams(map[string]interface{}{"allowed_uris": []string{"spiffe://allowed"}})
+	if err != nil {
+		t.Fatal(err)
+	}
+	r := httptest.NewRequest(http.MethodGet, "https://internal.example/resource", nil)
+	r.Header.Set("X-Forwarded-Client-Cert", "URI=spiffe://allowed")
+
+	if !p.Authenticate(context.Background(), r, cfg) {
+		t.Fatal("expected authentication to succeed")
+	}
+	if got := buf.String(); got != "" {
+		t.Fatalf("expected no auth failure log, got %s", got)
+	}
+}
+
+func TestEnvoyXFCCAuthenticateInvalidParamsFails(t *testing.T) {
+	p := EnvoyXFCCAuth{}
+	if p.Authenticate(context.Background(), nil, struct{}{}) {
+		t.Fatal("expected invalid params to fail")
+	}
+}
+
+func TestEnvoyXFCCIdentifyExtractionFailure(t *testing.T) {
+	p := EnvoyXFCCAuth{}
+	cfg, err := p.ParseParams(map[string]interface{}{"allowed_uris": []string{"spiffe://allowed"}})
+	if err != nil {
+		t.Fatal(err)
+	}
+	id, ok := p.Identify(&http.Request{Header: http.Header{}}, cfg)
+	if ok || id != "" {
+		t.Fatalf("expected identify failure, got id=%q ok=%v", id, ok)
+	}
+}
+
 func TestEnvoyXFCCMultipleNonIgnoredURIsFails(t *testing.T) {
 	p := EnvoyXFCCAuth{}
 	cfg, err := p.ParseParams(map[string]interface{}{"allowed_uri_prefixes": []string{"spiffe://"}})

app/auth/plugins/envoy_xfcc/incoming.go

@@ -40,8 +40,16 @@ func (e *EnvoyXFCCAuth) ParseParams(m map[string]interface{}) (interface{}, erro
 }
 
 func (e *EnvoyXFCCAuth) Authenticate(ctx context.Context, r *http.Request, p interface{}) bool {
-	_, ok := e.Identify(r, p)
-	return ok
+	cfg, ok := p.(*inParams)
+	if !ok {
+		logAuthFailure(ctx, r, "", "invalid_params")
+		return false
+	}
+	if _, ok := extractCallerIdentityFromValues(r.Header.Values(cfg.Header), cfg); !ok {
+		logAuthFailure(ctx, r, cfg.Header, "authentication_failed")
+		return false
+	}
+	return true
 }
 
 func (e *EnvoyXFCCAuth) Identify(r *http.Request, p interface{}) (string, bool) {
@@ -64,6 +72,21 @@ func (e *EnvoyXFCCAuth) StripAuth(r *http.Request, p interface{}) {
 	r.Header.Del(cfg.Header)
 }
 
+func logAuthFailure(ctx context.Context, r *http.Request, header, reason string) {
+	headers := http.Header{}
+	if r != nil {
+		headers = r.Header.Clone()
+	}
+	attrs := []any{
+		"reason", reason,
+		"headers", headers,
+	}
+	if header != "" {
+		attrs = append(attrs, "configured_header", header)
+	}
+	authplugins.Logger().WarnContext(ctx, "envoy_xfcc authentication failed", attrs...)
+}
+
 func extractCallerIdentityFromValues(values []string, cfg *inParams) (string, bool) {
 	if len(values) == 0 {
 		return "", false

app/auth/registry_test.go

@@ -1,7 +1,9 @@
 package authplugins
 
 import (
+	"bytes"
 	"context"
+	"log/slog"
 	"net/http"
 	"testing"
 )
@@ -56,3 +58,20 @@ func TestRegistryIncomingOutgoing(t *testing.T) {
 		t.Fatal("expected nil for unknown outgoing plugin")
 	}
 }
+
+func TestLoggerAccessors(t *testing.T) {
+	var buf bytes.Buffer
+	testLogger := slog.New(slog.NewTextHandler(&buf, nil))
+	previous := SetLogger(testLogger)
+	t.Cleanup(func() { SetLogger(previous) })
+
+	if got := Logger(); got != testLogger {
+		t.Fatal("expected configured logger")
+	}
+	if prev := SetLogger(nil); prev != testLogger {
+		t.Fatal("expected SetLogger to return previous logger")
+	}
+	if got := Logger(); got == nil || got == testLogger {
+		t.Fatal("expected nil logger to reset to discard logger")
+	}
+}

app/main.go

@@ -1564,6 +1564,7 @@ func main() {
 		handler = slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{Level: parseLevel(*logLevel)})
 	}
 	logger = slog.New(handler)
+	authplugins.SetLogger(logger)
 
 	if err := reload(); err != nil {
 		log.Fatal(err)