improve test logging

Author: ndyakov

internal/log.go

@@ -5,6 +5,7 @@ import (
 	"fmt"
 	"log"
 	"os"
+	"strings"
 )
 
 // TODO (ned): Revisit logging
@@ -27,3 +28,31 @@ func (l *logger) Printf(ctx context.Context, format string, v ...interface{}) {
 var Logger Logging = &logger{
 	log: log.New(os.Stderr, "redis: ", log.LstdFlags|log.Lshortfile),
 }
+
+func NewFilterLogger(substr []string) Logging {
+	l := Logger
+	if _, ok := l.(*logger); !ok {
+		l = &logger{
+			log: log.New(os.Stderr, "redis: ", log.LstdFlags|log.Lshortfile),
+		}
+	}
+	return &filterLogger{logger: l, substr: substr}
+}
+
+type filterLogger struct {
+	logger Logging
+	substr []string
+}
+
+func (l *filterLogger) Printf(ctx context.Context, format string, v ...interface{}) {
+	msg := fmt.Sprintf(format, v...)
+	for _, substr := range l.substr {
+		if strings.Contains(msg, substr) {
+			return
+		}
+	}
+	if l.logger != nil {
+		l.logger.Printf(ctx, format, v...)
+		return
+	}
+}

internal/pool/pool_test.go

@@ -10,6 +10,8 @@ import (
 
 	. "github.com/bsm/ginkgo/v2"
 	. "github.com/bsm/gomega"
+	"github.com/redis/go-redis/v9"
+	"github.com/redis/go-redis/v9/internal"
 
 	"github.com/redis/go-redis/v9/internal/pool"
 )
@@ -436,3 +438,8 @@ var _ = Describe("race", func() {
 		Expect(stats.Timeouts).To(Equal(uint32(1)))
 	})
 })
+
+func init() {
+	filterLogger := internal.NewFilterLogger([]string{"test panic"})
+	redis.SetLogger(filterLogger)
+}

main_test.go

@@ -1,9 +1,7 @@
 package redis_test
 
 import (
-	"context"
 	"fmt"
-	"log"
 	"net"
 	"os"
 	"strconv"
@@ -15,6 +13,7 @@ import (
 	. "github.com/bsm/ginkgo/v2"
 	. "github.com/bsm/gomega"
 	"github.com/redis/go-redis/v9"
+	"github.com/redis/go-redis/v9/internal"
 )
 
 const (
@@ -55,8 +54,6 @@ var (
 	sentinel1, sentinel2, sentinel3                *redis.Client
 )
 
-var TLogger *TestLogger
-
 var cluster = &clusterScenario{
 	ports:   []string{"16600", "16601", "16602", "16603", "16604", "16605"},
 	nodeIDs: make([]string, 6),
@@ -107,11 +104,11 @@ var _ = BeforeSuite(func() {
 	fmt.Printf("REDIS_VERSION: %.1f\n", RedisVersion)
 	fmt.Printf("CLIENT_LIBS_TEST_IMAGE: %v\n", os.Getenv("CLIENT_LIBS_TEST_IMAGE"))
 
-	// set logger that will filter some of the noise from the tests
-	TLogger := NewTestLogger()
-	TLogger.Filter("ERR unknown subcommand 'maint_notifications'")
-	TLogger.Filter("test panic")
-	redis.SetLogger(TLogger)
+	filterLogger := internal.NewFilterLogger([]string{
+		"ERR unknown subcommand 'maint_notifications'",
+		"test panic",
+	})
+	redis.SetLogger(filterLogger)
 
 	if RedisVersion < 7.0 || RedisVersion > 9 {
 		panic("incorrect or not supported redis version")
@@ -409,43 +406,3 @@ func (h *hook) ProcessPipelineHook(hook redis.ProcessPipelineHook) redis.Process
 	}
 	return hook
 }
-
-func NewTestLogger() *TestLogger {
-	intLogger := log.New(os.Stderr, "redis: ", log.LstdFlags|log.Lshortfile)
-	return &TestLogger{
-		intLogger,
-		[]string{},
-	}
-}
-
-// TestLogger is a logger that filters out specific substrings so
-// the test output is not polluted with noise.
-type TestLogger struct {
-	log                *log.Logger
-	filteredSubstrings []string
-}
-
-// Filter adds a substring to the filter list.
-func (tl *TestLogger) Filter(substr string) {
-	tl.filteredSubstrings = append(tl.filteredSubstrings, substr)
-}
-
-// Unfilter removes a substring from the filter list.
-func (tl *TestLogger) Unfilter(substr string) {
-	for i, s := range tl.filteredSubstrings {
-		if s == substr {
-			tl.filteredSubstrings = append(tl.filteredSubstrings[:i], tl.filteredSubstrings[i+1:]...)
-			return
-		}
-	}
-}
-
-func (tl *TestLogger) Printf(_ context.Context, format string, v ...interface{}) {
-	msg := fmt.Sprintf(format, v...)
-	for _, substr := range tl.filteredSubstrings {
-		if strings.Contains(msg, substr) {
-			return
-		}
-	}
-	_ = tl.log.Output(2, msg)
-}