Skip to content

x/net/http2: data race #48491

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.

Sign up for GitHub

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

Jump to bottom
Closed
horgh opened this issue Sep 20, 2021 · 6 comments
Closed

x/net/http2: data race #48491

horgh opened this issue Sep 20, 2021 · 6 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.

Comments

@horgh
Copy link
Contributor

horgh commented Sep 20, 2021

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

$ go version
go version go1.17.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
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/wstorey_maxmind_com/.cache/go-build"
GOENV="/home/wstorey_maxmind_com/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/wstorey_maxmind_com/go/pkg/mod"
GONOPROXY=""
GONOSUMDB="github.maxmind.com/*"
GOOS="linux"
GOPATH="/home/wstorey_maxmind_com/go"
GOPRIVATE=""
GOPROXY="https://go-proxy.maxmind.com/"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.17.1"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/wstorey_maxmind_com/http2-data-race/go.mod"
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-build247319395=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I ran a test using a GCP Compute API call using google.golang.org/api/compute/v1. The test is in this repo: https://github.com/horgh/http2-data-race

It works only on GCP VMs although I expect one could be written without that requirement. This is just how I was able to reproduce it.

What did you expect to see?

I expect the test to complete without issue

What did you see instead?

A data race was reported.

This began happening after I updated golang.org/x/net from golang/net@a5e0955 to golang/net@978cfad, although I don't know which commit in particular causes it (assuming one does).

=== RUN   TestDataRace
==================
WARNING: DATA RACE
Read at 0x00c00016e230 by goroutine 34:
  golang.org/x/net/http2.(*flow).add()
      /home/wstorey_maxmind_com/go/pkg/mod/golang.org/x/net@v0.0.0-20210917221730-978cfadd31cf/http2/flow.go:46 +0x844
  golang.org/x/net/http2.(*clientConnReadLoop).processData()
      /home/wstorey_maxmind_com/go/pkg/mod/golang.org/x/net@v0.0.0-20210917221730-978cfadd31cf/http2/transport.go:2381 +0x833
  golang.org/x/net/http2.(*clientConnReadLoop).run()
      /home/wstorey_maxmind_com/go/pkg/mod/golang.org/x/net@v0.0.0-20210917221730-978cfadd31cf/http2/transport.go:1960 +0x85e
  golang.org/x/net/http2.(*ClientConn).readLoop()
      /home/wstorey_maxmind_com/go/pkg/mod/golang.org/x/net@v0.0.0-20210917221730-978cfadd31cf/http2/transport.go:1812 +0xc4
  golang.org/x/net/http2.(*Transport).newClientConn·dwrap·34()
      /home/wstorey_maxmind_com/go/pkg/mod/golang.org/x/net@v0.0.0-20210917221730-978cfadd31cf/http2/transport.go:735 +0x39

Previous write at 0x00c00016e230 by goroutine 8:
  golang.org/x/net/http2.(*flow).add()
      /home/wstorey_maxmind_com/go/pkg/mod/golang.org/x/net@v0.0.0-20210917221730-978cfadd31cf/http2/flow.go:48 +0x744
  golang.org/x/net/http2.transportResponseBody.Read()
      /home/wstorey_maxmind_com/go/pkg/mod/golang.org/x/net@v0.0.0-20210917221730-978cfadd31cf/http2/transport.go:2248 +0x6c2
  bufio.(*Reader).Read()
      /usr/local/go/src/bufio/bufio.go:227 +0x4da
  io.ReadAtLeast()
      /usr/local/go/src/io/io.go:328 +0xdd
  io.ReadFull()
      /usr/local/go/src/io/io.go:347 +0xd8
  compress/gzip.(*Reader).readHeader()
      /usr/local/go/src/compress/gzip/gunzip.go:175 +0x73
  compress/gzip.(*Reader).Reset()
      /usr/local/go/src/compress/gzip/gunzip.go:113 +0x397
  compress/gzip.NewReader()
      /usr/local/go/src/compress/gzip/gunzip.go:94 +0x4b
  golang.org/x/net/http2.(*gzipReader).Read()
      /home/wstorey_maxmind_com/go/pkg/mod/golang.org/x/net@v0.0.0-20210917221730-978cfadd31cf/http2/transport.go:2718 +0x9c
  go.opencensus.io/plugin/ochttp.(*bodyTracker).Read()
      /home/wstorey_maxmind_com/go/pkg/mod/go.opencensus.io@v0.23.0/plugin/ochttp/trace.go:113 +0x65
  go.(*struct { io.ReadCloser }).Read()
      <autogenerated>:1 +0x7b
  go.opencensus.io/plugin/ochttp.(*tracker).Read()
      /home/wstorey_maxmind_com/go/pkg/mod/go.opencensus.io@v0.23.0/plugin/ochttp/client_stats.go:126 +0x67
  go.(*struct { io.ReadCloser }).Read()
      <autogenerated>:1 +0x7b
  encoding/json.(*Decoder).refill()
      /usr/local/go/src/encoding/json/stream.go:165 +0x410
  encoding/json.(*Decoder).readValue()
      /usr/local/go/src/encoding/json/stream.go:140 +0x188
  encoding/json.(*Decoder).Decode()
      /usr/local/go/src/encoding/json/stream.go:63 +0xd4
  google.golang.org/api/internal/gensupport.DecodeResponse()
      /home/wstorey_maxmind_com/go/pkg/mod/google.golang.org/api@v0.56.0/internal/gensupport/send.go:122 +0x426
  google.golang.org/api/compute/v1.(*InstancesAggregatedListCall).Do()
      /home/wstorey_maxmind_com/go/pkg/mod/google.golang.org/api@v0.56.0/compute/v1/compute-gen.go:87771 +0x32c
  google.golang.org/api/compute/v1.(*InstancesAggregatedListCall).Pages()
      /home/wstorey_maxmind_com/go/pkg/mod/google.golang.org/api@v0.56.0/compute/v1/compute-gen.go:87845 +0x1dd
  github.com/horgh/http2-data-race.TestDataRace()
      /home/wstorey_maxmind_com/http2-data-race/race_test.go:27 +0x25e
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1259 +0x22f
  testing.(*T).Run·dwrap·21()
      /usr/local/go/src/testing/testing.go:1306 +0x47

