From edce50380c97332a3a23f940ea9a2d135c223185 Mon Sep 17 00:00:00 2001 From: Andy Bonventre Date: Wed, 15 Jul 2026 08:49:55 -0400 Subject: [PATCH 1/2] fix(otel): keep gatekeeper's own OTel diagnostics out of the log export bridge configureLogging fanned every slog record out to otelslog.NewHandler unconditionally, because the bridge's Enabled() defers to the OTel logger rather than the configured console level. That meant logOTelError's DEBUG record on a failed export was itself re-enqueued into the same OTel log-export pipeline that had just failed: failed export -> DEBUG diagnostic -> fanned out to the bridge -> re-enqueued -> next export fails carrying it -> another diagnostic, indefinitely while the collector is unreachable. Bounded (one record per export attempt, queue drops on overflow) but a genuine feedback loop. gatekeeper.OTelDiagnosticKey is a new marker attribute; logOTelError tags its record with it, and configureLogging now wraps the otelslog bridge handler in a filter that drops any marked record before forwarding. The console/file handler is unaffected and still sees every record. Fixes #48 --- CHANGELOG.md | 6 +++++ cmd/gatekeeper/main.go | 10 ++++++- cmd/gatekeeper/main_test.go | 53 +++++++++++++++++++++++++++++++++++++ gatekeeper.go | 49 +++++++++++++++++++++++++++++++++- gatekeeper_test.go | 42 +++++++++++++++++++++++++++++ 5 files changed, 158 insertions(+), 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index fb90e66..197797d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,12 @@ Gatekeeper is a standalone credential-injecting TLS-intercepting proxy. It trans Gatekeeper is pre-1.0. The configuration schema and credential source interface may change between minor versions. +## v0.17.2 — 2026-07-15 + +### Fixed + +- **Gatekeeper's own OTel diagnostics no longer feed back into the failing OTel log-export pipeline** — `configureLogging` fans every slog record out to `otelslog.NewHandler("gatekeeper")` unconditionally: the bridge's `Enabled` defers entirely to the OTel logger, not the console handler's configured level, so nothing before v0.17.0's DEBUG demotion (and nothing since) kept the bridge from seeing a record just because it was noisy. That meant `logOTelError` ([#47](https://github.com/majorcontext/gatekeeper/pull/47))'s own DEBUG record on a failed export was itself enqueued right back into the OTel log-export pipeline that had just failed: failed export → DEBUG diagnostic → diagnostic fanned out to the bridge → re-enqueued for the next export → that export fails too, now carrying the diagnostic → another diagnostic logged → re-enqueued again, and so on for as long as the collector stays unreachable. Bounded — one record per export attempt, and the batch queue drops on overflow rather than growing without limit — but a genuine feedback loop, not merely repeated independent failures. `gatekeeper.OTelDiagnosticKey` is a new exported marker attribute; `logOTelError` tags its DEBUG record with it, and `configureLogging`'s otelslog bridge handler is now wrapped in a filter that drops any record carrying the marker before forwarding — the console/file handler is unaffected and still logs every record, marked or not, at its configured level. Diagnostics about the OTel pipeline itself are now visible locally but never re-enter the pipeline they're reporting on ([#48](https://github.com/majorcontext/gatekeeper/issues/48)) + ## v0.17.1 — 2026-07-15 ### Fixed diff --git a/cmd/gatekeeper/main.go b/cmd/gatekeeper/main.go index 8167281..38a3725 100644 --- a/cmd/gatekeeper/main.go +++ b/cmd/gatekeeper/main.go @@ -46,8 +46,16 @@ func otelSDKDisabled(getenv func(string) string) bool { // with no backoff between attempts) produced an INFO log line that drowned // the canonical request lines whenever no collector was present. Logging // export errors at DEBUG here keeps them observable without the noise. +// +// The record is tagged with gatekeeper.OTelDiagnosticKey so +// configureLogging's otelslog bridge filter excludes it from the OTel log +// export pipeline. Without that exclusion, a failed OTel log export +// produces this very DEBUG record, which — like any other record — gets +// fanned out to the same OTel log pipeline that just failed; it's queued, +// fails on the next export attempt, produces another diagnostic, and so on +// indefinitely while the collector stays unreachable. func logOTelError(err error) { - slog.Default().Debug("otel error", "error", err) + slog.Default().Debug("otel error", "error", err, gatekeeper.OTelDiagnosticKey, true) } func initOTel(ctx context.Context, getenv func(string) string) (shutdown func(context.Context) error, err error) { diff --git a/cmd/gatekeeper/main_test.go b/cmd/gatekeeper/main_test.go index abd934b..4a949bc 100644 --- a/cmd/gatekeeper/main_test.go +++ b/cmd/gatekeeper/main_test.go @@ -2,9 +2,12 @@ package main import ( "bytes" + "context" "errors" "log/slog" "testing" + + "github.com/majorcontext/gatekeeper" ) // TestOtelSDKDisabled pins the OTEL_SDK_DISABLED semantics: per the @@ -90,3 +93,53 @@ func TestLogOTelError_DemotesToDebug(t *testing.T) { } }) } + +// recordingHandler is a minimal slog.Handler that captures every record +// passed to it, for inspecting the attributes a call site attached. +type recordingHandler struct { + records []slog.Record +} + +func (h *recordingHandler) Enabled(context.Context, slog.Level) bool { return true } + +func (h *recordingHandler) Handle(_ context.Context, r slog.Record) error { + h.records = append(h.records, r) + return nil +} + +func (h *recordingHandler) WithAttrs([]slog.Attr) slog.Handler { return h } +func (h *recordingHandler) WithGroup(string) slog.Handler { return h } + +// TestLogOTelError_MarksAsOTelDiagnostic encodes the fix for #48: gatekeeper.go's +// configureLogging fans every slog record out to the otelslog bridge +// unconditionally, so logOTelError's own DEBUG record on a failed OTel +// export was itself re-enqueued into the same failing OTel log-export +// pipeline — failed export -> DEBUG diagnostic -> re-enqueued -> next +// export fails carrying it -> another diagnostic, indefinitely while the +// collector is unreachable. logOTelError must mark its record with +// gatekeeper.OTelDiagnosticKey so configureLogging's bridge filter can keep +// it out of that pipeline. +func TestLogOTelError_MarksAsOTelDiagnostic(t *testing.T) { + var handler recordingHandler + prev := slog.Default() + t.Cleanup(func() { slog.SetDefault(prev) }) + slog.SetDefault(slog.New(&handler)) + + logOTelError(errors.New(`Post "https://localhost:4318/v1/logs": dial tcp [::1]:4318: connect: connection refused`)) + + if len(handler.records) != 1 { + t.Fatalf("got %d records, want 1", len(handler.records)) + } + + marked := false + handler.records[0].Attrs(func(a slog.Attr) bool { + if a.Key == gatekeeper.OTelDiagnosticKey && a.Value.Kind() == slog.KindBool && a.Value.Bool() { + marked = true + return false + } + return true + }) + if !marked { + t.Errorf("logOTelError record missing %s=true attribute, so configureLogging's bridge filter can't exclude it from the OTel log-export pipeline", gatekeeper.OTelDiagnosticKey) + } +} diff --git a/gatekeeper.go b/gatekeeper.go index 8384404..30e1b4d 100644 --- a/gatekeeper.go +++ b/gatekeeper.go @@ -79,11 +79,58 @@ func configureLogging(cfg LogConfig) (func(), error) { } else { handler = slog.NewTextHandler(w, opts) } - handler = newMultiHandler(handler, otelslog.NewHandler("gatekeeper")) + handler = newMultiHandler(handler, newOTelDiagnosticFilter(otelslog.NewHandler("gatekeeper"))) slog.SetDefault(slog.New(handler)) return cleanup, nil } +// OTelDiagnosticKey marks a log record as gatekeeper's own diagnostic about +// the OTel pipeline itself — currently, the OTel SDK/export error records +// cmd/gatekeeper's logOTelError logs at DEBUG. configureLogging's otelslog +// bridge handler excludes any record carrying this attribute (see +// newOTelDiagnosticFilter): without the exclusion, a failed OTel log export +// produces a DEBUG diagnostic that is itself fanned out to the same OTel +// log-export pipeline that just failed, so it gets queued, fails on the +// next export attempt, produces another diagnostic, and so on indefinitely +// while a collector is unreachable. The console/file handler still receives +// every record regardless of this marker. +const OTelDiagnosticKey = "otel_diagnostic" + +// otelDiagnosticFilter wraps a slog.Handler — the otelslog bridge — and +// drops any record carrying OTelDiagnosticKey before it reaches the wrapped +// handler, keeping gatekeeper's own OTel diagnostics out of the OTel log +// export pipeline. Records without the marker pass through unchanged. +type otelDiagnosticFilter struct { + slog.Handler +} + +func newOTelDiagnosticFilter(h slog.Handler) slog.Handler { + return &otelDiagnosticFilter{Handler: h} +} + +func (f *otelDiagnosticFilter) Handle(ctx context.Context, record slog.Record) error { + marked := false + record.Attrs(func(a slog.Attr) bool { + if a.Key == OTelDiagnosticKey { + marked = true + return false + } + return true + }) + if marked { + return nil + } + return f.Handler.Handle(ctx, record) +} + +func (f *otelDiagnosticFilter) WithAttrs(attrs []slog.Attr) slog.Handler { + return &otelDiagnosticFilter{Handler: f.Handler.WithAttrs(attrs)} +} + +func (f *otelDiagnosticFilter) WithGroup(name string) slog.Handler { + return &otelDiagnosticFilter{Handler: f.Handler.WithGroup(name)} +} + // multiHandler fans out log records to multiple slog handlers. type multiHandler struct { handlers []slog.Handler diff --git a/gatekeeper_test.go b/gatekeeper_test.go index b05a3bd..5d64169 100644 --- a/gatekeeper_test.go +++ b/gatekeeper_test.go @@ -2935,6 +2935,48 @@ func TestMultiHandler_WithGroup(t *testing.T) { } } +// fakeSlogHandler is a minimal slog.Handler that records every record it +// receives, for observing what actually reaches a handler in tests. +type fakeSlogHandler struct { + records []slog.Record +} + +func (f *fakeSlogHandler) Enabled(context.Context, slog.Level) bool { return true } + +func (f *fakeSlogHandler) Handle(_ context.Context, r slog.Record) error { + f.records = append(f.records, r) + return nil +} + +func (f *fakeSlogHandler) WithAttrs([]slog.Attr) slog.Handler { return f } +func (f *fakeSlogHandler) WithGroup(string) slog.Handler { return f } + +// TestOTelDiagnosticFilter_KeepsBridgeOutOfLoop encodes the fix for #48: +// gatekeeper's own OTel diagnostics (logOTelError's DEBUG record on a +// failed export) must never reach the otelslog bridge handler, or the +// diagnostic itself gets enqueued into the same failing OTel log-export +// pipeline — producing another diagnostic on the next failed attempt, and +// so on indefinitely while a collector is unreachable. The console handler +// must still see every record, marked or not. +func TestOTelDiagnosticFilter_KeepsBridgeOutOfLoop(t *testing.T) { + var console, bridge fakeSlogHandler + handler := newMultiHandler(&console, newOTelDiagnosticFilter(&bridge)) + logger := slog.New(handler) + + logger.Debug("otel error", "error", "dial tcp [::1]:4318: connect: connection refused", OTelDiagnosticKey, true) + logger.Info("normal request", "host", "example.com") + + if got := len(console.records); got != 2 { + t.Fatalf("console handler received %d records, want 2 (both records)", got) + } + if got := len(bridge.records); got != 1 { + t.Fatalf("bridge handler received %d records, want 1 (the marked diagnostic must be filtered out)", got) + } + if got := bridge.records[0].Message; got != "normal request" { + t.Errorf("bridge handler's surviving record = %q, want %q (the unmarked one)", got, "normal request") + } +} + func TestHTTPSTokenExchangeOutrankedByStatic(t *testing.T) { // End-to-end wiring check for outranked resolvers: a token-exchange // credential under a wildcard host is outranked by a static credential From 68ff74d7954e83784da87abec23a4a125b5fc08c Mon Sep 17 00:00:00 2001 From: Andy Bonventre Date: Wed, 15 Jul 2026 09:24:57 -0400 Subject: [PATCH 2/2] fix(otel): filter diagnostics on marker value, not mere presence The bridge filter matched any record carrying OTelDiagnosticKey regardless of value, so a future record setting the key to false would still be kept out of the export bridge. Key off the boolean value so only genuine diagnostics (true) are filtered. --- gatekeeper.go | 2 +- gatekeeper_test.go | 17 ++++++++++++----- 2 files changed, 13 insertions(+), 6 deletions(-) diff --git a/gatekeeper.go b/gatekeeper.go index 30e1b4d..3af549b 100644 --- a/gatekeeper.go +++ b/gatekeeper.go @@ -111,7 +111,7 @@ func newOTelDiagnosticFilter(h slog.Handler) slog.Handler { func (f *otelDiagnosticFilter) Handle(ctx context.Context, record slog.Record) error { marked := false record.Attrs(func(a slog.Attr) bool { - if a.Key == OTelDiagnosticKey { + if a.Key == OTelDiagnosticKey && a.Value.Kind() == slog.KindBool && a.Value.Bool() { marked = true return false } diff --git a/gatekeeper_test.go b/gatekeeper_test.go index 5d64169..dc149e8 100644 --- a/gatekeeper_test.go +++ b/gatekeeper_test.go @@ -2965,15 +2965,22 @@ func TestOTelDiagnosticFilter_KeepsBridgeOutOfLoop(t *testing.T) { logger.Debug("otel error", "error", "dial tcp [::1]:4318: connect: connection refused", OTelDiagnosticKey, true) logger.Info("normal request", "host", "example.com") + // A record carrying the key set to false is not a diagnostic and must + // still reach the bridge — the filter keys off the value, not mere + // presence of the attribute. + logger.Info("opted-in request", "host", "example.com", OTelDiagnosticKey, false) - if got := len(console.records); got != 2 { - t.Fatalf("console handler received %d records, want 2 (both records)", got) + if got := len(console.records); got != 3 { + t.Fatalf("console handler received %d records, want 3 (all records)", got) } - if got := len(bridge.records); got != 1 { - t.Fatalf("bridge handler received %d records, want 1 (the marked diagnostic must be filtered out)", got) + if got := len(bridge.records); got != 2 { + t.Fatalf("bridge handler received %d records, want 2 (only the true-marked diagnostic is filtered out)", got) } if got := bridge.records[0].Message; got != "normal request" { - t.Errorf("bridge handler's surviving record = %q, want %q (the unmarked one)", got, "normal request") + t.Errorf("bridge handler's first surviving record = %q, want %q", got, "normal request") + } + if got := bridge.records[1].Message; got != "opted-in request" { + t.Errorf("bridge handler's second surviving record = %q, want %q (key=false must pass through)", got, "opted-in request") } }