diff --git a/logger.go b/logger.go index 559b3bd..a1b755f 100644 --- a/logger.go +++ b/logger.go @@ -30,6 +30,8 @@ type Logger struct { isDiscard uint32 level int64 + hasCustomLevel uint32 + parent *Logger prefix string timeFunc TimeFunction timeFormat string @@ -58,7 +60,7 @@ func (l *Logger) Log(level Level, msg any, keyvals ...any) { } // check if the level is allowed - if atomic.LoadInt64(&l.level) > int64(level) { + if l.getLevel() > int64(level) { return } @@ -231,11 +233,20 @@ func (l *Logger) SetReportCaller(report bool) { l.reportCaller = report } +func (l *Logger) getLevel() int64 { + for cur := l; cur != nil; cur = cur.parent { + if atomic.LoadUint32(&cur.hasCustomLevel) != 0 || cur.parent == nil { + return atomic.LoadInt64(&cur.level) + } + } + return int64(InfoLevel) +} + // GetLevel returns the current level. func (l *Logger) GetLevel() Level { l.mu.RLock() defer l.mu.RUnlock() - return Level(l.level) + return Level(l.getLevel()) } // SetLevel sets the current level. @@ -243,6 +254,7 @@ func (l *Logger) SetLevel(level Level) { l.mu.Lock() defer l.mu.Unlock() atomic.StoreInt64(&l.level, int64(level)) + atomic.StoreUint32(&l.hasCustomLevel, 1) } // GetPrefix returns the current prefix. @@ -340,6 +352,8 @@ func (l *Logger) With(keyvals ...any) *Logger { sl.fields = append(make([]any, 0, len(l.fields)+len(keyvals)), l.fields...) sl.fields = append(sl.fields, keyvals...) sl.styles = &st + sl.parent = l + sl.hasCustomLevel = 0 return &sl } diff --git a/logger_121.go b/logger_121.go index d9ff924..436d362 100644 --- a/logger_121.go +++ b/logger_121.go @@ -6,7 +6,6 @@ import ( "context" "log/slog" "runtime" - "sync/atomic" ) // type aliases for slog. @@ -24,7 +23,7 @@ const slogKindGroup = slog.KindGroup // // Implements slog.Handler. func (l *Logger) Enabled(_ context.Context, level slog.Level) bool { - return atomic.LoadInt64(&l.level) <= int64(level) + return l.getLevel() <= int64(level) } // Handle handles the Record. It will only be called if Enabled returns true. diff --git a/logger_no121.go b/logger_no121.go index 047d4a8..284c4c6 100644 --- a/logger_no121.go +++ b/logger_no121.go @@ -5,7 +5,6 @@ package log import ( "context" "runtime" - "sync/atomic" "golang.org/x/exp/slog" ) @@ -25,7 +24,7 @@ const slogKindGroup = slog.KindGroup // // Implements slog.Handler. func (l *Logger) Enabled(_ context.Context, level slog.Level) bool { - return atomic.LoadInt64(&l.level) <= int64(level) + return l.getLevel() <= int64(level) } // Handle handles the Record. It will only be called if Enabled returns true. diff --git a/logger_test.go b/logger_test.go index e1dec1d..9754647 100644 --- a/logger_test.go +++ b/logger_test.go @@ -287,3 +287,159 @@ func TestCustomLevel(t *testing.T) { l.Logf(level500, "foo") assert.Equal(t, "foo\n", buf.String()) } + +func TestWrappedLoggerInheritsLevel(t *testing.T) { + var buf bytes.Buffer + logger := NewWithOptions(&buf, Options{ + Level: InfoLevel, + ReportTimestamp: false, + ReportCaller: false, + }) + + wrappedLogger := logger.With("component", "auth") + + // Initially InfoLevel: debug message must be suppressed on child. + wrappedLogger.Debug("auth debug suppressed") + assert.Empty(t, buf.String()) + + // Changing parent level to DebugLevel must propagate to child. + logger.SetLevel(DebugLevel) + assert.Equal(t, DebugLevel, wrappedLogger.GetLevel()) + + wrappedLogger.Debug("auth debug allowed") + assert.Equal(t, "DEBUG auth debug allowed component=auth\n", buf.String()) + + // Changing parent level to WarnLevel must suppress info messages on child. + buf.Reset() + logger.SetLevel(WarnLevel) + assert.Equal(t, WarnLevel, wrappedLogger.GetLevel()) + + wrappedLogger.Info("auth info suppressed") + assert.Empty(t, buf.String()) + + wrappedLogger.Warn("auth warning allowed") + assert.Equal(t, "WARN auth warning allowed component=auth\n", buf.String()) +} + +func TestWrappedLoggerExplicitChildLevel(t *testing.T) { + var buf bytes.Buffer + logger := NewWithOptions(&buf, Options{ + Level: InfoLevel, + ReportTimestamp: false, + ReportCaller: false, + }) + + child := logger.With("component", "worker") + child.SetLevel(WarnLevel) + + // Child override must not mutate parent level. + assert.Equal(t, InfoLevel, logger.GetLevel()) + assert.Equal(t, WarnLevel, child.GetLevel()) + + // Subsequent parent level change must not override explicit child setting. + logger.SetLevel(DebugLevel) + assert.Equal(t, DebugLevel, logger.GetLevel()) + assert.Equal(t, WarnLevel, child.GetLevel()) + + // Parent permits debug messages while child suppresses them. + logger.Debug("parent debug allowed") + assert.Equal(t, "DEBUG parent debug allowed\n", buf.String()) + + buf.Reset() + child.Debug("child debug suppressed") + assert.Empty(t, buf.String()) + + child.Info("child info suppressed") + assert.Empty(t, buf.String()) + + child.Warn("child warn allowed") + assert.Equal(t, "WARN child warn allowed component=worker\n", buf.String()) +} + +func TestWrappedLoggerHierarchy(t *testing.T) { + var buf bytes.Buffer + root := NewWithOptions(&buf, Options{ + Level: InfoLevel, + ReportTimestamp: false, + ReportCaller: false, + }) + + child := root.With("tier", 1) + grandchild := child.With("tier", 2) + + assert.Equal(t, InfoLevel, root.GetLevel()) + assert.Equal(t, InfoLevel, child.GetLevel()) + assert.Equal(t, InfoLevel, grandchild.GetLevel()) + + // Root update propagates down entire hierarchy. + root.SetLevel(DebugLevel) + assert.Equal(t, DebugLevel, root.GetLevel()) + assert.Equal(t, DebugLevel, child.GetLevel()) + assert.Equal(t, DebugLevel, grandchild.GetLevel()) + + grandchild.Debug("grandchild debug") + assert.Equal(t, "DEBUG grandchild debug tier=1 tier=2\n", buf.String()) + + // Overriding child propagates to grandchild, while root is unaffected. + buf.Reset() + child.SetLevel(ErrorLevel) + assert.Equal(t, DebugLevel, root.GetLevel()) + assert.Equal(t, ErrorLevel, child.GetLevel()) + assert.Equal(t, ErrorLevel, grandchild.GetLevel()) + + grandchild.Warn("grandchild warn suppressed") + assert.Empty(t, buf.String()) + + grandchild.Error("grandchild error allowed") + assert.Equal(t, "ERROR grandchild error allowed tier=1 tier=2\n", buf.String()) + + buf.Reset() + root.Debug("root debug allowed") + assert.Equal(t, "DEBUG root debug allowed\n", buf.String()) +} + +func TestWrappedLoggerRace(t *testing.T) { + w := io.Discard + logger := New(w) + child := logger.With("component", "worker") + grandchild := child.With("task", 42) + + var wg sync.WaitGroup + levels := []Level{DebugLevel, InfoLevel, WarnLevel, ErrorLevel} + + for i := 0; i < 20; i++ { + wg.Add(4) + lvl := levels[i%len(levels)] + + go func() { + defer wg.Done() + logger.SetLevel(lvl) + logger.Debug("logger debug") + logger.Info("logger info") + }() + + go func() { + defer wg.Done() + child.GetLevel() + child.Info("child info") + child.Warn("child warn") + }() + + go func() { + defer wg.Done() + grandchild.GetLevel() + grandchild.Debug("grandchild debug") + grandchild.Error("grandchild error") + }() + + go func(idx int) { + defer wg.Done() + if idx%2 == 0 { + child.SetLevel(lvl) + } + }(i) + } + + wg.Wait() +} + diff --git a/pkg.go b/pkg.go index 116a621..76ed629 100644 --- a/pkg.go +++ b/pkg.go @@ -50,6 +50,7 @@ func NewWithOptions(w io.Writer, o Options) *Logger { mu: &sync.RWMutex{}, helpers: &sync.Map{}, level: int64(o.Level), + hasCustomLevel: 1, reportTimestamp: o.ReportTimestamp, reportCaller: o.ReportCaller, prefix: o.Prefix,