net/http: data race involving `net/http.(*http2Framer).WriteDataPadded`

[bcmills]

#!watchflakes
post <- pkg == "net/http" && log ~ `DATA RACE` && log ~ `net/http\.\(\*http2Framer\)\.WriteDataPadded`

https://build.golang.org/log/8f9829a1eacef63f57dd92e8a7647ac7fdd04a3a:

==================
WARNING: DATA RACE
Write at 0x00c00085e000 by goroutine 5319:
  net/http_test.neverEnding.Read()
      /workdir/go/src/net/http/serve_test.go:3014 +0x78
  net/http_test.(*neverEnding).Read()
      <autogenerated>:1 +0x1f
  io.copyBuffer()
      /workdir/go/src/io/io.go:428 +0x2c8
  io.Copy()
      /workdir/go/src/io/io.go:386 +0x57
  net/http_test.testIssue4191_InfiniteGetTimeout.func1()
      /workdir/go/src/net/http/transport_test.go:2229 +0x13
  net/http.HandlerFunc.ServeHTTP()
      /workdir/go/src/net/http/server.go:2111 +0x47
  net/http.(*ServeMux).ServeHTTP()
      /workdir/go/src/net/http/server.go:2489 +0xbc
  net/http.serverHandler.ServeHTTP()
      /workdir/go/src/net/http/server.go:2925 +0x682
  net/http.initALPNRequest.ServeHTTP()
      /workdir/go/src/net/http/server.go:3538 +0x34d
  net/http.(*initALPNRequest).ServeHTTP()
      <autogenerated>:1 +0x7b
  net/http.Handler.ServeHTTP-fm()
      <autogenerated>:1 +0x67
  net/http.(*http2serverConn).runHandler()
      /workdir/go/src/net/http/h2_bundle.go:6049 +0xe1
  net/http.(*http2serverConn).processHeaders.func1()
      /workdir/go/src/net/http/h2_bundle.go:5762 +0x5d

Previous read at 0x00c00085e000 by goroutine 5251:
  runtime.slicecopy()
      /workdir/go/src/runtime/slice.go:310 +0x0
  net/http.(*http2Framer).WriteDataPadded()
      /workdir/go/src/net/http/h2_bundle.go:2025 +0x4dc
  net/http.(*http2Framer).WriteData()
      /workdir/go/src/net/http/h2_bundle.go:1985 +0xdc
  net/http.(*http2writeData).writeFrame()
      /workdir/go/src/net/http/h2_bundle.go:10220 +0x1a
  net/http.(*http2serverConn).writeFrameAsync()
      /workdir/go/src/net/http/h2_bundle.go:4589 +0x85
  net/http.(*http2serverConn).startFrameWrite.func1()
      /workdir/go/src/net/http/h2_bundle.go:5000 +0x6b

Goroutine 5319 (running) created at:
  net/http.(*http2serverConn).processHeaders()
      /workdir/go/src/net/http/h2_bundle.go:5762 +0xdfb
  net/http.(*http2serverConn).processFrame()
      /workdir/go/src/net/http/h2_bundle.go:5262 +0x445
  net/http.(*http2serverConn).processFrameFromReader()
      /workdir/go/src/net/http/h2_bundle.go:5205 +0x2de
  net/http.(*http2serverConn).serve()
      /workdir/go/src/net/http/h2_bundle.go:4694 +0x15b0
  net/http.(*http2Server).ServeConn()
      /workdir/go/src/net/http/h2_bundle.go:4270 +0x181d
  net/http.http2ConfigureServer.func1()
      /workdir/go/src/net/http/h2_bundle.go:4060 +0x11e
  net/http.(*conn).serve()
      /workdir/go/src/net/http/server.go:1892 +0x1c01
  net/http.(*Server).Serve.func3()
      /workdir/go/src/net/http/server.go:3078 +0x4f

Goroutine 5251 (finished) created at:
  net/http.(*http2serverConn).startFrameWrite()
      /workdir/go/src/net/http/h2_bundle.go:5000 +0x5fa
  net/http.(*http2serverConn).scheduleFrameWrite()
      /workdir/go/src/net/http/h2_bundle.go:5102 +0x3c8
  net/http.(*http2serverConn).wroteFrame()
      /workdir/go/src/net/http/h2_bundle.go:5062 +0x469
  net/http.(*http2serverConn).serve()
      /workdir/go/src/net/http/h2_bundle.go:4690 +0x154b
  net/http.(*http2Server).ServeConn()
      /workdir/go/src/net/http/h2_bundle.go:4270 +0x181d
  net/http.http2ConfigureServer.func1()
      /workdir/go/src/net/http/h2_bundle.go:4060 +0x11e
  net/http.(*conn).serve()
      /workdir/go/src/net/http/server.go:1892 +0x1c01
  net/http.(*Server).Serve.func3()
      /workdir/go/src/net/http/server.go:3078 +0x4f
==================

https://build.golang.org/log/abcd1afb8c807a6e0947447747212fe2afa0183b:

