From ea34d0392561aed53ee733c29c2cea1ee7a67548 Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Thu, 29 Jun 2023 22:32:02 +0200 Subject: [PATCH] integration testing: configure gRPC logging during init Doing the initialization once was not good enough because it was not guaranteed that RunCustomEtcd gets called early enough, before there are other goroutines which use gRPC. The data race for test/integration/apiserver.TestWatchCacheUpdatedByEtcd was: WARNING: DATA RACE Read at 0x00000cfffb90 by goroutine 140052: k8s.io/kubernetes/vendor/google.golang.org/grpc/grpclog.V() /home/prow/go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/google.golang.org/grpc/grpclog/grpclog.go:41 +0x30 k8s.io/kubernetes/vendor/google.golang.org/grpc/grpclog.(*componentData).V() /home/prow/go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/google.golang.org/grpc/grpclog/component.go:103 +0x4e k8s.io/kubernetes/vendor/google.golang.org/grpc/internal/transport.(*http2Client).Close() /home/prow/go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/google.golang.org/grpc/internal/transport/http2_client.go:955 +0xca k8s.io/kubernetes/vendor/google.golang.org/grpc/internal/transport.(*http2Client).reader() /home/prow/go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/google.golang.org/grpc/internal/transport/http2_client.go:1619 +0xbfb k8s.io/kubernetes/vendor/google.golang.org/grpc/internal/transport.newHTTP2Client.func11() /home/prow/go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/google.golang.org/grpc/internal/transport/http2_client.go:394 +0x47 Previous write at 0x00000cfffb90 by goroutine 145643: k8s.io/kubernetes/vendor/google.golang.org/grpc/grpclog.SetLoggerV2() /home/prow/go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/vendor/google.golang.org/grpc/grpclog/loggerv2.go:75 +0x104 k8s.io/kubernetes/test/integration/framework.RunCustomEtcd.func2() /home/prow/go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/integration/framework/etcd.go:157 +0x33 sync.(*Once).doSlow() /usr/local/go/src/sync/once.go:74 +0x101 sync.(*Once).Do() /usr/local/go/src/sync/once.go:65 +0x46 k8s.io/kubernetes/test/integration/framework.RunCustomEtcd() /home/prow/go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/integration/framework/etcd.go:156 +0xb97 k8s.io/kubernetes/test/integration/apiserver.multiEtcdSetup() /home/prow/go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/integration/apiserver/watchcache_test.go:41 +0xc4 k8s.io/kubernetes/test/integration/apiserver.TestWatchCacheUpdatedByEtcd() /home/prow/go/src/k8s.io/kubernetes/_output/local/go/src/k8s.io/kubernetes/test/integration/apiserver/watchcache_test.go:92 +0xa9 testing.tRunner() /usr/local/go/src/testing/testing.go:1576 +0x216 testing.(*T).Run.func1() /usr/local/go/src/testing/testing.go:1629 +0x47 --- test/integration/framework/etcd.go | 17 +++++++++-------- 1 file changed, 9 insertions(+), 8 deletions(-) diff --git a/test/integration/framework/etcd.go b/test/integration/framework/etcd.go index 25e2fbbfe11..7a6f8144be1 100644 --- a/test/integration/framework/etcd.go +++ b/test/integration/framework/etcd.go @@ -25,7 +25,6 @@ import ( "os" "os/exec" "strings" - "sync" "syscall" "testing" "time" @@ -84,7 +83,15 @@ func startEtcd(output io.Writer) (func(), error) { return stop, nil } -var initGRPCOnce sync.Once +func init() { + // Quiet etcd logs for integration tests + // Comment out to get verbose logs if desired. + // This has to be done before there are any goroutines + // active which use gRPC. During init is safe, albeit + // then also affects tests which don't use RunCustomEtcd + // (the place this was done before). + grpclog.SetLoggerV2(grpclog.NewLoggerV2(io.Discard, io.Discard, os.Stderr)) +} // RunCustomEtcd starts a custom etcd instance for test purposes. func RunCustomEtcd(dataDir string, customFlags []string, output io.Writer) (url string, stopFn func(), err error) { @@ -151,12 +158,6 @@ func RunCustomEtcd(dataDir string, customFlags []string, output io.Writer) (url } } - // Quiet etcd logs for integration tests - // Comment out to get verbose logs if desired - initGRPCOnce.Do(func() { - grpclog.SetLoggerV2(grpclog.NewLoggerV2(io.Discard, io.Discard, os.Stderr)) - }) - if err := cmd.Start(); err != nil { return "", nil, fmt.Errorf("failed to run etcd: %v", err) }