Goroutine 34 (running) created at:
  golang.org/x/net/http2.(*Transport).newClientConn()
      /home/wstorey_maxmind_com/go/pkg/mod/golang.org/x/net@v0.0.0-20210917221730-978cfadd31cf/http2/transport.go:735 +0x16aa
  golang.org/x/net/http2.(*Transport).NewClientConn()
      /home/wstorey_maxmind_com/go/pkg/mod/golang.org/x/net@v0.0.0-20210917221730-978cfadd31cf/http2/transport.go:666 +0xa6
  golang.org/x/net/http2.(*addConnCall).run()
      /home/wstorey_maxmind_com/go/pkg/mod/golang.org/x/net@v0.0.0-20210917221730-978cfadd31cf/http2/client_conn_pool.go:201 +0x53
  golang.org/x/net/http2.(*clientConnPool).addConnIfNeeded·dwrap·2()
      /home/wstorey_maxmind_com/go/pkg/mod/golang.org/x/net@v0.0.0-20210917221730-978cfadd31cf/http2/client_conn_pool.go:182 +0x71

Goroutine 8 (running) created at:
  testing.(*T).Run()
      /usr/local/go/src/testing/testing.go:1306 +0x726
  testing.runTests.func1()
      /usr/local/go/src/testing/testing.go:1598 +0x99
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1259 +0x22f
  testing.runTests()
      /usr/local/go/src/testing/testing.go:1596 +0x7ca
  testing.(*M).Run()
      /usr/local/go/src/testing/testing.go:1504 +0x9d1
  main.main()
      _testmain.go:43 +0x22b
==================
    testing.go:1152: race detected during execution of test
--- FAIL: TestDataRace (0.58s)
=== CONT
    testing.go:1152: race detected during execution of test
FAIL
exit status 1
FAIL    github.com/horgh/http2-data-race        0.613s
@horgh
Copy link
Contributor Author

horgh commented Sep 20, 2021

Note this won't happen every run of the test. I ran it in a loop and it happens after a bunch of tries.

@dr2chase dr2chase added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Sep 20, 2021
@josharian
Copy link
Contributor

@bradfitz @neild

@bmhatfield
Copy link

I'm also hitting this. We just updated go modules and run with the race detector locally and folks stuff started crashing. Same sha, 978cfadd31cf, flow.go:26 for us. This may actually be meaningful.

@bmhatfield
Copy link

Our previous, operating correctly, version of this was golang.org/x/net v0.0.0-20210716203947-853a461950ff

@gopherbot
Copy link
Contributor

Change https://golang.org/cl/351949 mentions this issue: Revert "http2: avoid blocking while holding ClientConn.mu"

@gopherbot
Copy link
Contributor

Change https://golang.org/cl/351950 mentions this issue: http: fix race in DATA frame padding refund

dteh pushed a commit to dteh/fhttp that referenced this issue Jun 22, 2022
@neild
http: fix race in DATA frame padding refund
db0e92f 
Move flow adjustment back under cc.mu.

Fixes golang/go#48491.

Change-Id: Idb762091cfeb55c18bc74389e62193f81438624f
Reviewed-on: https://go-review.googlesource.com/c/net/+/351950
Trust: Damien Neil <dneil@google.com>
Run-TryBot: Damien Neil <dneil@google.com>
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
@golang golang locked and limited conversation to collaborators Sep 24, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@josharian @horgh @bmhatfield @dr2chase @gopherbot