fix(log): guard global Logger and LogLevel with atomics (#3988)

* fix(log): guard global Logger and LogLevel with atomics

* fix(log): pass calldepth to NewDefaultLogger for correct callsite

The atomic forwarding frame shifted DefaultLogger attribution to
log.go; use calldepth 3 for the plain logger and 4 for filterLogger,
which also fixes the pre-existing logging.go attribution in the
filter loggers.

* refactor(log): name the calldepth constants

internal/log.go

@@ -5,6 +5,7 @@ import (
 	"fmt"
 	"log"
 	"os"
+	"sync/atomic"
 )
 
 // TODO (ned): Revisit logging
@@ -15,24 +16,88 @@ type Logging interface {
 }
 
 type DefaultLogger struct {
-	log *log.Logger
+	log       *log.Logger
+	calldepth int
 }
 
 func (l *DefaultLogger) Printf(ctx context.Context, format string, v ...interface{}) {
-	_ = l.log.Output(2, fmt.Sprintf(format, v...))
+	_ = l.log.Output(l.calldepth, fmt.Sprintf(format, v...))
 }
 
-func NewDefaultLogger() Logging {
+// Calldepth values for NewDefaultLogger. Reads through Logger.Printf add one
+// forwarding frame (atomicLogger.Printf), so the plain default logger uses
+// DefaultLoggerCalldepth; wrappers that add another Printf frame (e.g.
+// logging's filterLogger) use FilterLoggerCalldepth.
+const (
+	DefaultLoggerCalldepth = 3
+	FilterLoggerCalldepth  = 4
+)
+
+// NewDefaultLogger returns a stderr logger that attributes each line to the
+// frame calldepth levels up the stack.
+func NewDefaultLogger(calldepth int) Logging {
 	return &DefaultLogger{
-		log: log.New(os.Stderr, "redis: ", log.LstdFlags|log.Lshortfile),
+		log:       log.New(os.Stderr, "redis: ", log.LstdFlags|log.Lshortfile),
+		calldepth: calldepth,
 	}
 }
 
+// atomicLogger holds the active Logging behind an atomic pointer so
+// redis.SetLogger, logging.Enable and logging.Disable can swap it while pool
+// and background goroutines read it through Printf. The interface is stored via
+// a pointer rather than atomic.Value, whose single-concrete-type rule the
+// swappable implementations (DefaultLogger, VoidLogger, custom loggers) break.
+type atomicLogger struct {
+	v atomic.Pointer[Logging]
+}
+
+func (a *atomicLogger) Store(l Logging) { a.v.Store(&l) }
+
+func (a *atomicLogger) Load() Logging {
+	if p := a.v.Load(); p != nil {
+		return *p
+	}
+	return nil
+}
+
+func (a *atomicLogger) Printf(ctx context.Context, format string, v ...interface{}) {
+	if l := a.Load(); l != nil {
+		l.Printf(ctx, format, v...)
+	}
+}
+
+func newAtomicLogger(l Logging) *atomicLogger {
+	a := &atomicLogger{}
+	a.Store(l)
+	return a
+}
+
 // Logger calls Output to print to the stderr.
 // Arguments are handled in the manner of fmt.Print.
-var Logger Logging = NewDefaultLogger()
+// Swap it with redis.SetLogger; read it through Logger.Printf.
+var Logger = newAtomicLogger(NewDefaultLogger(DefaultLoggerCalldepth))
 
-var LogLevel LogLevelT = LogLevelError
+// atomicLogLevel stores the active level as an int32 so redis.SetLogLevel can
+// change it while the level guards (isHealthyConn on the Get path, the
+// maintnotifications loggers) read it through the *OrAbove helpers.
+type atomicLogLevel struct {
+	v atomic.Int32
+}
+
+func (a *atomicLogLevel) Store(l LogLevelT) { a.v.Store(int32(l)) }
+func (a *atomicLogLevel) Load() LogLevelT   { return LogLevelT(a.v.Load()) }
+
+func (a *atomicLogLevel) WarnOrAbove() bool  { return a.Load().WarnOrAbove() }
+func (a *atomicLogLevel) InfoOrAbove() bool  { return a.Load().InfoOrAbove() }
+func (a *atomicLogLevel) DebugOrAbove() bool { return a.Load().DebugOrAbove() }
+
+func newAtomicLogLevel(l LogLevelT) *atomicLogLevel {
+	a := &atomicLogLevel{}
+	a.Store(l)
+	return a
+}
+
+var LogLevel = newAtomicLogLevel(LogLevelError)
 
 // LogLevelT represents the logging level
 type LogLevelT int

log_global_race_test.go

@@ -0,0 +1,74 @@
+package redis
+
+import (
+	"context"
+	"sync"
+	"testing"
+	"time"
+
+	"github.com/redis/go-redis/v9/internal"
+	"github.com/redis/go-redis/v9/logging"
+)
+
+type raceTestLogger struct{}
+
+func (raceTestLogger) Printf(ctx context.Context, format string, v ...interface{}) {}
+
+// internal.Logger and internal.LogLevel are process-wide logging config that
+// SetLogger/SetLogLevel and logging.Enable/Disable swap while command and pool
+// goroutines read them: internal.Logger through Printf (e.g. the sub-millisecond
+// duration warning in formatSec) and internal.LogLevel through the *OrAbove
+// guards (isHealthyConn on the Get path). Run with -race: the writers below race
+// the reads unless both are accessed atomically.
+func TestSetLoggerLogLevelConcurrentWithReads(t *testing.T) {
+	origLogger := internal.Logger.Load()
+	origLevel := internal.LogLevel.Load()
+	defer func() {
+		internal.Logger.Store(origLogger)
+		internal.LogLevel.Store(origLevel)
+	}()
+
+	ctx := context.Background()
+	var wg sync.WaitGroup
+	stop := make(chan struct{})
+
+	// Writers: swap the logger and level through the public setters.
+	for i := 0; i < 2; i++ {
+		wg.Add(1)
+		go func() {
+			defer wg.Done()
+			for {
+				select {
+				case <-stop:
+					return
+				default:
+					SetLogger(raceTestLogger{})
+					SetLogLevel(internal.LogLevelDebug)
+					logging.Disable()
+					SetLogLevel(internal.LogLevelError)
+				}
+			}
+		}()
+	}
+
+	// Readers: the exact patterns the library uses from its goroutines.
+	for i := 0; i < 2; i++ {
+		wg.Add(1)
+		go func() {
+			defer wg.Done()
+			for {
+				select {
+				case <-stop:
+					return
+				default:
+					internal.Logger.Printf(ctx, "probe %d", 1)
+					_ = internal.LogLevel.DebugOrAbove()
+				}
+			}
+		}()
+	}
+
+	time.Sleep(200 * time.Millisecond)
+	close(stop)
+	wg.Wait()
+}

logging/logging.go

@@ -31,35 +31,38 @@ func (v *VoidLogger) Printf(_ context.Context, _ string, _ ...interface{}) {
 // This can be used to speed up the library if logging is not needed.
 // It will override any custom logger that was set before and set the VoidLogger.
 func Disable() {
-	internal.Logger = &VoidLogger{}
+	internal.Logger.Store(&VoidLogger{})
 }
 
 // Enable enables logging by setting the internal logger to the default logger.
 // This is the default behavior.
 // You can use redis.SetLogger to set a custom logger.
 //
-// NOTE: This function is not thread-safe.
 // It will override any custom logger that was set before and set the DefaultLogger.
 func Enable() {
-	internal.Logger = internal.NewDefaultLogger()
+	internal.Logger.Store(internal.NewDefaultLogger(internal.DefaultLoggerCalldepth))
 }
 
 // SetLogLevel sets the log level for the library.
 func SetLogLevel(logLevel LogLevelT) {
-	internal.LogLevel = logLevel
+	internal.LogLevel.Store(logLevel)
 }
 
 // NewBlacklistLogger returns a new logger that filters out messages containing any of the substrings.
 // This can be used to filter out messages containing sensitive information.
 func NewBlacklistLogger(substr []string) internal.Logging {
-	l := internal.NewDefaultLogger()
+	// filterLogger.Printf adds a frame on top of the atomicLogger.Printf
+	// forwarding frame.
+	l := internal.NewDefaultLogger(internal.FilterLoggerCalldepth)
 	return &filterLogger{logger: l, substr: substr, blacklist: true}
 }
 
 // NewWhitelistLogger returns a new logger that only logs messages containing any of the substrings.
 // This can be used to only log messages related to specific commands or patterns.
 func NewWhitelistLogger(substr []string) internal.Logging {
-	l := internal.NewDefaultLogger()
+	// filterLogger.Printf adds a frame on top of the atomicLogger.Printf
+	// forwarding frame.
+	l := internal.NewDefaultLogger(internal.FilterLoggerCalldepth)
 	return &filterLogger{logger: l, substr: substr, blacklist: false}
 }
 

options_test.go

@@ -607,8 +607,8 @@ func TestNewClientSkipsEndpointDetectWhenMaintDisabled(t *testing.T) {
 }
 
 func TestClientSideCacheRESP2Warning(t *testing.T) {
-	origLogger := internal.Logger
-	defer func() { internal.Logger = origLogger }()
+	origLogger := internal.Logger.Load()
+	defer func() { internal.Logger.Store(origLogger) }()
 
 	cases := []struct {
 		name     string
@@ -640,7 +640,7 @@ func TestClientSideCacheRESP2Warning(t *testing.T) {
 	for _, tc := range cases {
 		t.Run(tc.name, func(t *testing.T) {
 			logger := &capturingLogger{}
-			internal.Logger = logger
+			internal.Logger.Store(logger)
 
 			tc.opt.init()
 

redis.go

@@ -42,12 +42,12 @@ func SetLogger(logger internal.Logging) {
 	if logger == nil {
 		return
 	}
-	internal.Logger = logger
+	internal.Logger.Store(logger)
 }
 
 // SetLogLevel sets the log level for the library.
 func SetLogLevel(logLevel internal.LogLevelT) {
-	internal.LogLevel = logLevel
+	internal.LogLevel.Store(logLevel)
 }
 
 //------------------------------------------------------------------------------