Data race in http2Client

[bdarnell]

Please answer these questions before submitting your issue.

What version of gRPC are you using?

1.9.1. The bug was not present in gRPC 1.7.2 (I haven't tested 1.8 It's in the current tip of the v1.8.x branch too)

What version of Go are you using (go version)?

go version go1.9.2 darwin/amd64

What operating system (Linux, Windows, …) and version?

macOS 10.13.2 and ubuntu 16.04

What did you do?

With the race detector enabled, issue a streaming rpc (I don't know if the use of streaming is relevant) and immediately cancel its context, so that the cancellation races with the arrival of the headers packet from the server. I don't have a minimal reproduction of this, but it manifests (very infrequently) in the cockroachdb test suite (run make stressrace PKG=./pkg/gossip in the cockroach repo for 30 minutes). See cockroachdb/cockroach#21451

What did you expect to see?

No data races

What did you see instead?

The race detector reports a race between RecvCompress and operateHeaders:

==================
WARNING: DATA RACE
Read at 0x00c42068a050 by goroutine 136:
  github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport.(*Stream).RecvCompress()
      /go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport/transport.go:274 +0x79
  github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc.(*clientStream).RecvMsg()
      /go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/stream.go:428 +0xd87
  github.com/cockroachdb/cockroach/pkg/gossip.(*gossipGossipClient).Recv()
      /go/src/github.com/cockroachdb/cockroach/pkg/gossip/gossip.pb.go:191 +0x85
  github.com/cockroachdb/cockroach/pkg/gossip.(*client).gossip.func2.1()
      /go/src/github.com/cockroachdb/cockroach/pkg/gossip/client.go:311 +0x42
  github.com/cockroachdb/cockroach/pkg/gossip.(*client).gossip.func2()
      /go/src/github.com/cockroachdb/cockroach/pkg/gossip/client.go:319 +0xe5
  github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1()
      /go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:195 +0x160

Previous write at 0x00c42068a050 by goroutine 79:
  github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport.(*http2Client).operateHeaders()
      /go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport/http2_client.go:1114 +0xa15
  github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport.(*http2Client).reader()
      /go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport/http2_client.go:1193 +0x89a

Goroutine 136 (running) created at:
  github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker()
      /go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:188 +0xba
  github.com/cockroachdb/cockroach/pkg/gossip.(*client).gossip()
      /go/src/github.com/cockroachdb/cockroach/pkg/gossip/client.go:306 +0x2e0
  github.com/cockroachdb/cockroach/pkg/gossip.(*client).startLocked.func1()
      /go/src/github.com/cockroachdb/cockroach/pkg/gossip/client.go:130 +0x64a
  github.com/cockroachdb/cockroach/pkg/util/stop.(*Stopper).RunWorker.func1()
      /go/src/github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:195 +0x160

Goroutine 79 (finished) created at:
  github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport.newHTTP2Client()
      /go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport/http2_client.go:273 +0x13f7
  github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport.NewClientTransport()
      /go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/transport/transport.go:518 +0xd7
  github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc.(*addrConn).createTransport()
      /go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/clientconn.go:1139 +0x3f9
  github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc.(*addrConn).resetTransport()
      /go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/clientconn.go:1100 +0x7b5
  github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc.(*addrConn).connect.func1()
      /go/src/github.com/cockroachdb/cockroach/vendor/google.golang.org/grpc/clientconn.go:829 +0x3c
==================

I have determined (via printf debugging) that we see one goroutine call http2Client.CloseStream while another is in http2Client.operateHeaders, and a third calls Stream.RecvCompress. The CloseStream call sets s.headerDone and closes s.headerChan, unblocking RecvCompress. The read of s.recvCompress in Stream.RecvCompress then races with the write of this field in operateHeaders.

I see two simple ways to address the data race: Acquire s.mu in Stream.RecvCompress, or move the assignment to s.recvCompress into the if !s.headerDone block so we don't change it if we've already signaled that we're done with headers. (it's possible that this error is revealing a deeper synchronization issue, but I'm not sure enough of the various goroutines involved here)

[bdarnell]

Thanks! Can I request a 1.9.2 release with this fix?

[dfawley]

Will do!