grpctest: minor improvements to the test logger implementation

clientconn_test.go

@@ -702,7 +702,7 @@ func (s) TestResolverEmptyUpdateNotPanic(t *testing.T) {
 }
 
 func (s) TestClientUpdatesParamsAfterGoAway(t *testing.T) {
-	grpctest.TLogger.ExpectError("Client received GoAway with error code ENHANCE_YOUR_CALM and debug data equal to ASCII \"too_many_pings\"")
+	grpctest.ExpectError("Client received GoAway with error code ENHANCE_YOUR_CALM and debug data equal to ASCII \"too_many_pings\"")
 
 	lis, err := net.Listen("tcp", "localhost:0")
 	if err != nil {

encoding/encoding_test.go

@@ -112,7 +112,7 @@ func (c *errProtoCodec) Name() string {
 // Tests the case where encoding fails on the server. Verifies that there is
 // no panic and that the encoding error is propagated to the client.
 func (s) TestEncodeDoesntPanicOnServer(t *testing.T) {
-	grpctest.TLogger.ExpectError("grpc: server failed to encode response")
+	grpctest.ExpectError("grpc: server failed to encode response")
 
 	// Create a codec that errors when encoding messages.
 	encodingErr := errors.New("encoding failed")

internal/grpctest/grpctest.go

@@ -53,7 +53,7 @@ type Tester struct{}
 
 // Setup updates the tlogger.
 func (Tester) Setup(t *testing.T) {
-	TLogger.Update(t)
+	Update(t)
 	// TODO: There is one final leak around closing connections without completely
 	//  draining the recvBuffer that has yet to be resolved. All other leaks have been
 	//  completely addressed, and this can be turned back on as soon as this issue is
@@ -75,7 +75,7 @@ func (Tester) Teardown(t *testing.T) {
 	if atomic.LoadUint32(&lcFailed) == 1 {
 		t.Log("Goroutine leak check disabled for future tests")
 	}
-	TLogger.EndTest(t)
+	EndTest(t)
 }
 
 // Interface defines Tester's methods for use in this package.

internal/grpctest/tlogger.go

@@ -27,15 +27,16 @@
 	"runtime"
 	"strconv"
 	"sync"
+	"sync/atomic"
 	"testing"
 	"time"
 
 	"google.golang.org/grpc/grpclog"
 )
 
-// TLogger serves as the grpclog logger and is the interface through which
+// tLoggerAtomic serves as the grpclog logger and is the interface through which
 // expected errors are declared in tests.
-var TLogger *tLogger
+var tLoggerAtomic atomic.Value
 
 const callingFrame = 4
 
@@ -73,13 +74,19 @@
 }
 
 func init() {
-	TLogger = &tLogger{errors: map[*regexp.Regexp]int{}}
+	tLoggerAtomic.Store(&tLogger{errors: map[*regexp.Regexp]int{}})
 	vLevel := os.Getenv("GRPC_GO_LOG_VERBOSITY_LEVEL")
 	if vl, err := strconv.Atoi(vLevel); err == nil {
-		TLogger.v = vl
+		lgr := getLogger()
+		lgr.v = vl
 	}
 }
 
+// getLogger returns the current logger instance.
+func getLogger() *tLogger {
+	return tLoggerAtomic.Load().(*tLogger)
+}
+
 // getCallingPrefix returns the <file:line> at the given depth from the stack.
 func getCallingPrefix(depth int) (string, error) {
 	_, file, line, ok := runtime.Caller(depth)
@@ -90,174 +97,177 @@
 }
 
 // log logs the message with the specified parameters to the tLogger.
-func (g *tLogger) log(ltype logType, depth int, format string, args ...any) {
-	g.mu.Lock()
-	defer g.mu.Unlock()
+func (tl *tLogger) log(ltype logType, depth int, format string, args ...any) {
+	tl.mu.Lock()
+	defer tl.mu.Unlock()
 	prefix, err := getCallingPrefix(callingFrame + depth)
 	if err != nil {
-		g.t.Error(err)
+		tl.t.Error(err)
 		return
 	}
 	args = append([]any{ltype.String() + " " + prefix}, args...)
-	args = append(args, fmt.Sprintf(" (t=+%s)", time.Since(g.start)))
+	args = append(args, fmt.Sprintf(" (t=+%s)", time.Since(tl.start)))
 
 	if format == "" {
 		switch ltype {
 		case errorLog:
-			// fmt.Sprintln is used rather than fmt.Sprint because t.Log uses fmt.Sprintln behavior.
-			if g.expected(fmt.Sprintln(args...)) {
-				g.t.Log(args...)
+			// fmt.Sprintln is used rather than fmt.Sprint because tl.Log uses fmt.Sprintln behavior.
+			if tl.expected(fmt.Sprintln(args...)) {
+				tl.t.Log(args...)
 			} else {
-				g.t.Error(args...)
+				tl.t.Error(args...)
 			}
 		case fatalLog:
 			panic(fmt.Sprint(args...))
 		default:
-			g.t.Log(args...)
+			tl.t.Log(args...)
 		}
 	} else {
 		// Add formatting directives for the callingPrefix and timeSuffix.
 		format = "%v " + format + "%s"
 		switch ltype {
 		case errorLog:
-			if g.expected(fmt.Sprintf(format, args...)) {
-				g.t.Logf(format, args...)
+			if tl.expected(fmt.Sprintf(format, args...)) {
+				tl.t.Logf(format, args...)
 			} else {
-				g.t.Errorf(format, args...)
+				tl.t.Errorf(format, args...)
 			}
 		case fatalLog:
 			panic(fmt.Sprintf(format, args...))
 		default:
-			g.t.Logf(format, args...)
+			tl.t.Logf(format, args...)
 		}
 	}
 }
 
 // Update updates the testing.T that the testing logger logs to. Should be done
 // before every test. It also initializes the tLogger if it has not already.
-func (g *tLogger) Update(t *testing.T) {
-	g.mu.Lock()
-	defer g.mu.Unlock()
-	if !g.initialized {
-		grpclog.SetLoggerV2(TLogger)
-		g.initialized = true
+func Update(t *testing.T) {
+	tl := getLogger()
+	tl.mu.Lock()
+	defer tl.mu.Unlock()
+	if !tl.initialized {
+		grpclog.SetLoggerV2(tl)
+		tl.initialized = true
 	}
-	g.t = t
-	g.start = time.Now()
-	g.errors = map[*regexp.Regexp]int{}
+	tl.t = t
+	tl.start = time.Now()
+	tl.errors = map[*regexp.Regexp]int{}
 }
 
 // ExpectError declares an error to be expected. For the next test, the first
 // error log matching the expression (using FindString) will not cause the test
 // to fail. "For the next test" includes all the time until the next call to
 // Update(). Note that if an expected error is not encountered, this will cause
 // the test to fail.
-func (g *tLogger) ExpectError(expr string) {
-	g.ExpectErrorN(expr, 1)
+func ExpectError(expr string) {
+	ExpectErrorN(expr, 1)
 }
 
 // ExpectErrorN declares an error to be expected n times.
-func (g *tLogger) ExpectErrorN(expr string, n int) {
-	g.mu.Lock()
-	defer g.mu.Unlock()
+func ExpectErrorN(expr string, n int) {
+	tl := getLogger()
+	tl.mu.Lock()
+	defer tl.mu.Unlock()
 	re, err := regexp.Compile(expr)
 	if err != nil {
-		g.t.Error(err)
+		tl.t.Error(err)
 		return
 	}
-	g.errors[re] += n
+	tl.errors[re] += n
 }
 
 // EndTest checks if expected errors were not encountered.
-func (g *tLogger) EndTest(t *testing.T) {
-	g.mu.Lock()
-	defer g.mu.Unlock()
-	for re, count := range g.errors {
+func EndTest(t *testing.T) {
+	tl := getLogger()
+	tl.mu.Lock()
+	defer tl.mu.Unlock()
+	for re, count := range tl.errors {
 		if count > 0 {
 			t.Errorf("Expected error '%v' not encountered", re.String())
 		}
 	}
-	g.errors = map[*regexp.Regexp]int{}
+	tl.errors = map[*regexp.Regexp]int{}
 }
 
 // expected determines if the error string is protected or not.
-func (g *tLogger) expected(s string) bool {
-	for re, count := range g.errors {
+func (tl *tLogger) expected(s string) bool {
+	for re, count := range tl.errors {
 		if re.FindStringIndex(s) != nil {
-			g.errors[re]--
+			tl.errors[re]--
 			if count <= 1 {
-				delete(g.errors, re)
+				delete(tl.errors, re)
 			}
 			return true
 		}
 	}
 	return false
 }
 
-func (g *tLogger) Info(args ...any) {
-	g.log(infoLog, 0, "", args...)
+func (tl *tLogger) Info(args ...any) {
+	tl.log(infoLog, 0, "", args...)
 }
 
-func (g *tLogger) Infoln(args ...any) {
-	g.log(infoLog, 0, "", args...)
+func (tl *tLogger) Infoln(args ...any) {
+	tl.log(infoLog, 0, "", args...)
 }
 
-func (g *tLogger) Infof(format string, args ...any) {
-	g.log(infoLog, 0, format, args...)
+func (tl *tLogger) Infof(format string, args ...any) {
+	tl.log(infoLog, 0, format, args...)
 }
 
-func (g *tLogger) InfoDepth(depth int, args ...any) {
-	g.log(infoLog, depth, "", args...)
+func (tl *tLogger) InfoDepth(depth int, args ...any) {
+	tl.log(infoLog, depth, "", args...)
 }
 
-func (g *tLogger) Warning(args ...any) {
-	g.log(warningLog, 0, "", args...)
+func (tl *tLogger) Warning(args ...any) {
+	tl.log(warningLog, 0, "", args...)
 }
 
-func (g *tLogger) Warningln(args ...any) {
-	g.log(warningLog, 0, "", args...)
+func (tl *tLogger) Warningln(args ...any) {
+	tl.log(warningLog, 0, "", args...)
 }
 
-func (g *tLogger) Warningf(format string, args ...any) {
-	g.log(warningLog, 0, format, args...)
+func (tl *tLogger) Warningf(format string, args ...any) {
+	tl.log(warningLog, 0, format, args...)
 }
 
-func (g *tLogger) WarningDepth(depth int, args ...any) {
-	g.log(warningLog, depth, "", args...)
+func (tl *tLogger) WarningDepth(depth int, args ...any) {
+	tl.log(warningLog, depth, "", args...)
 }
 
-func (g *tLogger) Error(args ...any) {
-	g.log(errorLog, 0, "", args...)
+func (tl *tLogger) Error(args ...any) {
+	tl.log(errorLog, 0, "", args...)
 }
 
-func (g *tLogger) Errorln(args ...any) {
-	g.log(errorLog, 0, "", args...)
+func (tl *tLogger) Errorln(args ...any) {
+	tl.log(errorLog, 0, "", args...)
 }
 
-func (g *tLogger) Errorf(format string, args ...any) {
-	g.log(errorLog, 0, format, args...)
+func (tl *tLogger) Errorf(format string, args ...any) {
+	tl.log(errorLog, 0, format, args...)
 }
 
-func (g *tLogger) ErrorDepth(depth int, args ...any) {
-	g.log(errorLog, depth, "", args...)
+func (tl *tLogger) ErrorDepth(depth int, args ...any) {
+	tl.log(errorLog, depth, "", args...)
 }
 
-func (g *tLogger) Fatal(args ...any) {
-	g.log(fatalLog, 0, "", args...)
+func (tl *tLogger) Fatal(args ...any) {
+	tl.log(fatalLog, 0, "", args...)
 }
 
-func (g *tLogger) Fatalln(args ...any) {
-	g.log(fatalLog, 0, "", args...)
+func (tl *tLogger) Fatalln(args ...any) {
+	tl.log(fatalLog, 0, "", args...)
 }
 
-func (g *tLogger) Fatalf(format string, args ...any) {
-	g.log(fatalLog, 0, format, args...)
+func (tl *tLogger) Fatalf(format string, args ...any) {
+	tl.log(fatalLog, 0, format, args...)
 }
 
-func (g *tLogger) FatalDepth(depth int, args ...any) {
-	g.log(fatalLog, depth, "", args...)
+func (tl *tLogger) FatalDepth(depth int, args ...any) {
+	tl.log(fatalLog, depth, "", args...)
 }
 
-func (g *tLogger) V(l int) bool {
-	return l <= g.v
+func (tl *tLogger) V(l int) bool {
+	return l <= tl.v
 }