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: data race in net/http.(*expectContinueReader) #43769

Open
gozssky opened this issue Jan 19, 2021 · 4 comments
Open

net/http: data race in net/http.(*expectContinueReader) #43769

gozssky opened this issue Jan 19, 2021 · 4 comments
Milestone

Comments

@gozssky
Copy link

@gozssky gozssky commented Jan 19, 2021

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

$ go version
go version go1.15.6 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/xyj/.cache/go-build"
GOENV="/home/xyj/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/xyj/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/xyj/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/lib/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/lib/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
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-build120895179=/tmp/go-build -gno-record-gcc-switches"

What did you do?

There are two background loops for each connection. readLoop reads responses from server and writeLoop writes reqeusts to server.

In a ReverseProxy, request.Body that writeLoop used may be a net/http.(*expectContinueReader). It means we must send "100 Continue" to client if we want to read data from the body. It may lead to concurrent writes to a same connection from readLoop and writeLoop.

What's worse, the connection is probably closed without waiting writeLoop to exit. After connection is closed, (*conn).bufw will be set to nil. See https://github.com/golang/go/blob/go1.15.6/src/net/http/server.go#L1690 . If writeLoop continues writing data to the connection, a panic will occur. Something like "Invalid memory address or nil pointer dereference".

This bug is mentioned in #29321. But that issue hasn't been updated for a long time, probably because of the label WaitingForInfo.

Reproduce code is https://play.golang.org/p/6i3dUmUgOjK. You need to run with race detector.

What did you expect to see?

There is no data race or panic.

What did you see instead?

Data race occurred. In very rare case, this caused panic.

Data Race Output
==================
WARNING: DATA RACE
Read at 0x00c00022c068 by goroutine 23:
  bufio.(*Writer).Available()
      /usr/lib/go/src/bufio/bufio.go:624 +0xce
  bufio.(*Writer).WriteString()
      /usr/lib/go/src/bufio/bufio.go:705 +0x2f
  net/http.writeStatusLine()
      /usr/lib/go/src/net/http/server.go:1506 +0x7a
  net/http.(*chunkWriter).writeHeader()
      /usr/lib/go/src/net/http/server.go:1476 +0xd77
  net/http.(*chunkWriter).close()
      /usr/lib/go/src/net/http/server.go:402 +0x188
  net/http.(*response).finishRequest()
      /usr/lib/go/src/net/http/server.go:1622 +0xc9
  net/http.(*conn).serve()
      /usr/lib/go/src/net/http/server.go:1930 +0x8a4
