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
This commit is contained in:
Patrick Ohly 2023-06-29 22:32:02 +02:00
parent b3d94ae74f
commit ea34d03925

View File

@ -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)
}