| 1 | package logger |
| 2 | |
| 3 | import ( |
| 4 | "context" |
| 5 | "log/slog" |
| 6 | "reflect" |
| 7 | "runtime" |
| 8 | "strings" |
| 9 | "sync" |
| 10 | "testing" |
| 11 | |
| 12 | "github.com/stretchr/testify/assert" |
| 13 | ) |
| 14 | |
| 15 | type pcCaptureHandler struct { |
| 16 | mu sync.Mutex |
| 17 | pcs []uintptr |
| 18 | } |
| 19 | |
| 20 | const expectedLoggerPrefix = "github.com/netdata/netdata/go/plugins/logger." |
| 21 | |
| 22 | func (h *pcCaptureHandler) Enabled(context.Context, slog.Level) bool { |
| 23 | return true |
| 24 | } |
| 25 | |
| 26 | func (h *pcCaptureHandler) Handle(_ context.Context, r slog.Record) error { |
| 27 | h.mu.Lock() |
| 28 | defer h.mu.Unlock() |
| 29 | h.pcs = append(h.pcs, r.PC) |
| 30 | return nil |
| 31 | } |
| 32 | |
| 33 | func (h *pcCaptureHandler) WithAttrs(_ []slog.Attr) slog.Handler { |
| 34 | return h |
| 35 | } |
| 36 | |
| 37 | func (h *pcCaptureHandler) WithGroup(_ string) slog.Handler { |
| 38 | return h |
| 39 | } |
| 40 | |
| 41 | func (h *pcCaptureHandler) lastFunction() string { |
| 42 | h.mu.Lock() |
| 43 | defer h.mu.Unlock() |
| 44 | if len(h.pcs) == 0 { |
| 45 | return "" |
| 46 | } |
| 47 | fn := runtime.FuncForPC(h.pcs[len(h.pcs)-1]) |
| 48 | if fn == nil { |
| 49 | return "" |
| 50 | } |
| 51 | return fn.Name() |
| 52 | } |
| 53 | |
| 54 | func newDepthTestLogger(isTerminal bool) (*Logger, *pcCaptureHandler) { |
| 55 | h := &pcCaptureHandler{} |
| 56 | var sh slog.Handler = h |
| 57 | if isTerminal { |
| 58 | sh = withTerminalCallDepth(4, sh) |
| 59 | } else { |
| 60 | sh = withCallDepth(4, sh) |
| 61 | } |
| 62 | return &Logger{sl: slog.New(sh), rl: newRateLimiter()}, h |
| 63 | } |
| 64 | |
| 65 | //go:noinline |
| 66 | func emitWhenInfo(l *Logger) { |
| 67 | l.When(true).Info("x") |
| 68 | } |
| 69 | |
| 70 | func TestCallDepthTerminalDebugUsesDynamicResolverForWhen(t *testing.T) { |
| 71 | setTestLevel(t, slog.LevelDebug) |
| 72 | |
| 73 | l, h := newDepthTestLogger(true) |
| 74 | emitWhenInfo(l) |
| 75 | |
| 76 | fn := h.lastFunction() |
| 77 | assert.NotEmpty(t, fn) |
| 78 | assert.False(t, strings.HasPrefix(fn, expectedLoggerPrefix), "expected non-logger caller, got %q", fn) |
| 79 | } |
| 80 | |
| 81 | func TestCallDepthTerminalDebugUsesDynamicResolverForOnce(t *testing.T) { |
| 82 | setTestLevel(t, slog.LevelDebug) |
| 83 | |
| 84 | l, h := newDepthTestLogger(true) |
| 85 | l.Once("k").Info("x") |
| 86 | |
| 87 | fn := h.lastFunction() |
| 88 | assert.NotEmpty(t, fn) |
| 89 | assert.False(t, strings.HasPrefix(fn, expectedLoggerPrefix), "expected non-logger caller, got %q", fn) |
| 90 | } |
| 91 | |
| 92 | func TestCallDepthGatingUsesFixedPathOutsideTerminalDebug(t *testing.T) { |
| 93 | t.Run("terminal non-debug", func(t *testing.T) { |
| 94 | setTestLevel(t, slog.LevelInfo) |
| 95 | |
| 96 | l, h := newDepthTestLogger(true) |
| 97 | emitWhenInfo(l) |
| 98 | |
| 99 | fn := h.lastFunction() |
| 100 | assert.NotEmpty(t, fn) |
| 101 | assert.True(t, strings.HasPrefix(fn, expectedLoggerPrefix), "expected logger frame with fixed path, got %q", fn) |
| 102 | }) |
| 103 | |
| 104 | t.Run("non-terminal debug", func(t *testing.T) { |
| 105 | setTestLevel(t, slog.LevelDebug) |
| 106 | |
| 107 | l, h := newDepthTestLogger(false) |
| 108 | emitWhenInfo(l) |
| 109 | |
| 110 | fn := h.lastFunction() |
| 111 | assert.NotEmpty(t, fn) |
| 112 | assert.True(t, strings.HasPrefix(fn, expectedLoggerPrefix), "expected logger frame with fixed path, got %q", fn) |
| 113 | }) |
| 114 | } |
| 115 | |
| 116 | func TestCallerSkipPrefixMatchesRuntimeLoggerPath(t *testing.T) { |
| 117 | fn := runtime.FuncForPC(reflect.ValueOf((*Logger).Info).Pointer()) |
| 118 | if assert.NotNil(t, fn) { |
| 119 | assert.True(t, strings.HasPrefix(fn.Name(), expectedLoggerPrefix)) |
| 120 | } |
| 121 | assert.Equal(t, expectedLoggerPrefix, callerSkipPrefixes[0]) |
| 122 | } |
| 123 | |
| 124 | func TestResolveCallerPCFallbackMatchesFixedPath(t *testing.T) { |
| 125 | setTestLevel(t, slog.LevelDebug) |
| 126 | |
| 127 | orig := callerSkipPrefixes |
| 128 | callerSkipPrefixes = []string{""} // force fallback branch |
| 129 | t.Cleanup(func() { |
| 130 | callerSkipPrefixes = orig |
| 131 | }) |
| 132 | |
| 133 | fixedLogger, fixedHandler := newDepthTestLogger(false) |
| 134 | emitWhenInfo(fixedLogger) |
| 135 | expected := fixedHandler.lastFunction() |
| 136 | assert.NotEmpty(t, expected) |
| 137 | |
| 138 | dynamicLogger, dynamicHandler := newDepthTestLogger(true) |
| 139 | emitWhenInfo(dynamicLogger) |
| 140 | actual := dynamicHandler.lastFunction() |
| 141 | assert.NotEmpty(t, actual) |
| 142 | |
| 143 | assert.Equal(t, expected, actual) |
| 144 | } |