Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

net/http: race in http2Transport #31192

Closed
vadmeste opened this issue Apr 1, 2019 · 32 comments
Closed

net/http: race in http2Transport #31192

vadmeste opened this issue Apr 1, 2019 · 32 comments
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done. release-blocker
Milestone

Comments

@vadmeste
Copy link

vadmeste commented Apr 1, 2019

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

go version go1.12.1 linux/amd64

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (go env)?

go env Output
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/vadmeste/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/vadmeste/work/gospace"
GOPROXY=""
GORACE=""
GOROOT="/home/vadmeste/work/go"
GOTMPDIR=""
GOTOOLDIR="/home/vadmeste/work/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build457736797=/tmp/go-build -gno-record-gcc-switches"

What did you do?

  1. Generate a self signed certificate:
$ openssl req -newkey rsa:2048 -nodes -keyout private.key -x509 -days 365 -out public.crt -subj "/C=US/ST=state/L=location/O=organization/CN=localhost"
  1. Ask the OS to trust the generated self signed certificate
$ # Tested under Ubuntu
$ sudo cp public.crt /usr/local/share/ca-certificates/
$ sudo update-ca-certificates
  1. Run the following test code: https://play.golang.org/p/mxV6_0TW-Ji
$ go run -race testcode.go

What did you expect to see?

No race detector warning

What did you see instead?

WARNING: DATA RACE
Write at 0x00c00180d1b8 by goroutine 17:
  main.main.func2()
      /home/vadmeste/work/go/src/bytes/buffer.go:102 +0x186

Previous write at 0x00c00180d1b8 by goroutine 203:
  bytes.(*Buffer).Read()
      /home/vadmeste/work/go/src/bytes/buffer.go:310 +0x266
  io/ioutil.(*nopCloser).Read()
      <autogenerated>:1 +0x87
  net/http.(*http2clientStream).writeRequestBody()
      /home/vadmeste/work/go/src/net/http/h2_bundle.go:7664 +0x64d
  net/http.(*http2Transport).getBodyWriterState.func1()
      /home/vadmeste/work/go/src/net/http/h2_bundle.go:8878 +0x13d

Goroutine 17 (running) created at:
  main.main()
      /home/vadmeste/x/testcode.go:48 +0x277

Goroutine 203 (running) created at:
  net/http.http2bodyWriterState.scheduleBodyWrite()
      /home/vadmeste/work/go/src/net/http/h2_bundle.go:8925 +0x12f
  net/http.(*http2ClientConn).roundTrip()
      /home/vadmeste/work/go/src/net/http/h2_bundle.go:7465 +0x90f
  net/http.(*http2Transport).RoundTripOpt()
      /home/vadmeste/work/go/src/net/http/h2_bundle.go:6867 +0x23d
  net/http.http2noDialH2RoundTripper.RoundTrip()
      /home/vadmeste/work/go/src/net/http/h2_bundle.go:6829 +0x4c
  net/http.(*Transport).roundTrip()
      /home/vadmeste/work/go/src/net/http/transport.go:430 +0x14d9
  net/http.(*Transport).RoundTrip()
      /home/vadmeste/work/go/src/net/http/roundtrip.go:17 +0x42
  net/http.send()
      /home/vadmeste/work/go/src/net/http/client.go:250 +0x6a9
  net/http.(*Client).send()
      /home/vadmeste/work/go/src/net/http/client.go:174 +0x1cb
  net/http.(*Client).do()
      /home/vadmeste/work/go/src/net/http/client.go:641 +0x4ef
  main.main.func2()
      /home/vadmeste/work/go/src/net/http/client.go:509 +0x4e0
@dgryski
Copy link
Contributor

dgryski commented Apr 1, 2019

@bradfitz @tombergan

