diff --git a/v2/handler.go b/v2/handler.go index 97723f8..8a0328f 100644 --- a/v2/handler.go +++ b/v2/handler.go @@ -119,7 +119,7 @@ func WithNoTimestamp() HandlerOption { // DefaultHandler is a Handler that can be used along with NewSLogger to // instantiate a structured logger. type DefaultHandler struct { - level atomic.Int64 + level *atomic.Int64 opts *handlerOpts buf *buffer @@ -162,10 +162,11 @@ func NewDefaultHandler(w io.Writer, options ...HandlerOption) *DefaultHandler { } handler := &DefaultHandler{ - w: w, - opts: opts, - buf: newBuffer(), - mu: &sync.Mutex{}, + w: w, + opts: opts, + buf: newBuffer(), + mu: &sync.Mutex{}, + level: &atomic.Int64{}, } handler.level.Store(int64(levelInfo)) @@ -257,7 +258,7 @@ func (d *DefaultHandler) Handle(_ context.Context, r slog.Record) error { // // NOTE: this is part of the slog.Handler interface. func (d *DefaultHandler) WithAttrs(attrs []slog.Attr) slog.Handler { - return d.with(d.tag, d.prefix, true, attrs...) + return d.with(d.tag, d.prefix, true, false, attrs...) } // WithGroup returns a new Handler with the given group appended to @@ -269,32 +270,43 @@ func (d *DefaultHandler) WithGroup(name string) slog.Handler { if d.tag != "" { name = d.tag + "." + name } - return d.with(name, d.prefix, true) + return d.with(name, d.prefix, true, false) } // SubSystem returns a copy of the given handler but with the new tag. All // attributes added with WithAttrs will be kept but all groups added with // WithGroup are lost. // -// note: this is part of the handler interface. +// NOTE: this creates a new logger with an independent log level. This +// means that SetLevel needs to be called on the new logger to change +// the level as any changes to the parent logger's level after creation +// will not be inherited by the new logger. +// +// NOTE: this is part of the Handler interface. func (d *DefaultHandler) SubSystem(tag string) Handler { - return d.with(tag, d.prefix, false) + return d.with(tag, d.prefix, false, false) } // WithPrefix returns a copy of the Handler but with the given string prefixed // to each log message. Note that the subsystem of the original logger is kept // but any existing prefix is overridden. // -// note: this is part of the handler interface. +// NOTE: this creates a new logger with an inherited log level. This +// means that if SetLevel is called on the parent logger, then this new +// level will be inherited by the new logger +// +// NOTE: this is part of the Handler interface. func (d *DefaultHandler) WithPrefix(prefix string) Handler { - return d.with(d.tag, prefix, false) + return d.with(d.tag, prefix, false, true) } // with returns a new logger with the given attributes added. // withCallstackOffset should be false if the caller returns a concrete // DefaultHandler and true if the caller returns the Handler interface. +// The shareLevel param determines whether the new handler shares the same +// level reference or gets its own independent level. func (d *DefaultHandler) with(tag, prefix string, withCallstackOffset bool, - attrs ...slog.Attr) *DefaultHandler { + shareLevel bool, attrs ...slog.Attr) *DefaultHandler { d.mu.Lock() sl := *d @@ -310,6 +322,14 @@ func (d *DefaultHandler) with(tag, prefix string, withCallstackOffset bool, sl.tag = tag sl.prefix = prefix + // If shareLevel is false, create a new independent level. Otherwise, + // sl.level already points to d.level. + if !shareLevel { + newLevel := &atomic.Int64{} + newLevel.Store(d.level.Load()) + sl.level = newLevel + } + return &sl } diff --git a/v2/handler_test.go b/v2/handler_test.go index 3c6f7ff..4813a35 100644 --- a/v2/handler_test.go +++ b/v2/handler_test.go @@ -298,3 +298,167 @@ value `, }, } + +// TestSubSystemLevelIndependence tests that child loggers created with +// SubSystem have independent level control and don't affect their parent's +// level. +func TestSubSystemLevelIndependence(t *testing.T) { + t.Parallel() + + var ( + buf bytes.Buffer + handler = NewDefaultHandler(&buf) + logger = NewSLogger(handler) + ) + + // Set initial level to Info. + logger.SetLevel(LevelInfo) + + // Create a child logger with subsystem. + childLogger := logger.SubSystem("CHILD") + + // Both loggers should initially have the same level. + if logger.Level() != childLogger.Level() { + t.Fatalf("Child logger level mismatch. Expected %s, got %s", + logger.Level(), childLogger.Level()) + } + + // Debug messages should not appear (level is Info). + logger.Debug("parent debug") + childLogger.Debug("child debug") + + // Assert that neither logger wrote to the buffer. + if buf.String() != "" { + t.Fatalf("Debug messages should not appear. Got: %s", + buf.String()) + } + + // Now, change ONLY child level to Debug. + childLogger.SetLevel(LevelDebug) + + // Loggers should now have different levels. + if logger.Level() == childLogger.Level() { + t.Fatalf("Child logger should have independent level. "+ + "Parent: %s, Child: %s", logger.Level(), + childLogger.Level()) + } + + // Verify parent is still Info and child is Debug. + if logger.Level() != LevelInfo { + t.Fatalf("Parent level should still be Info. Got: %s", + logger.Level()) + } + + if childLogger.Level() != LevelDebug { + t.Fatalf("Child level should be Debug. Got: %s", + childLogger.Level()) + } + + // Reset buffer. + buf.Reset() + + // Debug messages should only appear from child. + logger.Debug("parent debug") + childLogger.Debug("child debug") + + // Parent debug should NOT appear. + if bytes.Contains(buf.Bytes(), []byte("parent debug")) { + t.Fatalf("Parent debug message should not appear. Got: %s", + buf.String()) + } + + // Child debug SHOULD appear. + if !bytes.Contains(buf.Bytes(), []byte("child debug")) { + t.Fatalf("Child debug message should appear. Got: %s", + buf.String()) + } + + // Reset buffer. + buf.Reset() + + // Change parent level to Debug. + logger.SetLevel(LevelDebug) + + // Child level should remain unchanged. + if childLogger.Level() != LevelDebug { + t.Fatalf("Child level should remain Debug. Got: %s", + childLogger.Level()) + } + + // Now both should log debug messages. + logger.Debug("parent debug 2") + childLogger.Debug("child debug 2") + + // Both messages should appear. + if !bytes.Contains(buf.Bytes(), []byte("parent debug 2")) { + t.Fatalf("Parent debug message should appear. Got: %s", + buf.String()) + } + + if !bytes.Contains(buf.Bytes(), []byte("child debug 2")) { + t.Fatalf("Child debug message should appear. Got: %s", + buf.String()) + } +} + +// TestWithPrefixLevelInheritance tests that child loggers created with +// WithPrefix properly inherit level changes from their parent logger. +func TestWithPrefixLevelInheritance(t *testing.T) { + t.Parallel() + + var ( + buf bytes.Buffer + handler = NewDefaultHandler(&buf) + logger = NewSLogger(handler) + ) + + // Set initial level to Info. + logger.SetLevel(LevelInfo) + + // Create a child logger with prefix. + childLogger := logger.WithPrefix("child") + + // Both loggers should have the same level. + if logger.Level() != childLogger.Level() { + t.Fatalf("Child logger level mismatch. Expected %s, got %s", + logger.Level(), childLogger.Level()) + } + + // Debug messages should not appear (level is Info). + logger.Debug("parent debug") + childLogger.Debug("child debug") + + // Assert that neither logger wrote to the buffer. + if buf.String() != "" { + t.Fatalf("Debug messages should not appear. Got: %s", + buf.String()) + } + + // Now, change parent level to Debug. + logger.SetLevel(LevelDebug) + + // Both loggers should have the same level. + if logger.Level() != childLogger.Level() { + t.Fatalf("Child logger level mismatch. Expected %s, got %s", + logger.Level(), childLogger.Level()) + } + + // Reset buffer. + buf.Reset() + + // Now debug messages should appear from both loggers. + logger.Debug("parent debug") + childLogger.Debug("child debug") + + // Show that the buffer contains the parent log. + if !bytes.Contains(buf.Bytes(), []byte("parent debug")) { + t.Fatalf("Parent debug message not found in output: %s", + buf.String()) + } + + // Show that the buffer contains the child log. + if !bytes.Contains(buf.Bytes(), []byte("child debug")) { + t.Fatalf("Child debug message not found in output: %s", + buf.String()) + } +} diff --git a/v2/interface.go b/v2/interface.go index 34d4903..02855bc 100644 --- a/v2/interface.go +++ b/v2/interface.go @@ -96,11 +96,20 @@ type Logger interface { // SubSystem returns a copy of the logger but with the new subsystem // tag. + // + // NOTE: this creates a new logger with an independent log level. This + // means that SetLevel needs to be called on the new logger to change + // the level as any changes to the parent logger's level after creation + // will not be inherited by the new logger. SubSystem(tag string) Logger // WithPrefix returns a copy of the logger but with the given string // prefixed to each log message. Note that the subsystem of the original // logger is kept but any existing prefix is overridden. + // + // NOTE: this creates a new logger with an inherited log level. This + // means that if SetLevel is called on the parent logger, then this new + // level will be inherited by the new logger WithPrefix(prefix string) Logger } diff --git a/v2/log.go b/v2/log.go index 9145ab5..f6531d7 100644 --- a/v2/log.go +++ b/v2/log.go @@ -5,7 +5,6 @@ import ( "fmt" "io" "log/slog" - "sync/atomic" "github.com/btcsuite/btclog" ) @@ -26,18 +25,25 @@ type Handler interface { SetLevel(level btclog.Level) // SubSystem returns a copy of the given handler but with the new tag. + // + // NOTE: this creates a new logger with an independent log level. This + // means that SetLevel needs to be called on the new logger to change + // the level as any changes to the parent logger's level after creation + // will not be inherited by the new logger. SubSystem(tag string) Handler // WithPrefix returns a copy of the Handler but with the given string // prefixed to each log message. Note that the subsystem of the original // logger is kept but any existing prefix is overridden. + // + // NOTE: this creates a new logger with an inherited log level. This + // means that if SetLevel is called on the parent logger, then this new + // level will be inherited by the new logger WithPrefix(prefix string) Handler } // sLogger is an implementation of Logger backed by a structured sLogger. type sLogger struct { - level atomic.Int64 - handler Handler logger *slog.Logger @@ -59,7 +65,6 @@ func NewSLogger(handler Handler) Logger { logger: slog.New(handler), unusedCtx: context.Background(), } - l.level.Store(int64(toSlogLevel(handler.Level()))) return l } @@ -69,7 +74,7 @@ func NewSLogger(handler Handler) Logger { // // This is part of the Logger interface implementation. func (l *sLogger) Tracef(format string, params ...any) { - if l.level.Load() > int64(levelTrace) { + if !l.handler.Enabled(l.unusedCtx, levelTrace) { return } @@ -81,7 +86,7 @@ func (l *sLogger) Tracef(format string, params ...any) { // // This is part of the Logger interface implementation. func (l *sLogger) Debugf(format string, params ...any) { - if l.level.Load() > int64(levelDebug) { + if !l.handler.Enabled(l.unusedCtx, levelDebug) { return } @@ -93,7 +98,7 @@ func (l *sLogger) Debugf(format string, params ...any) { // // This is part of the Logger interface implementation. func (l *sLogger) Infof(format string, params ...any) { - if l.level.Load() > int64(levelInfo) { + if !l.handler.Enabled(l.unusedCtx, levelInfo) { return } @@ -105,7 +110,7 @@ func (l *sLogger) Infof(format string, params ...any) { // // This is part of the Logger interface implementation. func (l *sLogger) Warnf(format string, params ...any) { - if l.level.Load() > int64(levelWarn) { + if !l.handler.Enabled(l.unusedCtx, levelWarn) { return } @@ -117,7 +122,7 @@ func (l *sLogger) Warnf(format string, params ...any) { // // This is part of the Logger interface implementation. func (l *sLogger) Errorf(format string, params ...any) { - if l.level.Load() > int64(levelError) { + if !l.handler.Enabled(l.unusedCtx, levelError) { return } @@ -129,7 +134,7 @@ func (l *sLogger) Errorf(format string, params ...any) { // // This is part of the Logger interface implementation. func (l *sLogger) Criticalf(format string, params ...any) { - if l.level.Load() > int64(levelCritical) { + if !l.handler.Enabled(l.unusedCtx, levelCritical) { return } @@ -141,7 +146,7 @@ func (l *sLogger) Criticalf(format string, params ...any) { // // This is part of the Logger interface implementation. func (l *sLogger) Trace(v ...any) { - if l.level.Load() > int64(levelTrace) { + if !l.handler.Enabled(l.unusedCtx, levelTrace) { return } @@ -153,7 +158,7 @@ func (l *sLogger) Trace(v ...any) { // // This is part of the Logger interface implementation. func (l *sLogger) Debug(v ...any) { - if l.level.Load() > int64(levelDebug) { + if !l.handler.Enabled(l.unusedCtx, levelDebug) { return } @@ -165,7 +170,7 @@ func (l *sLogger) Debug(v ...any) { // // This is part of the Logger interface implementation. func (l *sLogger) Info(v ...any) { - if l.level.Load() > int64(levelInfo) { + if !l.handler.Enabled(l.unusedCtx, levelInfo) { return } @@ -177,7 +182,7 @@ func (l *sLogger) Info(v ...any) { // // This is part of the Logger interface implementation. func (l *sLogger) Warn(v ...any) { - if l.level.Load() > int64(levelWarn) { + if !l.handler.Enabled(l.unusedCtx, levelWarn) { return } @@ -189,7 +194,7 @@ func (l *sLogger) Warn(v ...any) { // // This is part of the Logger interface implementation. func (l *sLogger) Error(v ...any) { - if l.level.Load() > int64(levelError) { + if !l.handler.Enabled(l.unusedCtx, levelError) { return } @@ -201,7 +206,7 @@ func (l *sLogger) Error(v ...any) { // // This is part of the Logger interface implementation. func (l *sLogger) Critical(v ...any) { - if l.level.Load() > int64(levelCritical) { + if !l.handler.Enabled(l.unusedCtx, levelCritical) { return } @@ -213,7 +218,7 @@ func (l *sLogger) Critical(v ...any) { // // This is part of the Logger interface implementation. func (l *sLogger) TraceS(ctx context.Context, msg string, attrs ...any) { - if l.level.Load() > int64(levelTrace) { + if !l.handler.Enabled(ctx, levelTrace) { return } @@ -225,7 +230,7 @@ func (l *sLogger) TraceS(ctx context.Context, msg string, attrs ...any) { // // This is part of the Logger interface implementation. func (l *sLogger) DebugS(ctx context.Context, msg string, attrs ...any) { - if l.level.Load() > int64(levelDebug) { + if !l.handler.Enabled(ctx, levelDebug) { return } @@ -237,7 +242,7 @@ func (l *sLogger) DebugS(ctx context.Context, msg string, attrs ...any) { // // This is part of the Logger interface implementation. func (l *sLogger) InfoS(ctx context.Context, msg string, attrs ...any) { - if l.level.Load() > int64(levelInfo) { + if !l.handler.Enabled(ctx, levelInfo) { return } @@ -251,7 +256,7 @@ func (l *sLogger) InfoS(ctx context.Context, msg string, attrs ...any) { func (l *sLogger) WarnS(ctx context.Context, msg string, err error, attrs ...any) { - if l.level.Load() > int64(levelWarn) { + if !l.handler.Enabled(ctx, levelWarn) { return } @@ -269,7 +274,7 @@ func (l *sLogger) WarnS(ctx context.Context, msg string, err error, func (l *sLogger) ErrorS(ctx context.Context, msg string, err error, attrs ...any) { - if l.level.Load() > int64(levelError) { + if !l.handler.Enabled(ctx, levelError) { return } @@ -287,7 +292,7 @@ func (l *sLogger) ErrorS(ctx context.Context, msg string, err error, func (l *sLogger) CriticalS(ctx context.Context, msg string, err error, attrs ...any) { - if l.level.Load() > int64(levelCritical) { + if !l.handler.Enabled(ctx, levelCritical) { return } @@ -302,14 +307,13 @@ func (l *sLogger) CriticalS(ctx context.Context, msg string, err error, // // This is part of the Logger interface implementation. func (l *sLogger) Level() btclog.Level { - return fromSlogLevel(slog.Level(l.level.Load())) + return l.handler.Level() } // SetLevel changes the logging level of the Handler to the passed level. // // This is part of the Logger interface implementation. func (l *sLogger) SetLevel(level btclog.Level) { - l.level.Store(int64(toSlogLevel(level))) l.handler.SetLevel(level) }