net/http: data race in closing http.Response.Body when still reading it

[yichengq]

> ==================
> WARNING: DATA RACE
> Write by goroutine 499:
>   net/http.(*persistConn).readLoop()
>       /usr/local/go/src/net/http/transport.go:929 +0xdb8
>
> Previous read by goroutine 189:
>   net/http.func·024()
>       /usr/local/go/src/net/http/transport.go:910 +0x4c
>   net/http.(*bodyEOFSignal).condfn()
>       /usr/local/go/src/net/http/transport.go:1228 +0x105
>   net/http.(*bodyEOFSignal).Read()
>       /usr/local/go/src/net/http/transport.go:1200 +0x41c
>   io.ReadAtLeast()
>       /usr/local/go/src/io/io.go:298 +0x128
>   io.ReadFull()
>       /usr/local/go/src/io/io.go:316 +0x7d
>   encoding/binary.Read()
>       /usr/local/go/src/encoding/binary/binary.go:148 +0x14f
>   github.com/coreos/etcd/rafthttp.(*msgAppDecoder).decode()
>       /Users/unihorn/gopath/src/github.com/coreos/etcd/rafthttp/msgapp.go:66
> +0x13c
>   github.com/coreos/etcd/rafthttp.(*streamReader).run()
>
> /Users/unihorn/gopath/src/github.com/coreos/etcd/rafthttp/stream.go:309
> +0x387
>   runtime.goexit()
>       /usr/local/go/src/runtime/asm_amd64.s:2232 +0x0
>   net/http.func·008()
>       /usr/local/go/src/net/http/server.go:171 +0xb6
>
> Goroutine 499 (running) created at:
>   net/http.(*Transport).dialConn()
>       /usr/local/go/src/net/http/transport.go:660 +0x10d4
>   net/http.func·019()
>       /usr/local/go/src/net/http/transport.go:520 +0x8d

They share a alive variable, and this may be the problem.

[dvyukov]

@bradfitz

It looks like at can be harmful. Consider that bodyEOFSignal reads
alive=true and sends true on waitForBodyRead; then readLoop sets
alive=false; then readLoop receives true on waitForBodyRead and sets
alive to true again.

Probably we need to do:

waitForBodyRead <- err == nil &&
!pc.sawEOF &&
pc.wroteRequest() &&
pc.t.putIdleConn(pc)

and then:

case a := <-waitForBodyRead:
alive &= a

[dvyukov]

Flaked on race builder while trying https://go-review.googlesource.com/#/c/7570:

==================
WARNING: DATA RACE
Write by goroutine 168:
  net/http.(*persistConn).readLoop()
      /tmp/buildlet-scatch242213319/go/src/net/http/transport.go:931 +0xcad

Previous read by goroutine 31:
  net/http.(*persistConn).readLoop.func2()
      /tmp/buildlet-scatch242213319/go/src/net/http/transport.go:910 +0x4b
  net/http.(*bodyEOFSignal).condfn()
      /tmp/buildlet-scatch242213319/go/src/net/http/transport.go:1234 +0xff
  net/http.(*bodyEOFSignal).Read()
      /tmp/buildlet-scatch242213319/go/src/net/http/transport.go:1206 +0x418
  bytes.(*Buffer).ReadFrom()
      /tmp/buildlet-scatch242213319/go/src/bytes/buffer.go:173 +0x45e
  io/ioutil.readAll()
      /tmp/buildlet-scatch242213319/go/src/io/ioutil/ioutil.go:33 +0x1ba
  io/ioutil.ReadAll()
      /tmp/buildlet-scatch242213319/go/src/io/ioutil/ioutil.go:42 +0x74
  net/http_test.TestTransportConcurrency.func3()
      /tmp/buildlet-scatch242213319/go/src/net/http/transport_test.go:1117 +0x392

Goroutine 168 (running) created at:
  net/http.(*Transport).dialConn()
      /tmp/buildlet-scatch242213319/go/src/net/http/transport.go:660 +0x1045
  net/http.(*Transport).getConn.func3()
      /tmp/buildlet-scatch242213319/go/src/net/http/transport.go:520 +0x47

Goroutine 31 (running) created at:
  net/http_test.TestTransportConcurrency()
      /tmp/buildlet-scatch242213319/go/src/net/http/transport_test.go:1129 +0x58a
  testing.tRunner()
      /tmp/buildlet-scatch242213319/go/src/testing/testing.go:452 +0xfc
==================

https://storage.googleapis.com/go-build-log/9125f9a4/linux-amd64-race_77dfbf50.log

It seems to reproduce reliably with this change.
And the race does look harmful.
@bradfitz

[bradfitz]

Sent https://go-review.googlesource.com/8550

[DanielMorsing]

How is this race possible? We only write to alive unsynchronized when we have no body and we only install the function that is racing with that write when we do have a body.

[dvyukov]

Perhaps there were 2 requests on the connection: one with a body and another without a body.

[bradfitz]

I have a revised fix for this. Just needs a new test.

[DanielMorsing]

I might fix this through https://go-review.googlesource.com/#/c/9120/