@bradfitz bradfitz changed the title x/net/http2 client call causing a race detector warning x/net/http2: client call causing a race detector warning Apr 2, 2019
vadmeste added a commit to vadmeste/minio that referenced this issue Apr 2, 2019
A race is detected between a bytes.Buffer generated with cmd/rpc.Pool
and http2 module. An issue is raised in golang (golang/go#31192).

Meanwhile, this commit disables Pool in RPC code and it generates a
new 1kb of bytes.Buffer for each RPC call.
kannappanr pushed a commit to minio/minio that referenced this issue Apr 2, 2019
A race is detected between a bytes.Buffer generated with cmd/rpc.Pool
and http2 module. An issue is raised in golang (golang/go#31192).

Meanwhile, this commit disables Pool in RPC code and it generates a
new 1kb of bytes.Buffer for each RPC call.
@andybons andybons added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Apr 3, 2019
@andybons andybons added this to the Go1.13 milestone Apr 3, 2019
@bcmills bcmills changed the title x/net/http2: client call causing a race detector warning net/http: race in http2Transport Apr 9, 2019
@fraenkel
Copy link
Contributor

@bradfitz This might be the same issue with http. There is no guarantee that the bodyWriter is complete when roundtrip exits.

@andybons andybons modified the milestones: Go1.13, Go1.14 Jul 8, 2019
@rsc rsc modified the milestones: Go1.14, Backlog Oct 9, 2019
@odeke-em
Copy link
Member

Here is a standalone adapted from @vadmeste's original program but here one doesn't have to manually create certificates but also it is reduced down

package main

import (
	"bytes"
	"fmt"
	"io"
	"io/ioutil"
	"log"
	"net/http"
	"net/http/httptest"

	"golang.org/x/net/http2"
)

func main() {
	cst := httptest.NewUnstartedServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		fmt.Fprintf(w, "Pong")
	}))
	if err := http2.ConfigureServer(cst.Config, new(http2.Server)); err != nil {
		log.Fatalf("Failed to configure http2 server: %v", err)
	}
	cst.TLS = cst.Config.TLSConfig

	tr := &http.Transport{TLSClientConfig: cst.Config.TLSConfig}
	if err := http2.ConfigureTransport(tr); err != nil {
		log.Fatalf("Failed to configure http2 transport: %v", err)
	}
	tr.TLSClientConfig.InsecureSkipVerify = true
	cst.StartTLS()
	defer cst.Close()

	// Then finally create the HTTP client with the HTTP/2 transport.
	client := &http.Client{Transport: tr}

	for i := 0; i < 3; i++ {
		// Fill buf with data
		buf := bytes.NewBuffer(bytes.Repeat([]byte("A"), 128*1024))

		// Make a POST http call and read and discard response
		req, err := http.NewRequest("POST", cst.URL, buf)
		resp, err := client.Do(req)
		if err != nil {
			log.Fatalln(err)
		}
                if _, err := io.Copy(ioutil.Discard, resp.Body); err != nil {
			log.Fatalln(err)
		}
		resp.Body.Close()

		// Accessing buf here causes a RACE WARNING
		buf.Reset()
		fmt.Printf(".")
	}
}

@pmalek
Copy link

pmalek commented Jun 14, 2020

@fraenkel Modifying @odeke-em 's example to use http like so:

package main

import (
	"bytes"
	"fmt"
	"io"
	"io/ioutil"
	"log"
	"net/http"
	"net/http/httptest"
)

func main() {
	srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		fmt.Fprintf(w, "Pong")
	}))
	defer srv.Close()

	client := srv.Client()

	for i := 0; i < 100; i++ {
		// Fill buf with data
		buf := bytes.NewBuffer(bytes.Repeat([]byte("A"), 128*1024))

		// Make a POST http call, read and discard response
		req, err := http.NewRequest("POST", srv.URL, buf)
		resp, err := client.Do(req)
		if err != nil {
			log.Fatalln(err)
		}
		if _, err := io.Copy(ioutil.Discard, resp.Body); err != nil {
			log.Fatalln(err)
		}
		resp.Body.Close()

		buf.Reset()
		fmt.Printf(".")
	}
}

I do not observe a data race.

The original issue is still present in gotip from go version devel +bd486c3 Sat Jun 13 16:03:19 2020 +0000 linux/amd64 and in 1.14.2.

There is no guarantee that the bodyWriter is complete when roundtrip exits.
I'm wondering what might be the fix for this. Could we make it so that the bodyWriter is complete when roundtrip exits?

@odeke-em
Copy link
Member

odeke-em commented Jun 14, 2020 via email

@pmalek
Copy link

pmalek commented Jun 14, 2020

@odeke-em My bad. But the TLS is also required to trigger this bug so both ts.EnableHTTP2 = true and ts.StartTLS() instead of ts.Start() in my simplified example will trigger the data race.

@fraenkel
Copy link
Contributor

It took me a bit to reproduce the issue and then find the statement that covers this situation.

https://golang.org/pkg/net/http/#RoundTripper
callers wanting to reuse the body for subsequent requests must arrange to wait for the Close call before doing so.

The body isn't closed until net/http.(*http2clientStream).writeRequestBody() returns.

@pmalek
Copy link

pmalek commented Jun 15, 2020

...must arrange to wait for the Close call...

That's interesting because as far as I can see there's no way of telling outside of the e.g. http.Post or http.Do call, whether the Close was called and that it returned.

@fraenkel
Copy link
Contributor

fraenkel commented Sep 6, 2020

Looking at this further, the issue is when a GOAWAY is sent from the server all outstanding streams are sent a response errClientConnGotGoAway. However, cs.writeRequestBody() may still be executing.

@fraenkel
Copy link
Contributor

fraenkel commented Sep 6, 2020

Good news, its easy to fix. Just have to create a test that always fails.

@gopherbot
Copy link

Change https://golang.org/cl/253259 mentions this issue: net/http2: wait until the request body has been written

@answer1991
Copy link

@andybons

Could you please add this fix to next milestone, as Kubernetes affected.

@answer1991
Copy link