Previous write at 0x00c00022c068 by goroutine 39: bufio.(*Writer).Flush() /usr/lib/go/src/bufio/bufio.go:619 +0x3c4 net/http.(*expectContinueReader).Read() /usr/lib/go/src/net/http/server.go:905 +0x2c7 io.(*LimitedReader).Read() /usr/lib/go/src/io/io.go:455 +0xc7 io.copyBuffer() /usr/lib/go/src/io/io.go:409 +0x14b io.Copy() /usr/lib/go/src/io/io.go:368 +0xb0 net.genericReadFrom() /usr/lib/go/src/net/net.go:643 +0x32 net.(*TCPConn).readFrom() /usr/lib/go/src/net/tcpsock_posix.go:54 +0x17c net.(*TCPConn).ReadFrom() /usr/lib/go/src/net/tcpsock.go:103 +0x79 io.copyBuffer() /usr/lib/go/src/io/io.go:395 +0x3fe io.Copy() /usr/lib/go/src/io/io.go:368 +0xb5 net/http.persistConnWriter.ReadFrom() /usr/lib/go/src/net/http/transport.go:1733 +0x32 bufio.(*Writer).ReadFrom() /usr/lib/go/src/bufio/bufio.go:730 +0x554 io.copyBuffer() /usr/lib/go/src/io/io.go:395 +0x3fe io.Copy() /usr/lib/go/src/io/io.go:368 +0x78 net/http.(*transferWriter).doBodyCopy() /usr/lib/go/src/net/http/transfer.go:400 +0x2f net/http.(*transferWriter).writeBody() /usr/lib/go/src/net/http/transfer.go:359 +0xc31 net/http.(*Request).write() /usr/lib/go/src/net/http/request.go:682 +0x887 net/http.(*persistConn).writeLoop() /usr/lib/go/src/net/http/transport.go:2343 +0x349
Goroutine 23 (running) created at: net/http.(*Server).Serve() /usr/lib/go/src/net/http/server.go:2969 +0x5d3 net/http.Serve() /usr/lib/go/src/net/http/server.go:2498 +0xe4
Goroutine 39 (running) created at: net/http.(*Transport).dialConn() /usr/lib/go/src/net/http/transport.go:1709 +0xc30 net/http.(*Transport).dialConnFor() /usr/lib/go/src/net/http/transport.go:1421 +0x151 ================== ================== WARNING: DATA RACE Write at 0x00c000237000 by goroutine 23: runtime.slicestringcopy() /usr/lib/go/src/runtime/slice.go:281 +0x0 bufio.(*Writer).WriteString() /usr/lib/go/src/bufio/bufio.go:715 +0x289 net/http.writeStatusLine() /usr/lib/go/src/net/http/server.go:1506 +0x7a net/http.(*chunkWriter).writeHeader() /usr/lib/go/src/net/http/server.go:1476 +0xd77 net/http.(*chunkWriter).close() /usr/lib/go/src/net/http/server.go:402 +0x188 net/http.(*response).finishRequest() /usr/lib/go/src/net/http/server.go:1622 +0xc9 net/http.(*conn).serve() /usr/lib/go/src/net/http/server.go:1930 +0x8a4
Previous write at 0x00c000237000 by goroutine 39: runtime.slicestringcopy() /usr/lib/go/src/runtime/slice.go:281 +0x0 bufio.(*Writer).WriteString() /usr/lib/go/src/bufio/bufio.go:715 +0x289 net/http.(*expectContinueReader).Read() /usr/lib/go/src/net/http/server.go:904 +0x28b io.(*LimitedReader).Read() /usr/lib/go/src/io/io.go:455 +0xc7 io.copyBuffer() /usr/lib/go/src/io/io.go:409 +0x14b io.Copy() /usr/lib/go/src/io/io.go:368 +0xb0 net.genericReadFrom() /usr/lib/go/src/net/net.go:643 +0x32 net.(*TCPConn).readFrom() /usr/lib/go/src/net/tcpsock_posix.go:54 +0x17c net.(*TCPConn).ReadFrom() /usr/lib/go/src/net/tcpsock.go:103 +0x79 io.copyBuffer() /usr/lib/go/src/io/io.go:395 +0x3fe io.Copy() /usr/lib/go/src/io/io.go:368 +0xb5 net/http.persistConnWriter.ReadFrom() /usr/lib/go/src/net/http/transport.go:1733 +0x32 bufio.(*Writer).ReadFrom() /usr/lib/go/src/bufio/bufio.go:730 +0x554 io.copyBuffer() /usr/lib/go/src/io/io.go:395 +0x3fe io.Copy() /usr/lib/go/src/io/io.go:368 +0x78 net/http.(*transferWriter).doBodyCopy() /usr/lib/go/src/net/http/transfer.go:400 +0x2f net/http.(*transferWriter).writeBody() /usr/lib/go/src/net/http/transfer.go:359 +0xc31 net/http.(*Request).write() /usr/lib/go/src/net/http/request.go:682 +0x887 net/http.(*persistConn).writeLoop() /usr/lib/go/src/net/http/transport.go:2343 +0x349
Goroutine 23 (running) created at: net/http.(*Server).Serve() /usr/lib/go/src/net/http/server.go:2969 +0x5d3 net/http.Serve() /usr/lib/go/src/net/http/server.go:2498 +0xe4
Goroutine 39 (running) created at: net/http.(*Transport).dialConn() /usr/lib/go/src/net/http/transport.go:1709 +0xc30 net/http.(*Transport).dialConnFor() /usr/lib/go/src/net/http/transport.go:1421 +0x151 ==================
@bcmills
Copy link
Member

@bcmills bcmills commented Jan 19, 2021

Duplicate of #34902

@bcmills bcmills marked this as a duplicate of #34902 Jan 19, 2021
@bcmills bcmills closed this Jan 19, 2021
@bcmills bcmills reopened this Jan 19, 2021
@bcmills
Copy link
Member

@bcmills bcmills commented Jan 19, 2021

Well, hrm. The same data race was reported on #34902 (in #34902 (comment)), but your report here is for go1.15.6 which should have included the fix.

@bcmills
Copy link
Member

@bcmills bcmills commented Jan 19, 2021

CC @katiehockman @FiloSottile @rolandshoemaker (via CL 242598, which was intended to fix #34902)

@bcmills bcmills added this to the Backlog milestone Jan 19, 2021
@gozssky
Copy link
Author

@gozssky gozssky commented Jan 19, 2021

Well, hrm. The same data race was reported on #34902 (in #34902 (comment)), but your report here is for go1.15.6 which should have included the fix.

That fix doesn't work for this issue. The root cause is probably the concurrent writes to the same connection in ReverseProxy.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
2 participants