net/http: http2 close request body and read it again

[timandy]

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

$ go version
go version go1.18 linux/amd64

Does this issue reproduce with the latest release?

not try

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

go env Output

$ go env

GO111MODULE=""
GOARCH="amd64"
GOBIN="/home/gopath/bin"
GOCACHE="/root/.cache/go-build"
GOENV="/root/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/gopath/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/gopath"
GOPRIVATE=""
GOPROXY="https://goproxy.cn,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.18"
GCCGO="gccgo"
GOAMD64="v1"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/dev/null"
GOWORK=""
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-build112645457=/tmp/go-build -gno-record-gcc-switches"

What did you do?

func (r *DispatchRequestReader) Read(buff []byte) (n int, err error) {
	if r.prevCloseStack != nil {
		logger.Error(string(r.prevCloseStack))
	}
	if r.compositeReader == nil {
		r.compositeReader = io.MultiReader(r.buffer.ToReader(), bytes.NewReader(r.remain), r.ReadCloser)
	}
	return r.compositeReader.Read(buff)
}

func (r *DispatchRequestReader) Close() error {
	r.prevCloseStack = debug.Stack()
	r.buffer = nil
	r.remain = nil
	r.compositeReader = nil
	r.content = ""
	return r.ReadCloser.Close()
}

17:42:21.950 [] [1884] [] [] ERROR core-frame/servlet/DispatchRequestReader.go:75 goroutine 73 [running]:
runtime/debug.Stack()
	/usr/local/go/src/runtime/debug/stack.go:24 +0x65
wohui-service/core-frame/servlet.(*DispatchRequestReader).Close(0xc00025c540)
	/home/dulwich/wohui-mock-source/core-frame/servlet/DispatchRequestReader.go:85 +0x25
net/http.(*readTrackingBody).Close(0x0?)
	/usr/local/go/src/net/http/transport.go:642 +0x25
net/http.(*http2clientStream).abortStreamLocked(0xc00114c600, {0x16d2ee0?, 0xc000666db0?})
	/usr/local/go/src/net/http/h2_bundle.go:7093 +0xa4
net/http.(*http2clientStream).abortStream(0x12a5700?, {0x16d2ee0?, 0xc000666db0?})
	/usr/local/go/src/net/http/h2_bundle.go:7084 +0xac
net/http.(*http2clientConnReadLoop).processResetStream(0xc0005e1f98, 0xc001406a80)
	/usr/local/go/src/net/http/h2_bundle.go:9482 +0x1a5
net/http.(*http2clientConnReadLoop).run(0xc0005e1f98)
	/usr/local/go/src/net/http/h2_bundle.go:8853 +0x425
net/http.(*http2ClientConn).readLoop(0xc0001c9200)
	/usr/local/go/src/net/http/h2_bundle.go:8711 +0x6f
created by net/http.(*http2Transport).newClientConn
	/usr/local/go/src/net/http/h2_bundle.go:7439 +0xa65

panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0x9a379c]

goroutine 1884 [running]:
wohui-service/core/trace/config.(*HeapBuffer).ToReader(...)
	/home/dulwich/wohui-mock-source/core/trace/config/HeapBuffer.go:67
wohui-service/core-frame/servlet.(*DispatchRequestReader).Read(0xc00025c540, {0xc000980000, 0x80000, 0x80000})
	/home/dulwich/wohui-mock-source/core-frame/servlet/DispatchRequestReader.go:78 +0xbc
net/http.(*readTrackingBody).Read(0xc00019f7a0?, {0xc000980000?, 0x80000?, 0x80000?})
	/usr/local/go/src/net/http/transport.go:637 +0x2a
net/http.(*http2clientStream).writeRequestBody(0xc00114c600, 0xc0010eac00)
	/usr/local/go/src/net/http/h2_bundle.go:8276 +0x3f9
net/http.(*http2clientStream).writeRequest(0xc00114c600, 0xc0010eac00)
	/usr/local/go/src/net/http/h2_bundle.go:8013 +0x74e
net/http.(*http2clientStream).doRequest(0x0?, 0x0?)
	/usr/local/go/src/net/http/h2_bundle.go:7899 +0x1e
created by net/http.(*http2ClientConn).RoundTrip
	/usr/local/go/src/net/http/h2_bundle.go:7828 +0x30a

This situation only occurs with a small probability when a large number of requests are made quickly, and it may occur even if there are no concurrent requests.

What did you expect to see?

newClientConn close the request body, but .(*http2ClientConn).RoundTrip read the request body again.

What did you see instead?

do not close the request body if need read it again.

[mknyszek]

CC @neild

[mknyszek]

Go 1.18 is not a supported version of Go. Does this reproduce with newer releases?

[neild]

The Request.Body documentation states:

 	// Body must allow Read to be called concurrently with Close.
	// In particular, calling Close should unblock a Read waiting
	// for input.

The Transport can interrupt a blocked Read from the request body by closing the body. The natural unreliability of ordering of concurrent operations means that this Close can happen before, after, or during the Read.

[timandy]

@neild Thanks for your answer. Does it mean that once Close function is called, the data returned by the Read function will not be written to the request? In other words, the Read function can return (0,EOF) or (0, OtherError) or Normal Read or something else?

[neild]

Any data returned by Read might be written to the response (although it probably won't be), but it's fine for Read to return an error and no data after the request body has been closed.

That is, if Read returns a non-zero number of bytes and an error, I wouldn't count on those bytes not being written to the response. If Read returns io.EOF, it should only do so if all data has been read.

[timandy]

Any data returned by Read might be written to the response (although it probably won't be), but it's fine for Read to return an error and no data after the request body has been closed.

That is, if Read returns a non-zero number of bytes and an error, I wouldn't count on those bytes not being written to the response. If Read returns io.EOF, it should only do so if all data has been read.

The explanation was very clear, thanks a lot.