feat(14-01): sunscreen redacting slog handler installed by every generated main

- Wrap redacts sensitive keys at any depth and scrubs Bearer, sk- and x-api-key shapes - InstallDefault is the first statement of the generated run; hello main regenerated - surf test pins that recovered panics echo no credential - sunscreen README, root modules row and the logging docs page
2026-10-03 20:01:36 +02:00
parent ee0004fb65
commit 7241704e93
11 changed files with 591 additions and 1 deletions
--- a/modules/sunscreen/README.md
+++ b/modules/sunscreen/README.md
@@ -0,0 +1,63 @@
+# sunscreen
+
+Credential-redacting slog handler that keeps API keys, tokens and passwords out of application logs.
+
+`import "git.golem15.com/golem15/summercms/modules/sunscreen"`
+
+## Overview
+
+`sunscreen` wraps any `log/slog` handler and rewrites every record before it is written: values of sensitive attribute keys become `[REDACTED]`, and credential shapes inside messages and string values are scrubbed. It is the SummerCMS counterpart of a Monolog tap that a WinterCMS application wires into its log channels to scrub contexts and messages. Every application `main` that `summer build` generates calls `sunscreen.InstallDefault(os.Stderr)` as its first statement, so the default logger, the standard `log` package and every plugin that falls back to `slog.Default` log through it from the start.
+
+## Features
+
+- Sensitive keys (`sunscreen.RedactedKeys`): `api_key`, `apikey`, `authorization`, `bearer`, `password`, `secret`, `token`, `webhook_secret`, `admin_password`, `openai_api_key`, `anthropic_api_key` and `perplexity_api_key`, compared case-insensitively at any group depth. The value of such an attribute becomes `sunscreen.Redacted`, whatever its kind.
+- Scrub patterns (`sunscreen.Scrub`): `Bearer <token>` becomes `Bearer [REDACTED]`, `sk-` followed by 20 or more key characters (dashed keys included) becomes `sk-[REDACTED]`, and `x-api-key: <value>` becomes `x-api-key: [REDACTED]`. The Bearer and x-api-key matches are case-insensitive.
+- Applied to the record message, string values, error values, byte slices and the formatted text of any other value; maps with string keys, such as `http.Header`, are redacted key by key.
+- `slog.LogValuer` values are resolved before redaction, groups are walked recursively, and attributes added with `WithAttrs` are redacted before they reach the wrapped handler.
+- `sunscreen.InstallDefault` builds a fresh text handler instead of wrapping the existing default, whose output goes through the `log` package that `slog.SetDefault` redirects back into the new handler.
+
+## Usage
+
+The generated `main` already installs it:
+
+```go
+func run(args []string, out io.Writer) error {
+	sunscreen.InstallDefault(os.Stderr)
+	cfg, err := compass.Load("config")
+	// ...
+}
+```
+
+To redact another handler, for example a JSON handler in a custom binary, wrap it:
+
+```go
+logger := slog.New(sunscreen.Wrap(slog.NewJSONHandler(os.Stderr, nil)))
+logger.Error("vendor call failed", "api_key", key, "err", err)
+// {"level":"ERROR","msg":"vendor call failed","api_key":"[REDACTED]","err":"..."}
+```
+
+Redaction is a safety net, not a licence: log ids and outcomes, never request bodies, tokens or arguments that carry them.
+
+## API reference
+
+| Identifier | Description |
+|------------|-------------|
+| `sunscreen.Wrap` | Returns a `slog.Handler` that redacts every record and every `WithAttrs` attribute before the wrapped handler sees it. Wrapping a sunscreen handler again returns it unchanged. |
+| `sunscreen.InstallDefault` | Makes a redacting text handler writing to the given writer the process default logger. |
+| `sunscreen.Scrub` | Replaces the Bearer, `sk-` and `x-api-key:` credential shapes in a string. |
+| `sunscreen.Redacted` | The replacement text, `[REDACTED]`. |
+| `sunscreen.RedactedKeys` | Returns a copy of the attribute keys whose values are always redacted. |
+
+## Dependencies
+
+- SummerCMS modules: none.
+- Third-party: none.
+- Standard library: `context`, `fmt`, `io`, `log/slog`, `reflect`, `regexp`, `slices`, `strings`.
+
+## Testing
+
+```sh
+go test ./modules/sunscreen/...
+```
+
+The tests log through the handler into a buffer and need no external services.
--- a/modules/sunscreen/example_test.go
+++ b/modules/sunscreen/example_test.go
@@ -0,0 +1,30 @@
+package sunscreen_test
+
+import (
+	"errors"
+	"log/slog"
+	"os"
+
+	"git.golem15.com/golem15/summercms/modules/sunscreen"
+)
+
+func ExampleWrap() {
+	// Drop the time so the output is stable; a real application keeps it.
+	plain := slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{
+		ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
+			if len(groups) == 0 && a.Key == slog.TimeKey {
+				return slog.Attr{}
+			}
+			return a
+		},
+	})
+	logger := slog.New(sunscreen.Wrap(plain))
+
+	logger.Info("vendor call failed",
+		"api_key", "live-key-123",
+		slog.Group("request", slog.String("Authorization", "Bearer abc.def")),
+		"err", errors.New("401 for key sk-abcdefghijklmnopqrstuvwx"),
+	)
+	// Output:
+	// level=INFO msg="vendor call failed" api_key=[REDACTED] request.Authorization=[REDACTED] err="401 for key sk-[REDACTED]"
+}
--- a/modules/sunscreen/sunscreen.go
+++ b/modules/sunscreen/sunscreen.go
@@ -0,0 +1,198 @@
+// Package sunscreen is a credential-redacting slog handler that keeps API
+// keys, tokens and passwords out of application logs.
+package sunscreen
+
+import (
+	"context"
+	"fmt"
+	"io"
+	"log/slog"
+	"reflect"
+	"regexp"
+	"slices"
+	"strings"
+)
+
+// Redacted replaces the value of a sensitive attribute and the secret part
+// of a scrubbed string.
+const Redacted = "[REDACTED]"
+
+var redactedKeys = []string{
+	"api_key",
+	"apikey",
+	"authorization",
+	"bearer",
+	"password",
+	"secret",
+	"token",
+	"webhook_secret",
+	"admin_password",
+	"openai_api_key",
+	"anthropic_api_key",
+	"perplexity_api_key",
+}
+
+var keySet = func() map[string]struct{} {
+	m := make(map[string]struct{}, len(redactedKeys))
+	for _, k := range redactedKeys {
+		m[k] = struct{}{}
+	}
+	return m
+}()
+
+// RedactedKeys returns the attribute keys whose values are always replaced
+// with Redacted. Keys are compared case-insensitively, at any group depth.
+func RedactedKeys() []string {
+	return slices.Clone(redactedKeys)
+}
+
+func sensitive(key string) bool {
+	_, ok := keySet[strings.ToLower(key)]
+	return ok
+}
+
+var patterns = []struct {
+	re   *regexp.Regexp
+	repl string
+}{
+	{regexp.MustCompile(`(?i)Bearer\s+[A-Za-z0-9._\-+/=]+`), "Bearer " + Redacted},
+	// Also covers dashed keys such as sk-ant-..., which the reference
+	// pattern sk-[A-Za-z0-9]{20,} misses.
+	{regexp.MustCompile(`sk-[A-Za-z0-9_\-]{20,}`), "sk-" + Redacted},
+	{regexp.MustCompile(`(?i)x-api-key:\s*[^\s,]+`), "x-api-key: " + Redacted},
+}
+
+// Scrub replaces credential shapes in s: "Bearer <token>" becomes
+// "Bearer [REDACTED]", "sk-" followed by 20 or more key characters becomes
+// "sk-[REDACTED]", and "x-api-key: <value>" becomes "x-api-key: [REDACTED]".
+// The Bearer and x-api-key matches are case-insensitive.
+func Scrub(s string) string {
+	for _, p := range patterns {
+		s = p.re.ReplaceAllString(s, p.repl)
+	}
+	return s
+}
+
+// Wrap returns a handler that redacts every record before next sees it: the
+// message is scrubbed; attributes whose key is one of RedactedKeys get the
+// value Redacted, at any group depth; LogValuer values are resolved first;
+// string values, error values and other formatted values are scrubbed; maps
+// with string keys are redacted key by key. Attributes added with WithAttrs
+// are redacted the same way before they reach next.
+func Wrap(next slog.Handler) slog.Handler {
+	if h, ok := next.(*handler); ok {
+		return h
+	}
+	return &handler{next: next}
+}
+
+// InstallDefault makes a redacting text handler writing to w the process
+// default logger (slog.SetDefault), so plugins that fall back to
+// slog.Default and the standard log package both log through it. It builds
+// a fresh slog.TextHandler instead of wrapping the existing default, whose
+// output goes through the log package that SetDefault redirects back here.
+func InstallDefault(w io.Writer) {
+	slog.SetDefault(slog.New(Wrap(slog.NewTextHandler(w, nil))))
+}
+
+type handler struct {
+	next slog.Handler
+}
+
+func (h *handler) Enabled(ctx context.Context, level slog.Level) bool {
+	return h.next.Enabled(ctx, level)
+}
+
+func (h *handler) Handle(ctx context.Context, r slog.Record) error {
+	out := slog.NewRecord(r.Time, r.Level, Scrub(r.Message), r.PC)
+	r.Attrs(func(a slog.Attr) bool {
+		out.AddAttrs(redactAttr(a))
+		return true
+	})
+	return h.next.Handle(ctx, out)
+}
+
+func (h *handler) WithAttrs(attrs []slog.Attr) slog.Handler {
+	red := make([]slog.Attr, len(attrs))
+	for i, a := range attrs {
+		red[i] = redactAttr(a)
+	}
+	return &handler{next: h.next.WithAttrs(red)}
+}
+
+func (h *handler) WithGroup(name string) slog.Handler {
+	return &handler{next: h.next.WithGroup(name)}
+}
+
+func redactAttr(a slog.Attr) slog.Attr {
+	if sensitive(a.Key) {
+		return slog.String(a.Key, Redacted)
+	}
+	v := a.Value.Resolve()
+	switch v.Kind() {
+	case slog.KindGroup:
+		group := v.Group()
+		out := make([]slog.Attr, len(group))
+		for i, g := range group {
+			out[i] = redactAttr(g)
+		}
+		return slog.Attr{Key: a.Key, Value: slog.GroupValue(out...)}
+	case slog.KindString:
+		return slog.String(a.Key, Scrub(v.String()))
+	case slog.KindAny:
+		return slog.Attr{Key: a.Key, Value: redactAny(v.Any())}
+	default:
+		return slog.Attr{Key: a.Key, Value: v}
+	}
+}
+
+func redactAny(x any) slog.Value {
+	switch t := x.(type) {
+	case nil:
+		return slog.AnyValue(nil)
+	case error:
+		return slog.StringValue(Scrub(t.Error()))
+	case []byte:
+		return slog.StringValue(Scrub(string(t)))
+	}
+	if m, ok := redactMap(x); ok {
+		return slog.AnyValue(m)
+	}
+	text := fmt.Sprintf("%+v", x)
+	if scrubbed := Scrub(text); scrubbed != text {
+		return slog.StringValue(scrubbed)
+	}
+	return slog.AnyValue(x)
+}
+
+// redactMap copies a map with string keys (including http.Header and other
+// named map types), redacting sensitive keys and scrubbing the rest.
+func redactMap(x any) (map[string]any, bool) {
+	rv := reflect.ValueOf(x)
+	if rv.Kind() != reflect.Map || rv.Type().Key().Kind() != reflect.String {
+		return nil, false
+	}
+	out := make(map[string]any, rv.Len())
+	iter := rv.MapRange()
+	for iter.Next() {
+		k := iter.Key().String()
+		if sensitive(k) {
+			out[k] = Redacted
+			continue
+		}
+		val := iter.Value().Interface()
+		switch t := val.(type) {
+		case string:
+			out[k] = Scrub(t)
+		case []string:
+			s := make([]string, len(t))
+			for i, e := range t {
+				s[i] = Scrub(e)
+			}
+			out[k] = s
+		default:
+			out[k] = redactAny(val).Any()
+		}
+	}
+	return out, true
+}
--- a/modules/sunscreen/sunscreen_test.go
+++ b/modules/sunscreen/sunscreen_test.go
@@ -0,0 +1,144 @@
+package sunscreen
+
+import (
+	"bytes"
+	"errors"
+	"log"
+	"log/slog"
+	"net/http"
+	"strings"
+	"testing"
+)
+
+const (
+	skKey   = "sk-abcdefghijklmnopqrstuvwxyz123456"
+	antKey  = "sk-ant-api03-abcdefghijklmnopqrstuvwxyz"
+	bearer  = "eyJhbGciOiJIUzI1NiJ9.payload.sig"
+	apiKey  = "live-api-key-value"
+	passwd  = "hunter2-secret-pass"
+	nested  = "nested-token-value"
+	valuerV = "valuer-secret-value"
+)
+
+type secretValuer struct{}
+
+func (secretValuer) LogValue() slog.Value {
+	return slog.GroupValue(slog.String("Token", valuerV), slog.String("name", "alice"))
+}
+
+type config struct {
+	Endpoint string
+	Header   string
+}
+
+func newTestLogger(buf *bytes.Buffer) *slog.Logger {
+	return slog.New(Wrap(slog.NewTextHandler(buf, &slog.HandlerOptions{Level: slog.LevelDebug})))
+}
+
+func TestRedactHandler(t *testing.T) {
+	var buf bytes.Buffer
+	logger := newTestLogger(&buf)
+
+	logger.With("API_KEY", apiKey, slog.Group("ctx", slog.String("password", passwd))).
+		WithGroup("req").
+		Info("calling vendor with Bearer "+bearer,
+			"Authorization", "Bearer "+bearer,
+			"user", 7,
+			slog.Group("deep", slog.Group("deeper", slog.String("Secret", nested), slog.String("note", "key "+skKey))),
+			"valuer", secretValuer{},
+			"err", errors.New("upstream said: x-api-key: "+apiKey+", retry"),
+			"headers", http.Header{"Authorization": {"Bearer " + bearer}, "Accept": {"application/json"}},
+			"payload", map[string]any{"OpenAI_API_Key": skKey, "inner": map[string]string{"webhook_secret": nested, "ok": "fine"}},
+			"cfg", config{Endpoint: "https://api.example.com", Header: "x-api-key: " + apiKey},
+			"raw", []byte("token sk-"+strings.Repeat("Z", 24)),
+			"anthropic", antKey,
+		)
+	out := buf.String()
+	for _, secret := range []string{skKey, antKey, bearer, apiKey, passwd, nested, valuerV, strings.Repeat("Z", 24)} {
+		if strings.Contains(out, secret) {
+			t.Fatalf("log leaks %q:\n%s", secret, out)
+		}
+	}
+	for _, want := range []string{
+		"API_KEY=[REDACTED]",
+		"ctx.password=[REDACTED]",
+		"req.Authorization=[REDACTED]",
+		"req.user=7",
+		"req.deep.deeper.Secret=[REDACTED]",
+		`req.deep.deeper.note="key sk-[REDACTED]"`,
+		"req.valuer.Token=[REDACTED]",
+		"req.valuer.name=alice",
+		`x-api-key: [REDACTED]`,
+		"Bearer [REDACTED]",
+		"ok:fine",
+		"https://api.example.com",
+	} {
+		if !strings.Contains(out, want) {
+			t.Fatalf("log missing %q:\n%s", want, out)
+		}
+	}
+
+	// Enabled follows the wrapped handler; wrapping twice is a no-op.
+	quiet := Wrap(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelWarn}))
+	if quiet.Enabled(t.Context(), slog.LevelInfo) || !quiet.Enabled(t.Context(), slog.LevelError) {
+		t.Fatal("Enabled must follow the wrapped handler")
+	}
+	if Wrap(quiet) != quiet {
+		t.Fatal("Wrap of a sunscreen handler must return it unchanged")
+	}
+
+	keys := RedactedKeys()
+	keys[0] = "mutated"
+	if RedactedKeys()[0] != "api_key" || len(keys) != 12 {
+		t.Fatalf("RedactedKeys must return a copy of the 12 keys: %v", RedactedKeys())
+	}
+
+	buf.Reset()
+	logger.Info("plain", "nil", nil, "count", 3, "ok", true)
+	if !strings.Contains(buf.String(), "nil=<nil>") || !strings.Contains(buf.String(), "count=3") {
+		t.Fatalf("non-secret values changed: %s", buf.String())
+	}
+}
+
+func TestScrub(t *testing.T) {
+	cases := []struct{ in, want string }{
+		{"Authorization: Bearer abc.DEF-123_+/=", "Authorization: Bearer [REDACTED]"},
+		{"bearer   lower.case.token", "Bearer [REDACTED]"},
+		{"key=" + skKey + " end", "key=sk-[REDACTED] end"},
+		{antKey, "sk-[REDACTED]"},
+		{"sk-short", "sk-short"},
+		{"X-API-KEY: abc123, next", "x-api-key: [REDACTED], next"},
+		{"x-api-key:abc", "x-api-key: [REDACTED]"},
+		{"nothing secret here: 42 albums", "nothing secret here: 42 albums"},
+		{"", ""},
+	}
+	for _, c := range cases {
+		if got := Scrub(c.in); got != c.want {
+			t.Errorf("Scrub(%q) = %q, want %q", c.in, got, c.want)
+		}
+	}
+	if Scrub(Scrub("Bearer abc")) != "Bearer [REDACTED]" {
+		t.Fatal("Scrub must be idempotent")
+	}
+}
+
+func TestInstallDefault(t *testing.T) {
+	prev := slog.Default()
+	prevFlags, prevWriter := log.Flags(), log.Writer()
+	t.Cleanup(func() {
+		slog.SetDefault(prev)
+		log.SetFlags(prevFlags)
+		log.SetOutput(prevWriter)
+	})
+	var buf bytes.Buffer
+	InstallDefault(&buf)
+	slog.Info("login", "password", passwd)
+	log.Printf("legacy log with Bearer %s", bearer)
+	out := buf.String()
+	if strings.Contains(out, passwd) || strings.Contains(out, bearer) {
+		t.Fatalf("default logger leaks:\n%s", out)
+	}
+	if !strings.Contains(out, "password=[REDACTED]") || !strings.Contains(out, "Bearer [REDACTED]") {
+		t.Fatalf("default logger output:\n%s", out)
+	}
+}
--- a/modules/surf/recover_redaction_test.go
+++ b/modules/surf/recover_redaction_test.go
@@ -0,0 +1,74 @@
+package surf
+
+import (
+	"bytes"
+	"errors"
+	"log/slog"
+	"net/http"
+	"net/http/httptest"
+	"strings"
+	"testing"
+
+	"git.golem15.com/golem15/summercms/modules/pact"
+	"git.golem15.com/golem15/summercms/modules/sunscreen"
+)
+
+// TestRecoverHidesPanicDetails pins the SafeExceptionResponse behaviour: a
+// panicking handler's message, here carrying credentials, never reaches the
+// response in either group type, and a log record of the panic written
+// through a sunscreen handler carries neither credential.
+func TestRecoverHidesPanicDetails(t *testing.T) {
+	const skKey = "sk-abcdefghijklmnopqrstuvwxyz0123"
+	const token = "eyJhbGciOiJIUzI1NiJ9.claims.signature"
+	panicErr := errors.New("vendor rejected key " + skKey + " with Authorization: Bearer " + token)
+
+	prev := slog.Default()
+	t.Cleanup(func() { slog.SetDefault(prev) })
+	var logs bytes.Buffer
+	sunscreen.InstallDefault(&logs)
+
+	r := New(nil)
+	r.GroupRaw("/oauth", nil, func(g pact.Router) {
+		g.Post("/token", func(http.ResponseWriter, *http.Request) { panic(panicErr) })
+	})
+	r.Post("/api/v1/recognize", func(http.ResponseWriter, *http.Request) { panic(panicErr) })
+	h, err := r.compile()
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	cases := []struct {
+		path, body, contentType string
+	}{
+		{"/api/v1/recognize", `{"error":true,"message":"Internal server error"}`, "application/json"},
+		{"/oauth/token", "", ""},
+	}
+	for _, c := range cases {
+		rec := httptest.NewRecorder()
+		h.ServeHTTP(rec, httptest.NewRequest(http.MethodPost, c.path, nil))
+		if rec.Code != http.StatusInternalServerError {
+			t.Fatalf("%s status = %d", c.path, rec.Code)
+		}
+		body := strings.TrimSpace(rec.Body.String())
+		if body != c.body {
+			t.Fatalf("%s body = %q, want the opaque %q", c.path, body, c.body)
+		}
+		if got := rec.Header().Get("Content-Type"); got != c.contentType {
+			t.Fatalf("%s Content-Type = %q", c.path, got)
+		}
+		for _, secret := range []string{skKey, token, "vendor rejected"} {
+			if strings.Contains(rec.Body.String(), secret) {
+				t.Fatalf("%s response echoes %q", c.path, secret)
+			}
+		}
+	}
+
+	slog.Error("handler panicked", "err", panicErr, "path", "/api/v1/recognize")
+	out := logs.String()
+	if strings.Contains(out, skKey) || strings.Contains(out, token) {
+		t.Fatalf("log record leaks a credential:\n%s", out)
+	}
+	if !strings.Contains(out, "sk-[REDACTED]") || !strings.Contains(out, "Bearer [REDACTED]") {
+		t.Fatalf("log record not scrubbed as expected:\n%s", out)
+	}
+}