Skip to content

Commit f92e566

Browse files
ccoVeillendyakov
andcommitted
feat: add optional logger wherever possible
This commit introduces an optional logger parameter to various structs. This enhancement allows users to provide custom logging implementations. An issue will remain for direct calls to internal.Logger.Printf, as the call depth cannot be adjusted there without changing the function signature. While most of the changes comes from ccoVeille's work, Nedyalko Dyakov made some changes in other files to ensure the legacy logger is replaced with the new logger. Co-authored-by: Nedyalko Dyakov <[email protected]>
1 parent 21bfcf3 commit f92e566

24 files changed

+944
-196
lines changed

commands.go

Lines changed: 3 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@ import (
1313
"time"
1414

1515
"github.com/redis/go-redis/v9/internal"
16+
"github.com/redis/go-redis/v9/logging"
1617
)
1718

1819
// KeepTTL is a Redis KEEPTTL option to keep existing TTL, it requires your redis-server version >= 6.0,
@@ -28,23 +29,15 @@ func usePrecise(dur time.Duration) bool {
2829

2930
func formatMs(ctx context.Context, dur time.Duration) int64 {
3031
if dur > 0 && dur < time.Millisecond {
31-
internal.Logger.Printf(
32-
ctx,
33-
"specified duration is %s, but minimal supported value is %s - truncating to 1ms",
34-
dur, time.Millisecond,
35-
)
32+
logging.LoggerWithLevel().Infof(ctx, "specified duration is %s, but minimal supported value is %s - truncating to 1ms", dur, time.Millisecond)
3633
return 1
3734
}
3835
return int64(dur / time.Millisecond)
3936
}
4037

4138
func formatSec(ctx context.Context, dur time.Duration) int64 {
4239
if dur > 0 && dur < time.Second {
43-
internal.Logger.Printf(
44-
ctx,
45-
"specified duration is %s, but minimal supported value is %s - truncating to 1s",
46-
dur, time.Second,
47-
)
40+
logging.LoggerWithLevel().Infof(ctx, "specified duration is %s, but minimal supported value is %s - truncating to 1s", dur, time.Second)
4841
return 1
4942
}
5043
return int64(dur / time.Second)

export_test.go

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -6,9 +6,9 @@ import (
66
"net"
77
"strings"
88

9-
"github.com/redis/go-redis/v9/internal"
109
"github.com/redis/go-redis/v9/internal/hashtag"
1110
"github.com/redis/go-redis/v9/internal/pool"
11+
"github.com/redis/go-redis/v9/logging"
1212
)
1313

1414
func (c *baseClient) Pool() pool.Pooler {
@@ -87,7 +87,7 @@ func (c *clusterState) IsConsistent(ctx context.Context) bool {
8787
func GetSlavesAddrByName(ctx context.Context, c *SentinelClient, name string) []string {
8888
addrs, err := c.Replicas(ctx, name).Result()
8989
if err != nil {
90-
internal.Logger.Printf(ctx, "sentinel: Replicas name=%q failed: %s",
90+
logging.LoggerWithLevel().Errorf(ctx, "sentinel: Replicas name=%q failed: %s",
9191
name, err)
9292
return []string{}
9393
}

internal/auth/streaming/pool_hook.go

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@ import (
77

88
"github.com/redis/go-redis/v9/internal"
99
"github.com/redis/go-redis/v9/internal/pool"
10+
"github.com/redis/go-redis/v9/logging"
1011
)
1112

1213
// ReAuthPoolHook is a pool hook that manages background re-authentication of connections
@@ -166,7 +167,7 @@ func (r *ReAuthPoolHook) OnPut(_ context.Context, conn *pool.Conn) (bool, bool,
166167
defer func() {
167168
if rec := recover(); rec != nil {
168169
// once again - safety first
169-
internal.Logger.Printf(context.Background(), "panic in reauth worker: %v", rec)
170+
logging.LoggerWithLevel().Errorf(context.Background(), "panic in reauth worker: %v", rec)
170171
}
171172
r.scheduledLock.Lock()
172173
delete(r.scheduledReAuth, connID)

internal/log.go

Lines changed: 2 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -7,9 +7,6 @@ import (
77
"os"
88
)
99

10-
// TODO (ned): Revisit logging
11-
// Add more standardized approach with log levels and configurability
12-
1310
type Logging interface {
1411
Printf(ctx context.Context, format string, v ...interface{})
1512
}
@@ -19,7 +16,7 @@ type DefaultLogger struct {
1916
}
2017

2118
func (l *DefaultLogger) Printf(ctx context.Context, format string, v ...interface{}) {
22-
_ = l.log.Output(2, fmt.Sprintf(format, v...))
19+
_ = l.log.Output(4, fmt.Sprintf(format, v...))
2320
}
2421

2522
func NewDefaultLogger() Logging {
@@ -38,6 +35,7 @@ var LogLevel LogLevelT = LogLevelError
3835
type LogLevelT int
3936

4037
// Log level constants for the entire go-redis library
38+
// TODO(ndyakov): In v10 align those levels with slog.Level
4139
const (
4240
LogLevelError LogLevelT = iota // 0 - errors only
4341
LogLevelWarn // 1 - warnings and errors

internal/pool/conn.go

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -11,9 +11,9 @@ import (
1111
"sync/atomic"
1212
"time"
1313

14-
"github.com/redis/go-redis/v9/internal"
1514
"github.com/redis/go-redis/v9/internal/maintnotifications/logs"
1615
"github.com/redis/go-redis/v9/internal/proto"
16+
"github.com/redis/go-redis/v9/logging"
1717
)
1818

1919
var noDeadline = time.Time{}
@@ -508,7 +508,7 @@ func (cn *Conn) getEffectiveReadTimeout(normalTimeout time.Duration) time.Durati
508508
// Deadline has passed, clear relaxed timeouts atomically and use normal timeout
509509
newCount := cn.relaxedCounter.Add(-1)
510510
if newCount <= 0 {
511-
internal.Logger.Printf(context.Background(), logs.UnrelaxedTimeoutAfterDeadline(cn.GetID()))
511+
logging.LoggerWithLevel().Infof(context.Background(), logs.UnrelaxedTimeoutAfterDeadline(cn.GetID()))
512512
cn.clearRelaxedTimeout()
513513
}
514514
return normalTimeout
@@ -542,7 +542,7 @@ func (cn *Conn) getEffectiveWriteTimeout(normalTimeout time.Duration) time.Durat
542542
// Deadline has passed, clear relaxed timeouts atomically and use normal timeout
543543
newCount := cn.relaxedCounter.Add(-1)
544544
if newCount <= 0 {
545-
internal.Logger.Printf(context.Background(), logs.UnrelaxedTimeoutAfterDeadline(cn.GetID()))
545+
logging.LoggerWithLevel().Infof(context.Background(), logs.UnrelaxedTimeoutAfterDeadline(cn.GetID()))
546546
cn.clearRelaxedTimeout()
547547
}
548548
return normalTimeout

internal/pool/pool.go

Lines changed: 23 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@ import (
1111
"github.com/redis/go-redis/v9/internal"
1212
"github.com/redis/go-redis/v9/internal/proto"
1313
"github.com/redis/go-redis/v9/internal/util"
14+
"github.com/redis/go-redis/v9/logging"
1415
)
1516

1617
var (
@@ -119,6 +120,9 @@ type Options struct {
119120
// DialerRetryTimeout is the backoff duration between retry attempts.
120121
// Default: 100ms
121122
DialerRetryTimeout time.Duration
123+
124+
// Optional logger for connection pool operations.
125+
Logger logging.LoggerWithLevelI
122126
}
123127

124128
type lastDialErrorWrap struct {
@@ -254,7 +258,7 @@ func (p *ConnPool) checkMinIdleConns() {
254258
p.idleConnsLen.Add(-1)
255259

256260
p.freeTurn()
257-
internal.Logger.Printf(context.Background(), "addIdleConn panic: %+v", err)
261+
p.logger().Errorf(context.Background(), "addIdleConn panic: %+v", err)
258262
}
259263
}()
260264

@@ -416,7 +420,7 @@ func (p *ConnPool) dialConn(ctx context.Context, pooled bool) (*Conn, error) {
416420
return cn, nil
417421
}
418422

419-
internal.Logger.Printf(ctx, "redis: connection pool: failed to dial after %d attempts: %v", attempt, lastErr)
423+
p.logger().Errorf(ctx, "redis: connection pool: failed to dial after %d attempts: %v", attempt, lastErr)
420424
// All retries failed - handle error tracking
421425
p.setLastDialError(lastErr)
422426
if atomic.AddUint32(&p.dialErrorsNum, 1) == uint32(p.cfg.PoolSize) {
@@ -510,10 +514,10 @@ func (p *ConnPool) getConn(ctx context.Context) (*Conn, error) {
510514
acceptConn, err := hookManager.ProcessOnGet(ctx, cn, false)
511515
if err != nil || !acceptConn {
512516
if err != nil {
513-
internal.Logger.Printf(ctx, "redis: connection pool: failed to process idle connection by hook: %v", err)
517+
p.logger().Errorf(ctx, "redis: connection pool: failed to process idle connection by hook: %v", err)
514518
_ = p.CloseConn(cn)
515519
} else {
516-
internal.Logger.Printf(ctx, "redis: connection pool: conn[%d] rejected by hook, returning to pool", cn.GetID())
520+
p.logger().Errorf(ctx, "redis: connection pool: conn[%d] rejected by hook, returning to pool", cn.GetID())
517521
// Return connection to pool without freeing the turn that this Get() call holds.
518522
// We use putConnWithoutTurn() to run all the Put hooks and logic without freeing a turn.
519523
p.putConnWithoutTurn(ctx, cn)
@@ -541,7 +545,7 @@ func (p *ConnPool) getConn(ctx context.Context) (*Conn, error) {
541545
// this should not happen with a new connection, but we handle it gracefully
542546
if err != nil || !acceptConn {
543547
// Failed to process connection, discard it
544-
internal.Logger.Printf(ctx, "redis: connection pool: failed to process new connection conn[%d] by hook: accept=%v, err=%v", newcn.GetID(), acceptConn, err)
548+
p.logger().Errorf(ctx, "redis: connection pool: failed to process new connection conn[%d] by hook: accept=%v, err=%v", newcn.GetID(), acceptConn, err)
545549
_ = p.CloseConn(newcn)
546550
return nil, err
547551
}
@@ -583,7 +587,7 @@ func (p *ConnPool) queuedNewConn(ctx context.Context) (*Conn, error) {
583587
if !freeTurnCalled {
584588
p.freeTurn()
585589
}
586-
internal.Logger.Printf(context.Background(), "queuedNewConn panic: %+v", err)
590+
p.logger().Errorf(ctx, "queuedNewConn panic: %+v", err)
587591
}
588592
}()
589593

@@ -736,7 +740,7 @@ func (p *ConnPool) popIdle() (*Conn, error) {
736740

737741
// If we exhausted all attempts without finding a usable connection, return nil
738742
if attempts > 1 && attempts >= maxAttempts && int32(attempts) >= p.poolSize.Load() {
739-
internal.Logger.Printf(context.Background(), "redis: connection pool: failed to get a usable connection after %d attempts", attempts)
743+
p.logger().Errorf(context.Background(), "redis: connection pool: failed to get a usable connection after %d attempts", attempts)
740744
return nil, nil
741745
}
742746

@@ -765,7 +769,7 @@ func (p *ConnPool) putConn(ctx context.Context, cn *Conn, freeTurn bool) {
765769
// Peek at the reply type to check if it's a push notification
766770
if replyType, err := cn.PeekReplyTypeSafe(); err != nil || replyType != proto.RespPush {
767771
// Not a push notification or error peeking, remove connection
768-
internal.Logger.Printf(ctx, "Conn has unread data (not push notification), removing it")
772+
p.logger().Errorf(ctx, "Conn has unread data (not push notification), removing it")
769773
p.removeConnInternal(ctx, cn, err, freeTurn)
770774
return
771775
}
@@ -778,7 +782,7 @@ func (p *ConnPool) putConn(ctx context.Context, cn *Conn, freeTurn bool) {
778782
if hookManager != nil {
779783
shouldPool, shouldRemove, err = hookManager.ProcessOnPut(ctx, cn)
780784
if err != nil {
781-
internal.Logger.Printf(ctx, "Connection hook error: %v", err)
785+
p.logger().Errorf(ctx, "Connection hook error: %v", err)
782786
p.removeConnInternal(ctx, cn, err, freeTurn)
783787
return
784788
}
@@ -811,12 +815,12 @@ func (p *ConnPool) putConn(ctx context.Context, cn *Conn, freeTurn bool) {
811815
case StateUnusable:
812816
// expected state, don't log it
813817
case StateClosed:
814-
internal.Logger.Printf(ctx, "Unexpected conn[%d] state changed by hook to %v, closing it", cn.GetID(), currentState)
818+
p.logger().Errorf(ctx, "Unexpected conn[%d] state changed by hook to %v, closing it", cn.GetID(), currentState)
815819
shouldCloseConn = true
816820
p.removeConnWithLock(cn)
817821
default:
818822
// Pool as-is
819-
internal.Logger.Printf(ctx, "Unexpected conn[%d] state changed by hook to %v, pooling as-is", cn.GetID(), currentState)
823+
p.logger().Warnf(ctx, "Unexpected conn[%d] state changed by hook to %v, pooling as-is", cn.GetID(), currentState)
820824
}
821825
}
822826

@@ -1030,7 +1034,7 @@ func (p *ConnPool) isHealthyConn(cn *Conn, nowNs int64) bool {
10301034
if replyType, err := cn.rd.PeekReplyType(); err == nil && replyType == proto.RespPush {
10311035
// For RESP3 connections with push notifications, we allow some buffered data
10321036
// The client will process these notifications before using the connection
1033-
internal.Logger.Printf(
1037+
p.logger().Infof(
10341038
context.Background(),
10351039
"push: conn[%d] has buffered data, likely push notifications - will be processed by client",
10361040
cn.GetID(),
@@ -1053,3 +1057,10 @@ func (p *ConnPool) isHealthyConn(cn *Conn, nowNs int64) bool {
10531057
cn.SetUsedAtNs(nowNs)
10541058
return true
10551059
}
1060+
1061+
func (p *ConnPool) logger() *logging.LoggerWrapper {
1062+
if p.cfg != nil && p.cfg.Logger != nil {
1063+
return logging.NewLoggerWrapper(p.cfg.Logger)
1064+
}
1065+
return logging.LoggerWithLevel()
1066+
}

0 commit comments

Comments
 (0)