diff --git a/internal/router/director.go b/internal/router/director.go index af6b417..0b5f208 100644 --- a/internal/router/director.go +++ b/internal/router/director.go @@ -77,13 +77,19 @@ func (d *director) Resolve( return Target{}, status.Errorf(codes.Unavailable, "router: no handler for upstream %q", upstream) } - d.logger.Debug( - "routing request", - tag.String("method", method), - tag.String("namespace", namespace), - tag.String("upstream", upstream), - tag.Stringer("outcome", outcome), - ) + // The decision is already counted in decisions_total; the entry is for an + // operator running at debug level. Gating on Enabled keeps requests at the + // default level from building the tags an entry they will never see would + // carry. + if d.logger.Enabled(logger.LevelDebug) { + d.logger.Debug( + "routing request", + tag.String("method", method), + tag.String("namespace", namespace), + tag.String("upstream", upstream), + tag.Stringer("outcome", outcome), + ) + } return Target{Upstream: upstream, Handle: handle}, nil } diff --git a/pkg/logger/logger.go b/pkg/logger/logger.go index 02aebc9..83daab9 100644 --- a/pkg/logger/logger.go +++ b/pkg/logger/logger.go @@ -29,6 +29,11 @@ type ( Logger interface { // Debug logs msg and tags at [LevelDebug]. Debug(msg string, tags ...tag.Tag) + // Enabled reports whether an entry at lvl would be recorded. Callers + // on hot paths may gate the construction of tags on it, since building + // arguments for an entry that is then discarded allocates. An + // unrecognized level answers true, so a bad value never hides logs. + Enabled(lvl Level) bool // Error logs msg and tags at [LevelError]. Error(msg string, tags ...tag.Tag) // Fatal logs msg and tags, then typically calls os.Exit(1). @@ -78,6 +83,12 @@ func Debug(msg string, tags ...tag.Tag) { defaultLogger.Debug(msg, tags...) } +// Enabled reports whether an entry at lvl would be recorded using the default +// logger. See [Logger.Enabled]. +func Enabled(lvl Level) bool { + return defaultLogger.Enabled(lvl) +} + // Error logs msg and tags at [LevelError] using the default logger. func Error(msg string, tags ...tag.Tag) { defaultLogger.Error(msg, tags...) diff --git a/pkg/logger/noop.go b/pkg/logger/noop.go index 87fbc2b..c12047b 100644 --- a/pkg/logger/noop.go +++ b/pkg/logger/noop.go @@ -18,6 +18,12 @@ func NewNoopLogger() *NoopLogger { func (n *NoopLogger) Debug(string, ...tag.Tag) { } +// Enabled implements [Logger]. NoopLogger discards every entry, whatever the +// level, so nothing it could log is worth building. +func (n *NoopLogger) Enabled(Level) bool { + return false +} + // Error implements [Logger] by discarding the entry. func (n *NoopLogger) Error(string, ...tag.Tag) { } diff --git a/pkg/logger/noop_test.go b/pkg/logger/noop_test.go index f8f5309..51ea267 100644 --- a/pkg/logger/noop_test.go +++ b/pkg/logger/noop_test.go @@ -24,4 +24,9 @@ func TestNoopLogger(t *testing.T) { }) require.Same(t, l, l.With(tag.String("k", "v"))) + + // Enabled reports false at every level, recognized or not, because every + // entry is discarded. + require.False(t, l.Enabled(logger.LevelDebug)) + require.False(t, l.Enabled(logger.Level(42))) } diff --git a/pkg/logger/test.go b/pkg/logger/test.go index f03f1ff..650145e 100644 --- a/pkg/logger/test.go +++ b/pkg/logger/test.go @@ -104,6 +104,12 @@ func (t *TestLogger) TagsOf(l Level, msg string) map[string]any { // Debug implements [Logger] by recording the entry at [LevelDebug]. func (t *TestLogger) Debug(msg string, tags ...tag.Tag) { t.record(LevelDebug, msg, tags) } +// Enabled implements [Logger]. TestLogger records every level, so entries are +// always worth building. +func (t *TestLogger) Enabled(Level) bool { + return true +} + // Error implements [Logger] by recording the entry at [LevelError]. func (t *TestLogger) Error(msg string, tags ...tag.Tag) { t.record(LevelError, msg, tags) } diff --git a/pkg/logger/test_test.go b/pkg/logger/test_test.go index 3e3bc1a..3cf132e 100644 --- a/pkg/logger/test_test.go +++ b/pkg/logger/test_test.go @@ -19,6 +19,10 @@ func TestTestLoggerContains(t *testing.T) { l.Info("hello") require.True(t, l.Contains("hello")) require.False(t, l.Contains("goodbye")) + + // TestLogger records every level, recognized or not. + require.True(t, l.Enabled(logger.LevelDebug)) + require.True(t, l.Enabled(logger.Level(42))) } func TestTestLoggerContainsEntry(t *testing.T) { diff --git a/pkg/logger/zero.go b/pkg/logger/zero.go index 554cb13..7d77e5d 100644 --- a/pkg/logger/zero.go +++ b/pkg/logger/zero.go @@ -29,6 +29,17 @@ func (l *ZeroLogger) Debug(msg string, tags ...tag.Tag) { logEvent(l.log.Debug(), msg, tags) } +// Enabled implements [Logger], reporting whether the configured level records +// entries at lvl. An unrecognized level answers true rather than inheriting +// [zeroLevel]'s Info mapping, so a bad value never hides logs. +func (l *ZeroLogger) Enabled(lvl Level) bool { + if lvl > LevelError { + return true + } + + return l.log.GetLevel() <= zeroLevel(lvl) +} + // Error implements [Logger]. func (l *ZeroLogger) Error(msg string, tags ...tag.Tag) { logEvent(l.log.Error(), msg, tags) diff --git a/pkg/logger/zero_test.go b/pkg/logger/zero_test.go index 95aa630..3dbd26f 100644 --- a/pkg/logger/zero_test.go +++ b/pkg/logger/zero_test.go @@ -48,6 +48,40 @@ func TestZeroLoggerLevels(t *testing.T) { } } +func TestZeroLoggerEnabled(t *testing.T) { + t.Parallel() + + tests := []struct { + name string + cfg logger.Level // configured level of the logger + ask logger.Level // level being asked about + want bool + }{ + {"debug config enables debug", logger.LevelDebug, logger.LevelDebug, true}, + {"debug config enables error", logger.LevelDebug, logger.LevelError, true}, + {"info config disables debug", logger.LevelInfo, logger.LevelDebug, false}, + {"info config enables info", logger.LevelInfo, logger.LevelInfo, true}, + {"warn config disables info", logger.LevelWarn, logger.LevelInfo, false}, + {"warn config enables warn", logger.LevelWarn, logger.LevelWarn, true}, + {"error config disables warn", logger.LevelError, logger.LevelWarn, false}, + {"error config enables error", logger.LevelError, logger.LevelError, true}, + // An unrecognized level is enabled at every configured level, so a + // bad value never hides logs. + {"unknown level is enabled at debug", logger.LevelDebug, logger.Level(42), true}, + {"unknown level is enabled at info", logger.LevelInfo, logger.Level(42), true}, + {"unknown level is enabled at error", logger.LevelError, logger.Level(42), true}, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + t.Parallel() + + l := logger.NewZeroLogger(&bytes.Buffer{}, tt.cfg) + require.Equal(t, tt.want, l.Enabled(tt.ask)) + }) + } +} + func TestZeroLoggerTags(t *testing.T) { t.Parallel()