==================
WARNING: DATA RACE
Write at 0x00c000b68000 by goroutine 23273:
  net/http_test.neverEnding.Read()
      /workdir/go/src/net/http/serve_test.go:3014 +0x78
  net/http_test.(*neverEnding).Read()
      <autogenerated>:1 +0x1f
  io.copyBuffer()
      /workdir/go/src/io/io.go:428 +0x2c8
  io.Copy()
      /workdir/go/src/io/io.go:386 +0x2ee
  net/http.(*response).ReadFrom()
      /workdir/go/src/net/http/server.go:601 +0x27f
  io.copyBuffer()
      /workdir/go/src/io/io.go:420 +0x1ef
  io.Copy()
      /workdir/go/src/io/io.go:386 +0x57
  net/http_test.testIssue4191_InfiniteGetToPutTimeout.func1()
      /workdir/go/src/net/http/transport_test.go:2268 +0x13
  net/http.HandlerFunc.ServeHTTP()
      /workdir/go/src/net/http/server.go:2111 +0x47
  net/http.(*ServeMux).ServeHTTP()
      /workdir/go/src/net/http/server.go:2489 +0xbc
  net/http.serverHandler.ServeHTTP()
      /workdir/go/src/net/http/server.go:2925 +0x682
  net/http.(*conn).serve()
      /workdir/go/src/net/http/server.go:1984 +0xbe4
  net/http.(*Server).Serve.func3()
      /workdir/go/src/net/http/server.go:3078 +0x4f

Previous read at 0x00c000b68000 by goroutine 23266:
  runtime.slicecopy()
      /workdir/go/src/runtime/slice.go:310 +0x0
  net/http.(*http2Framer).WriteDataPadded()
      /workdir/go/src/net/http/h2_bundle.go:2025 +0x4dc
  net/http.(*http2Framer).WriteData()
      /workdir/go/src/net/http/h2_bundle.go:1985 +0xdc
  net/http.(*http2writeData).writeFrame()
      /workdir/go/src/net/http/h2_bundle.go:10220 +0x1a
  net/http.(*http2serverConn).writeFrameAsync()
      /workdir/go/src/net/http/h2_bundle.go:4589 +0x85
  net/http.(*http2serverConn).startFrameWrite.func1()
      /workdir/go/src/net/http/h2_bundle.go:5000 +0x6b

Goroutine 23273 (running) created at:
  net/http.(*Server).Serve()
      /workdir/go/src/net/http/server.go:3078 +0x817
  net/http/httptest.(*Server).goServe.func1()
      /workdir/go/src/net/http/httptest/server.go:310 +0xaa

Goroutine 23266 (finished) created at:
  net/http.(*http2serverConn).startFrameWrite()
      /workdir/go/src/net/http/h2_bundle.go:5000 +0x5fa
  net/http.(*http2serverConn).scheduleFrameWrite()
      /workdir/go/src/net/http/h2_bundle.go:5102 +0x3c8
  net/http.(*http2serverConn).wroteFrame()
      /workdir/go/src/net/http/h2_bundle.go:5062 +0x469
  net/http.(*http2serverConn).serve()
      /workdir/go/src/net/http/h2_bundle.go:4690 +0x154b
  net/http.(*http2Server).ServeConn()
      /workdir/go/src/net/http/h2_bundle.go:4270 +0x181d
  net/http.http2ConfigureServer.func1()
      /workdir/go/src/net/http/h2_bundle.go:4060 +0x11e
  net/http.(*conn).serve()
      /workdir/go/src/net/http/server.go:1892 +0x1c01
  net/http.(*Server).Serve.func3()
      /workdir/go/src/net/http/server.go:3078 +0x4f
==================

[bcmills]

This may have been introduced in or around CL 456555.

[neild]

Looks like the HTTP/2 server is reading from a buffer passed to ResponseWriter.Write after the Write call has returned, which is not okay.

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net/http" && `DATA RACE` && `net/http\.\(\*http2Framer\)\.WriteDataPadded` && `net/http_test\.neverEnding\.Read`

2023-01-31 19:43 linux-amd64-longtest-race go@b89a840d net/http.TestIssue4191_InfiniteGetToPutTimeout (log)

==================
WARNING: DATA RACE
Write at 0x00c000b68000 by goroutine 23273:
  net/http_test.neverEnding.Read()
      /workdir/go/src/net/http/serve_test.go:3014 +0x78
  net/http_test.(*neverEnding).Read()
      <autogenerated>:1 +0x1f
  io.copyBuffer()
      /workdir/go/src/io/io.go:428 +0x2c8
  io.Copy()
...
  net/http.(*conn).serve()
      /workdir/go/src/net/http/server.go:1892 +0x1c01
  net/http.(*Server).Serve.func3()
      /workdir/go/src/net/http/server.go:3078 +0x4f
==================
--- FAIL: TestIssue4191_InfiniteGetToPutTimeout (0.51s)
    --- FAIL: TestIssue4191_InfiniteGetToPutTimeout/h1 (0.51s)
        testing.go:1446: race detected during execution of test
    testing.go:1446: race detected during execution of test
2023/01/31 20:16:22 Unsolicited response received on idle HTTP channel starting with "HTTP/1.1 204 No Content\r\nConnection: close\r\n\r\n"; err=<nil>

— watchflakes