From 85f861ccf0cb11afd0d23ab59ab6724aee19e2d6 Mon Sep 17 00:00:00 2001 From: n30nex Date: Sat, 12 Sep 2026 21:13:14 -0400 Subject: [PATCH] feat(cache): add payload-free debug cache diagnostics --- internal/cache/cache.go | 5 +++ internal/cache/logging_test.go | 64 ++++++++++++++++++++++++++++++++++ 2 files changed, 69 insertions(+) create mode 100644 internal/cache/logging_test.go diff --git a/internal/cache/cache.go b/internal/cache/cache.go index abee276..9237754 100644 --- a/internal/cache/cache.go +++ b/internal/cache/cache.go @@ -11,6 +11,7 @@ import ( "context" "encoding/json" "errors" + "log/slog" "time" "github.com/MeshCore-Beacon/beacon-server/internal/config" @@ -86,11 +87,13 @@ func getOrSet[T any](ctx context.Context, c *Client, key string, ttl time.Durati raw, err := c.rdb.Get(ctx, key).Bytes() if err != nil && !errors.Is(err, redis.Nil) { // real Redis error, degrade gracefully + slog.DebugContext(ctx, "cache bypass", "component", "cache", "reason", "read_error") return fetch() } var zero, out T if errors.Is(err, redis.Nil) { // cache miss — fetch, store, return + slog.DebugContext(ctx, "cache miss", "component", "cache") val, err := fetch() if err != nil { return zero, err @@ -104,6 +107,7 @@ func getOrSet[T any](ctx context.Context, c *Client, key string, ttl time.Durati } if err = json.Unmarshal(raw, &out); err != nil { // corrupt cache entry — overwrite it + slog.DebugContext(ctx, "cache invalid entry", "component", "cache") val, err := fetch() if err != nil { return zero, err @@ -115,5 +119,6 @@ func getOrSet[T any](ctx context.Context, c *Client, key string, ttl time.Durati _ = c.rdb.Set(ctx, key, data, ttl) return val, nil } + slog.DebugContext(ctx, "cache hit", "component", "cache") return out, nil } diff --git a/internal/cache/logging_test.go b/internal/cache/logging_test.go new file mode 100644 index 0000000..d16eed5 --- /dev/null +++ b/internal/cache/logging_test.go @@ -0,0 +1,64 @@ +// Copyright 2026 Beacon Contributors +// SPDX-License-Identifier: AGPL-3.0-or-later + +package cache + +import ( + "bytes" + "context" + "encoding/json" + "log" + "log/slog" + "strings" + "testing" + "time" +) + +func TestCacheDiagnostics(t *testing.T) { + previous, writer, flags := slog.Default(), log.Writer(), log.Flags() + t.Cleanup(func() { slog.SetDefault(previous); log.SetOutput(writer); log.SetFlags(flags) }) + var out bytes.Buffer + slog.SetDefault(slog.New(slog.NewJSONHandler(&out, &slog.HandlerOptions{Level: slog.LevelDebug}))) + c, mr := newTestClient(t) + key, value := "private-cache-key", "private-cache-value" + calls := 0 + fetch := func() (string, error) { calls++; return value, nil } + for i := 0; i < 2; i++ { + got, err := getOrSet(context.Background(), c, key, time.Minute, fetch) + if err != nil || got != value { + t.Fatalf("cache result changed: %v", err) + } + } + if calls != 1 { + t.Fatalf("fetches=%d, want 1", calls) + } + mr.Set(key, "invalid JSON") + if _, err := getOrSet(context.Background(), c, key, time.Minute, fetch); err != nil { + t.Fatal(err) + } + lines := bytes.Split(bytes.TrimSpace(out.Bytes()), []byte("\n")) + want := []string{"cache miss", "cache hit", "cache invalid entry"} + if len(lines) != len(want) { + t.Fatalf("got %d records, want %d", len(lines), len(want)) + } + for i, line := range lines { + var record map[string]any + if err := json.Unmarshal(line, &record); err != nil { + t.Fatal(err) + } + if record["component"] != "cache" || record["level"] != "DEBUG" || record["msg"] != want[i] { + t.Fatalf("unexpected record: %v", record) + } + } + if strings.Contains(out.String(), key) || strings.Contains(out.String(), value) { + t.Fatal("cache key or payload leaked") + } + out.Reset() + slog.SetDefault(slog.New(slog.NewJSONHandler(&out, nil))) + if _, err := getOrSet(context.Background(), c, key, time.Minute, fetch); err != nil { + t.Fatal(err) + } + if out.Len() != 0 { + t.Fatal("debug diagnostics appeared at info level") + } +}