github.com/livekit/protocol@v1.39.3/logger/logger_test.go (about)

     1  package logger
     2  
     3  import (
     4  	"fmt"
     5  	"runtime"
     6  	"strings"
     7  	"testing"
     8  
     9  	"github.com/stretchr/testify/require"
    10  	"go.uber.org/zap"
    11  	"go.uber.org/zap/zapcore"
    12  
    13  	"github.com/livekit/protocol/logger/testutil"
    14  	"github.com/livekit/protocol/logger/zaputil"
    15  	"github.com/livekit/protocol/utils/must"
    16  )
    17  
    18  func zapLoggerCore(l Logger) zapcore.Core {
    19  	return l.(ZapLogger).ToZap().Desugar().Core()
    20  }
    21  
    22  func TestLoggerComponent(t *testing.T) {
    23  	t.Run("inheriting parent level", func(t *testing.T) {
    24  		l, err := NewZapLogger(&Config{
    25  			Level: "info",
    26  			ComponentLevels: map[string]string{
    27  				"mycomponent": "warn",
    28  			},
    29  		})
    30  		require.NoError(t, err)
    31  
    32  		sub := zapLoggerCore(l.WithComponent("sub"))
    33  		require.True(t, sub.Enabled(zapcore.InfoLevel))
    34  		require.False(t, sub.Enabled(zapcore.DebugLevel))
    35  
    36  		compLogger := zapLoggerCore(l.WithComponent("mycomponent").WithComponent("level2"))
    37  		require.True(t, compLogger.Enabled(zapcore.WarnLevel))
    38  		require.False(t, compLogger.Enabled(zapcore.InfoLevel))
    39  	})
    40  
    41  	t.Run("obeys component override", func(t *testing.T) {
    42  		l, err := NewZapLogger(&Config{
    43  			Level: "info",
    44  			ComponentLevels: map[string]string{
    45  				"sub":  "debug",
    46  				"sub2": "error",
    47  			},
    48  		})
    49  		require.NoError(t, err)
    50  
    51  		sub := zapLoggerCore(l.WithComponent("sub"))
    52  		sub2 := zapLoggerCore(l.WithComponent("sub2"))
    53  		require.True(t, sub.Enabled(zapcore.DebugLevel))
    54  		require.False(t, sub2.Enabled(zapcore.InfoLevel))
    55  	})
    56  
    57  	t.Run("updates dynamically", func(t *testing.T) {
    58  		config := &Config{
    59  			Level: "info",
    60  			ComponentLevels: map[string]string{
    61  				"sub":  "debug",
    62  				"sub2": "error",
    63  			},
    64  		}
    65  		l, err := NewZapLogger(config)
    66  		require.NoError(t, err)
    67  
    68  		sub := zapLoggerCore(l.WithComponent("sub"))
    69  		sub2 := zapLoggerCore(l.WithComponent("sub2.test"))
    70  		err = config.Update(&Config{
    71  			Level: "debug",
    72  			ComponentLevels: map[string]string{
    73  				"sub": "info",
    74  				// sub2 removed
    75  			},
    76  		})
    77  		require.NoError(t, err)
    78  
    79  		require.True(t, zapLoggerCore(l).Enabled(zapcore.DebugLevel))
    80  		require.False(t, sub.Enabled(zapcore.DebugLevel))
    81  		require.True(t, sub.Enabled(zapcore.InfoLevel))
    82  		require.True(t, sub2.Enabled(zapcore.InfoLevel))
    83  	})
    84  
    85  	t.Run("log output matches expected values", func(t *testing.T) {
    86  		ws := &testutil.BufferedWriteSyncer{}
    87  		l, err := NewZapLogger(&Config{}, WithTap(zaputil.NewWriteEnabler(ws, zapcore.DebugLevel)))
    88  		require.NoError(t, err)
    89  		l.Debugw("foo", "bar", "baz")
    90  
    91  		var log TestLogOutput
    92  		require.NoError(t, ws.Unmarshal(&log))
    93  
    94  		require.Equal(t, "debug", log.Level)
    95  		require.NotEqual(t, 0, log.TS)
    96  		require.NotEqual(t, "", log.Caller)
    97  		require.Equal(t, "foo", log.Msg)
    98  		require.Equal(t, "baz", log.Bar)
    99  	})
   100  
   101  	t.Run("component enabler for tapped logger returns lowest enabled level", func(t *testing.T) {
   102  		tapLevel := zap.NewAtomicLevel()
   103  		l, err := NewZapLogger(&Config{Level: "info"}, WithTap(zaputil.NewWriteEnabler(&testutil.BufferedWriteSyncer{}, tapLevel)))
   104  		require.NoError(t, err)
   105  
   106  		lvl := l.ComponentLeveler().ComponentLevel("foo")
   107  
   108  		// check config level
   109  		require.False(t, lvl.Enabled(zapcore.DebugLevel))
   110  		require.True(t, lvl.Enabled(zapcore.InfoLevel))
   111  
   112  		// check tap level
   113  		tapLevel.SetLevel(zapcore.DebugLevel)
   114  		require.True(t, lvl.Enabled(zapcore.DebugLevel))
   115  	})
   116  }
   117  
   118  type TestLogOutput struct {
   119  	testutil.TestLogOutput
   120  	Bar string
   121  }
   122  
   123  type logFunc func(string, ...any)
   124  
   125  func testLogCaller(f logFunc) {
   126  	f("test")
   127  }
   128  
   129  func TestLoggerCallDepth(t *testing.T) {
   130  	t.Cleanup(func() {
   131  		defaultLogger = LogRLogger(discardLogger)
   132  		pkgLogger = LogRLogger(discardLogger)
   133  	})
   134  
   135  	var caller string
   136  	testLogCaller(func(string, ...any) {
   137  		_, file, line, _ := runtime.Caller(1)
   138  		caller = fmt.Sprintf("%s:%d", file, line)
   139  	})
   140  
   141  	cases := map[string]func(l Logger) logFunc{
   142  		"NewZapLogger": func(l Logger) logFunc {
   143  			return l.Debugw
   144  		},
   145  		"package logger": func(l Logger) logFunc {
   146  			SetLogger(l, "TEST")
   147  			return Debugw
   148  		},
   149  		"GetLogger": func(l Logger) logFunc {
   150  			SetLogger(l, "TEST")
   151  			return GetLogger().Debugw
   152  		},
   153  		"ToZap": func(l Logger) logFunc {
   154  			return l.(ZapLogger).ToZap().Debugw
   155  		},
   156  		"WithUnlikelyValues": func(l Logger) logFunc {
   157  			return l.WithUnlikelyValues().Debugw
   158  		},
   159  	}
   160  	for label, getLogFunc := range cases {
   161  		t.Run(label, func(t *testing.T) {
   162  			ws := &testutil.BufferedWriteSyncer{}
   163  			l := must.Get(NewZapLogger(&Config{}, WithTap(zaputil.NewWriteEnabler(ws, zapcore.DebugLevel))))
   164  
   165  			testLogCaller(getLogFunc(l))
   166  
   167  			var log TestLogOutput
   168  			require.NoError(t, ws.Unmarshal(&log))
   169  			require.True(t, strings.HasSuffix(caller, log.Caller), `caller mismatch expected suffix match on "%s" got "%s"`, caller, log.Caller)
   170  		})
   171  	}
   172  }