]> git.feebdaed.xyz Git - 0xmirror/grpc-go.git/commitdiff
grpctest: minor improvements to the test logger implementation (#8370)
authorAshesh Vidyut <134911583+asheshvidyut@users.noreply.github.com>
Mon, 7 Jul 2025 06:25:00 +0000 (11:55 +0530)
committerGitHub <noreply@github.com>
Mon, 7 Jul 2025 06:25:00 +0000 (11:55 +0530)
clientconn_test.go
encoding/encoding_test.go
internal/grpctest/grpctest.go
internal/grpctest/tlogger.go
internal/grpctest/tlogger_test.go
internal/transport/keepalive_test.go
orca/producer_test.go
test/end2end_test.go
test/goaway_test.go
test/healthcheck_test.go
test/metadata_test.go

index 9cca5a8eb7b71b48d2c49ee5a5b6e73702fa10f7..68c22414014809fb6cf54ab15ceb16f4d889c674 100644 (file)
@@ -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 {
index 2dce42ddd16380bf06044542d18d4f09f7d1e88f..ab22429b66b4160198867569243482db17a1eb65 100644 (file)
@@ -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")
index b8bc385807c0d92d237b9170f994d46cf81ee56d..29e8c8b9714539d1e702dd85adaa7b7631c46a23 100644 (file)
@@ -53,7 +53,7 @@ type Tester struct{}
 
 // Setup updates the tlogger.
 func (Tester) Setup(t *testing.T) {
-       TLogger.Update(t)
+       tLogr.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)
+       tLogr.endTest(t)
 }
 
 // Interface defines Tester's methods for use in this package.
index f7f6da15284f91192a7897861bd5db80c3d9fa43..492381758762bb1ceef186ce78278c1daf87152d 100644 (file)
@@ -33,9 +33,9 @@ import (
        "google.golang.org/grpc/grpclog"
 )
 
-// TLogger serves as the grpclog logger and is the interface through which
+// tLogr serves as the grpclog logger and is the interface through which
 // expected errors are declared in tests.
-var TLogger *tLogger
+var tLogr *tLogger
 
 const callingFrame = 4
 
@@ -73,11 +73,21 @@ type tLogger struct {
 }
 
 func init() {
-       TLogger = &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
+       vLevel := 0 // Default verbosity level
+
+       if vLevelEnv, found := os.LookupEnv("GRPC_GO_LOG_VERBOSITY_LEVEL"); found {
+               // If found, attempt to convert. If conversion is successful, update vLevel.
+               // If conversion fails, log a warning, but vLevel remains its default of 0.
+               if val, err := strconv.Atoi(vLevelEnv); err == nil {
+                       vLevel = val
+               } else {
+                       // Log the error if the environment variable is not a valid integer.
+                       fmt.Printf("Warning: GRPC_GO_LOG_VERBOSITY_LEVEL environment variable '%s' is not a valid integer. "+
+                               "Using default verbosity level 0. Error: %v\n", vLevelEnv, err)
+               }
        }
+       // Initialize tLogr with the determined verbosity level.
+       tLogr = &tLogger{errors: make(map[*regexp.Regexp]int), v: vLevel}
 }
 
 // getCallingPrefix returns the <file:line> at the given depth from the stack.
@@ -90,61 +100,61 @@ func getCallingPrefix(depth int) (string, error) {
 }
 
 // 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
+// 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 (tl *tLogger) update(t *testing.T) {
+       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
@@ -152,41 +162,41 @@ func (g *tLogger) Update(t *testing.T) {
 // 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) {
+       tLogr.mu.Lock()
+       defer tLogr.mu.Unlock()
        re, err := regexp.Compile(expr)
        if err != nil {
-               g.t.Error(err)
+               tLogr.t.Error(err)
                return
        }
-       g.errors[re] += n
+       tLogr.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 {
+// endTest checks if expected errors were not encountered.
+func (tl *tLogger) endTest(t *testing.T) {
+       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
                }
@@ -194,70 +204,70 @@ func (g *tLogger) expected(s string) bool {
        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
 }
index 364f1432e0f573e065c919e2c94e3a470db0786a..3bb99a8d9c9c8f766247428a7795bb55bc172aa7 100644 (file)
@@ -66,10 +66,10 @@ func (s) TestWarningDepth(*testing.T) {
 
 func (s) TestError(*testing.T) {
        const numErrors = 10
-       TLogger.ExpectError("Expected error")
-       TLogger.ExpectError("Expected ln error")
-       TLogger.ExpectError("Expected formatted error")
-       TLogger.ExpectErrorN("Expected repeated error", numErrors)
+       ExpectError("Expected error")
+       ExpectError("Expected ln error")
+       ExpectError("Expected formatted error")
+       ExpectErrorN("Expected repeated error", numErrors)
        grpclog.Error("Expected", "error")
        grpclog.Errorln("Expected", "ln", "error")
        grpclog.Errorf("%v %v %v", "Expected", "formatted", "error")
index 037b0b1c1b77242c211d22c62fb9443df7247840..0bd7ba356b3c9c1448eb02cdde3453a1a535ea7f 100644 (file)
@@ -398,7 +398,7 @@ func (s) TestKeepaliveClientStaysHealthyWithResponsiveServer(t *testing.T) {
 // explicitly makes sure the fix works and the client sends a ping every [Time]
 // period.
 func (s) TestKeepaliveClientFrequency(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\"")
 
        serverConfig := &ServerConfig{
                KeepalivePolicy: keepalive.EnforcementPolicy{
@@ -430,7 +430,7 @@ func (s) TestKeepaliveClientFrequency(t *testing.T) {
 // (when there are no active streams), based on the configured
 // EnforcementPolicy.
 func (s) TestKeepaliveServerEnforcementWithAbusiveClientNoRPC(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\"")
 
        serverConfig := &ServerConfig{
                KeepalivePolicy: keepalive.EnforcementPolicy{
@@ -461,7 +461,7 @@ func (s) TestKeepaliveServerEnforcementWithAbusiveClientNoRPC(t *testing.T) {
 // (even when there is an active stream), based on the configured
 // EnforcementPolicy.
 func (s) TestKeepaliveServerEnforcementWithAbusiveClientWithRPC(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\"")
 
        serverConfig := &ServerConfig{
                KeepalivePolicy: keepalive.EnforcementPolicy{
index 130b21a728297df2d33ab9ea4ca05c6273767c23..41758b8676be9b7a418bb0e832ac2be66aba24fb 100644 (file)
@@ -266,7 +266,7 @@ func (f *fakeORCAService) StreamCoreMetrics(req *v3orcaservicepb.OrcaLoadReportR
 // TestProducerBackoff verifies that the ORCA producer applies the proper
 // backoff after stream failures.
 func (s) TestProducerBackoff(t *testing.T) {
-       grpctest.TLogger.ExpectErrorN("injected error", 4)
+       grpctest.ExpectErrorN("injected error", 4)
 
        ctx, cancel := context.WithTimeout(context.Background(), defaultTestTimeout)
        defer cancel()
index 584c90ca3b15795c6514789e32ccb02c9ed3233f..ad80c9c5a1af590300a321c0786bcc3083b4dfce 100644 (file)
@@ -5312,7 +5312,7 @@ func (s) TestStatusInvalidUTF8Message(t *testing.T) {
 // will fail to marshal the status because of the invalid utf8 message. Details
 // will be dropped when sending.
 func (s) TestStatusInvalidUTF8Details(t *testing.T) {
-       grpctest.TLogger.ExpectError("Failed to marshal rpc status")
+       grpctest.ExpectError("Failed to marshal rpc status")
 
        var (
                origMsg = string([]byte{0xff, 0xfe, 0xfd})
@@ -6323,7 +6323,7 @@ func (s) TestServerClosesConn(t *testing.T) {
 // TestNilStatsHandler ensures we do not panic as a result of a nil stats
 // handler.
 func (s) TestNilStatsHandler(t *testing.T) {
-       grpctest.TLogger.ExpectErrorN("ignoring nil parameter", 2)
+       grpctest.ExpectErrorN("ignoring nil parameter", 2)
        ss := &stubserver.StubServer{
                UnaryCallF: func(context.Context, *testpb.SimpleRequest) (*testpb.SimpleResponse, error) {
                        return &testpb.SimpleResponse{}, nil
index 076412da7c2000e38ec2b7963cce058300358d5d..6f90eccef1a77da932c43120928383e1bb79df54 100644 (file)
@@ -121,7 +121,7 @@ func (s) TestDetailedGoAwayErrorOnGracefulClosePropagatesToRPCError(t *testing.T
 }
 
 func (s) TestDetailedGoAwayErrorOnAbruptClosePropagatesToRPCError(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\"")
        // set the min keepalive time very low so that this test can take
        // a reasonable amount of time
        prev := internal.KeepaliveMinPingTime
index 18d9685c1b60afcfcb1b3c94c7c5610ce8f24787..c406d2274445e2dce7e8b3b27139c51a2e916a4d 100644 (file)
@@ -254,7 +254,7 @@ func (s) TestHealthCheckWatchStateChange(t *testing.T) {
 
 // If Watch returns Unimplemented, then the ClientConn should go into READY state.
 func (s) TestHealthCheckHealthServerNotRegistered(t *testing.T) {
-       grpctest.TLogger.ExpectError("Subchannel health check is unimplemented at server side, thus health check is disabled")
+       grpctest.ExpectError("Subchannel health check is unimplemented at server side, thus health check is disabled")
        s := grpc.NewServer()
        lis, err := net.Listen("tcp", "localhost:0")
        if err != nil {
index 57139a8d9e3cea6ae2696e36c9ef522fdc6fed29..6c469d2f7c957c83cc9b40798459edcbf02bc19d 100644 (file)
@@ -37,7 +37,7 @@ import (
 )
 
 func (s) TestInvalidMetadata(t *testing.T) {
-       grpctest.TLogger.ExpectErrorN("stream: failed to validate md when setting trailer", 5)
+       grpctest.ExpectErrorN("stream: failed to validate md when setting trailer", 5)
 
        tests := []struct {
                name     string