hashicorp / go-retryablehttp

Retryable HTTP client in Go
Mozilla Public License 2.0
1.99k stars 251 forks source link

Data race in Client body handling? #94

Closed pcman312 closed 4 years ago

pcman312 commented 4 years ago

We ran into a data race when using this in Vault (using v0.6.2):

https://app.circleci.com/pipelines/github/hashicorp/vault/8325/workflows/fd591032-03ba-46c7-b024-7c86545a08f9/jobs/54628/steps

WARNING: DATA RACE
Write at 0x00c00010ac40 by goroutine 65:
  github.com/hashicorp/vault/vendor/github.com/hashicorp/go-retryablehttp.(*Client).Do()
      /go/src/github.com/hashicorp/vault/vendor/github.com/hashicorp/go-retryablehttp/client.go:453 +0x1e8b
  github.com/hashicorp/vault/vendor/github.com/hashicorp/vault/api.(*Client).RawRequestWithContext()
      /go/src/github.com/hashicorp/vault/vendor/github.com/hashicorp/vault/api/client.go:846 +0x79c
  github.com/hashicorp/vault/vendor/github.com/hashicorp/vault/api.(*Sys).Mount()
      /go/src/github.com/hashicorp/vault/vendor/github.com/hashicorp/vault/api/sys_mounts.go:47 +0x22a
  github.com/hashicorp/vault/command/server/seal_test.prepareTestContainer.func2()
      /go/src/github.com/hashicorp/vault/command/server/seal/server_seal_transit_acc_test.go:171 +0x295
  github.com/hashicorp/vault/vendor/github.com/cenkalti/backoff.RetryNotify()
      /go/src/github.com/hashicorp/vault/vendor/github.com/cenkalti/backoff/retry.go:37 +0xc8
  github.com/hashicorp/vault/vendor/github.com/ory/dockertest.(*Pool).Retry()
      /go/src/github.com/hashicorp/vault/vendor/github.com/cenkalti/backoff/retry.go:24 +0xeb
  github.com/hashicorp/vault/command/server/seal_test.prepareTestContainer()
      /go/src/github.com/hashicorp/vault/command/server/seal/server_seal_transit_acc_test.go:158 +0x8c5
  github.com/hashicorp/vault/command/server/seal_test.TestTransitSeal_TokenRenewal()
      /go/src/github.com/hashicorp/vault/command/server/seal/server_seal_transit_acc_test.go:52 +0x53
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:909 +0x199 

Previous read at 0x00c00010ac40 by goroutine 14:
  net/http.(*persistConn).writeLoop()
      /usr/local/go/src/net/http/request.go:1389 +0x4d0 

Goroutine 65 (running) created at:
  testing.(*T).Run()
      /usr/local/go/src/testing/testing.go:960 +0x651
  testing.runTests.func1()
      /usr/local/go/src/testing/testing.go:1202 +0xa6
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:909 +0x199
  testing.runTests()
      /usr/local/go/src/testing/testing.go:1200 +0x521
  testing.(*M).Run()
      /usr/local/go/src/testing/testing.go:1117 +0x2ff
  main.main()
      _testmain.go:48 +0x223 

Goroutine 14 (finished) created at:
  net/http.(*Transport).dialConn()
      /usr/local/go/src/net/http/transport.go:1581 +0xc06
  net/http.(*Transport).dialConnFor()
      /usr/local/go/src/net/http/transport.go:1313 +0x14f
==================
    testing.go:853: race detected during execution of test

I've tried reproducing this locally but haven't been successful yet. It appears to be a pretty rare occurrence as I don't recall seeing a race more than a couple of times (and I'm not sure if the previous times were the same race or from an already patched one).

I suspect this is somehow related to rewinding the request body since the write appears to be when setting the request body: req.Body = ioutil.NopCloser(body) here and the read in the net/http library: if r.Body != nil here (note: this is in go 1.13.8)