go: x/net/http2: investigate data race in Transport Request.Body reuse when GetBody is not defined

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

$ go version go version go1.10.1 linux/amd64

Does this issue reproduce with the latest release?

yes

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

GOARCH=“amd64” GOBIN=“” GOCACHE=“/home/test/.cache/go-build” GOEXE=“” GOHOSTARCH=“amd64” GOHOSTOS=“linux” GOOS=“linux” GORACE=“” GOROOT=“/home/test/go” GOTMPDIR=“” GOTOOLDIR=“/home/test/go/pkg/tool/linux_amd64” GCCGO=“gccgo” CC=“gcc” CXX=“g++” CGO_ENABLED=“1” 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-build614182611=/tmp/go-build -gno-record-gcc-switches”

and nginx version: nginx/1.13.3

What did you do?

Here is my client:

package main

import (
    "fmt"
    "net/http"
    "sync"
    "time"
    "errors"
    "bytes"
    "io/ioutil"
)

type Client struct {
    urlBase    string
    httpClient *http.Client
}

func NewClient(url string) *Client {
    cc := &Client{
        urlBase:    url,
        httpClient: &http.Client{Transport: &http.Transport{MaxIdleConnsPerHost: 100, MaxIdleConns: 100, IdleConnTimeout: 90 * time.Second, ExpectContinueTimeout: 5 * time.Second}},
    }
    cc.httpClient.Timeout = 5 * time.Second
    return cc
}

func (self *Client) Send(content []byte) error {
    if content == nil {
        return errors.New("nil content")
    }

    body := &bytes.Buffer{}
    body.Write(content)

    begin := time.Now()
    req, err := http.NewRequest("POST", self.urlBase, body)
    if err != nil {
        return fmt.Errorf("Send %+v (from %v to %v)", err, begin, time.Now())
    }
    req.Header = make(http.Header)
    req.Header.Set("Content-Type", "application/json")
    begin = time.Now()
    resp, err := self.httpClient.Do(req)
    if err != nil {
        return fmt.Errorf("Send %+v (from %v to %v)", err, begin, time.Now())
    }
    defer resp.Body.Close()

    if resp.StatusCode >= http.StatusBadRequest {
        bs, _ := ioutil.ReadAll(resp.Body)
        return fmt.Errorf("Send : HTTP : %d , BODY : %s , REQ : %s", resp.StatusCode, string(bs), string(content))
    }

    bs, err := ioutil.ReadAll(resp.Body)
    if err != nil {
        return fmt.Errorf("Send : ERR : %v", err)
    }
    fmt.Println("Send : Resp : ", string(bs))
    return nil
}

func main() {
    client := NewClient(
        "https://test.cn", // I use /etc/hosts to bind the domain
    )
    var content = []byte(`{"test":1}`)
    var wg sync.WaitGroup
    for i := 0; i < 100; i++ {
        wg.Add(1)
        go func() {
            defer wg.Done()
            client.Send(content)
        }()
    }
    wg.Wait()
}

And here is my nginx configure of http2:

    http2_max_concurrent_streams 40960;
    http2_max_requests 3;
    http2_max_field_size  8k;
    http2_max_header_size  32k;
    http2_recv_buffer_size 1024k;
    http2_recv_timeout  120s;

What did you expect to see?

I expect all requests are successfully.

What did you see instead?

But I got 400 occasionally and found client prematurely closed stream: only 0 out of 10 bytes of request body received line in nginx log.

I used GODEBUG to try to figure out, and found data not sent after END_HEADERS：

2018/04/23 18:32:25 http2: Transport encoding header ":method" = "POST"
2018/04/23 18:32:25 http2: Transport encoding header ":path" = "/"
2018/04/23 18:32:25 http2: Transport encoding header ":scheme" = "https"
2018/04/23 18:32:25 http2: Transport encoding header "content-type" = "application/json"
2018/04/23 18:32:25 http2: Transport encoding header "content-length" = "10"
2018/04/23 18:32:25 http2: Transport encoding header "accept-encoding" = "gzip"
2018/04/23 18:32:25 http2: Transport encoding header "user-agent" = "Go-http-client/2.0"
2018/04/23 18:32:25 http2: Framer 0xc4205480e0: wrote HEADERS flags=END_HEADERS stream=5 len=8
2018/04/23 18:32:25 http2: Framer 0xc4205480e0: wrote DATA flags=END_STREAM stream=5 len=0 data=""

That’s the reason why nginx responsed 400 directly.