Could you please add this fix to next milestone, as Kubernetes affected.

@rsc

@networkimprov
Copy link

@odeke-em are you available to review the above CL?

@ianlancetaylor ianlancetaylor modified the milestones: Backlog, Go1.16 Sep 24, 2020
@toothrot
Copy link
Contributor

/cc @neild

@networkimprov
Copy link

We had a request to backport this, as it impacts Kubernetes, per @answer1991.

@odeke-em
Copy link
Member

@dmitshur what do you think about the requested backport from @answer1991 and @networkimprov per #31192 (comment)?

@answer1991
Copy link

Glad to see the fix merged.
As Kubernetes now is using golang 1.15.x, it would be fine if we backport the fix to 1.15.

@dmitshur
Copy link
Contributor

dmitshur commented Nov 2, 2020

I don't have enough information to know the severity of impact caused by this problem and whether there's a reasonable workaround. We need that information to balance it against the risk of backporting a commit when making a decision.

@answer1991 The process for requesting a backport is described at https://golang.org/wiki/MinorReleases. If after reading it you think this issue should be considered for backporting, please use gopherbot to make a request and provide a brief rationale for it. I know you've said this impacts Kubernetes, but please provide a little more detail about how serious it is. Thanks.

CC @golang/release.

@answer1991
Copy link

Kubernetes team had already announced GOAWAY feature in Kubernetes v1.19 release notes. However, if Kubernetes enable GOAWAY feature, the client will receive unexpected 500 status code errors which I described at #41234, and there is no workaround. I think backport to golang 1.15 is necessary.

@gopherbot please backport, as Kubernetes is affected and there is no workaround.

@gopherbot
Copy link

Backport issue(s) opened: #42539 (for 1.15).

Remember to create the cherry-pick CL(s) as soon as the patch is submitted to master, according to https://golang.org/wiki/MinorReleases.

@networkimprov
Copy link

@dmitshur @toothrot I think this needs backport to 1.14 as well?

@dmitshur
Copy link
Contributor

Yep, since the issue affects both Go 1.15 and 1.14, it needs to be considered for backport to both, or neither. (We typically double-check that as part reviewing backport requests, but it's helpful to also catch it earlier.)

@answer1991
Copy link

I don't know why the bot didn't create a cherry-pick to Go 1.14. Because I mentioned 1.15 in my comment? Re-try

@answer1991
Copy link

Kubernetes team had already announced GOAWAY feature in Kubernetes v1.19 release notes. However, if Kubernetes enable GOAWAY feature, the client will receive unexpected 500 status code errors which I described at #41234, and there is no workaround. I think backport is necessary.

@gopherbot please backport, as Kubernetes is affected and there is no workaround.

@dmitshur
Copy link
Contributor

Backport issue opened: #42586 (for 1.14).

(Follow up requests are not supported, so they need to be created manually until #25574 is resolved.)

@answer1991
Copy link

thanks!

@dmitshur dmitshur added NeedsFix The path to resolution is known, but the work has not been done. and removed NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Nov 20, 2020
@dmitshur
Copy link
Contributor

dmitshur commented Nov 20, 2020

Reopening as the net/http issue isn't fixed in Go 1.16 yet.

This issue got closed because CL 253259 was submitted with the phrase "Fixes #31192". However that CL is for x/net. The bundled copy of golang.org/x/net/http2 inside net/http still needs to be updated to include the fix.

Doing the bundle update was attempted, but it caused an existing net/http test to fail. This is #42498. That issue needs to be resolved.

@dmitshur dmitshur reopened this Nov 20, 2020
@neild
Copy link
Contributor

neild commented Dec 4, 2020

#42498 has been resolved (I believe), and should no longer block doing the bundle update.

@answer1991
Copy link

Should we backport #42498 too?

@gopherbot
Copy link

Change https://golang.org/cl/275446 mentions this issue: all: update dependencies with changes in scope for Go 1.16 freeze

@gopherbot
Copy link

Change https://golang.org/cl/277012 mentions this issue: std: update golang.org/x/net to 20201209123823-ac852fbbde11

@golang golang locked and limited conversation to collaborators Dec 10, 2021
dteh pushed a commit to dteh/fhttp that referenced this issue Jun 22, 2022
When the clientConn is done with a request, if there is a request body,
we must wait until the body is written otherwise there can be a race
when attempting to rewind the body.

Fixes golang/go#31192
Fixes golang/go#41234

Change-Id: I77606cc19372eea8bbd8995102354f092b8042be
Reviewed-on: https://go-review.googlesource.com/c/net/+/253259
Reviewed-by: Damien Neil <dneil@google.com>
Trust: Emmanuel Odeke <emmanuel@orijtech.com>
Run-TryBot: Emmanuel Odeke <emmanuel@orijtech.com>
TryBot-Result: Go Bot <gobot@golang.org>
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done. release-blocker
Projects
None yet
Development

No branches or pull requests