search

golang / go

The Go programming language
https://go.dev
BSD 3-Clause "New" or "Revised" License
123.65k stars 17.61k forks source link

x/net/http2: GOAWAY or reset by peer while read response body #47083

Closed yushni closed 2 years ago

yushni commented 3 years ago

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

1.16.4

$ go version

Does this issue reproduce with the latest release?

yes

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

linux, amd64

go env Output
$ go env

What did you do?

Do many calls to the server, and in one of the messages i receive 200 OK status, read some part of body and then get a GOAWAY or read: reset by peer error.

[2021-07-07 10:50:40.677] TRACE HTTPREQUEST: &{Method:GET URL:{CUT} Proto:HTTP/1.1 ProtoMajor:1 ProtoMinor:1 Header:map[Accept:[application/json] Appkey:[] Authorization:[Bearer {ELIDED}] Cli-Version:[2] Slb-Data-Partition-Id:[slb-osdu-dev-sis-internal-hq]] Body:{Reader:0xc0003baea0} GetBody:<nil> ContentLength:0 TransferEncoding:[] Close:false Host:evq-digital-re.managed-osdu.cloud.slb-ds.com Form:map[] PostForm:map[] MultipartForm:<nil> Trailer:map[] RemoteAddr: RequestURI: TLS:<nil> Cancel:0xc00098e480 Response:<nil> ctx:0xc0006abf20}

2021/07/07 10:50:40 http2: Transport encoding header ":method" = "GET"
2021/07/07 10:50:40 http2: Transport encoding header ":path" = "/CUT"
2021/07/07 10:50:40 http2: Transport encoding header ":scheme" = "https"
2021/07/07 10:50:40 http2: Transport encoding header "accept" = "application/json"
2021/07/07 10:50:40 http2: Transport encoding header "accept-encoding" = "gzip"
2021/07/07 10:50:40 http2: Transport encoding header "user-agent" = "Go-http-client/2.0"
2021/07/07 10:50:40 http2: Framer 0xc000596620: wrote HEADERS flags=END_HEADERS stream=9 len=11
2021/07/07 10:50:40 http2: Framer 0xc000596620: wrote DATA flags=END_STREAM stream=9 len=0 data=""
2021/07/07 10:50:40 http2: Framer 0xc000596620: read WINDOW_UPDATE stream=9 len=4 incr=2147418111
2021/07/07 10:50:40 http2: Transport received WINDOW_UPDATE stream=9 len=4 incr=2147418111
2021/07/07 10:50:40 http2: Framer 0xc000596620: read GOAWAY len=8 LastStreamID=9 ErrCode=NO_ERROR Debug=""
2021/07/07 10:50:40 http2: Transport received GOAWAY len=8 LastStreamID=9 ErrCode=NO_ERROR Debug=""
2021/07/07 10:50:40 http2: Framer 0xc000596620: read HEADERS flags=END_HEADERS stream=9 len=300
2021/07/07 10:50:40 http2: decoded hpack field header field ":status" = "200"
2021/07/07 10:50:40 http2: decoded hpack field header field "date" = "Wed, 07 Jul 2021 10:50:40 GMT"
2021/07/07 10:50:40 http2: decoded hpack field header field "content-type" = "application/json"
2021/07/07 10:50:40 http2: decoded hpack field header field "access-control-allow-methods" = "OPTIONS, GET, POST, PUT, PATCH, DELETE"
2021/07/07 10:50:40 http2: decoded hpack field header field "cache-control" = "no-cache, no-store, must-revalidate"
2021/07/07 10:50:40 http2: decoded hpack field header field "content-security-policy" = "default-src 'none'"
2021/07/07 10:50:40 http2: decoded hpack field header field "expires" = "0"
2021/07/07 10:50:40 http2: decoded hpack field header field "pragma" = "no-cache"
2021/07/07 10:50:40 http2: decoded hpack field header field "strict-transport-security" = "max-age=15724800; includeSubDomains"
2021/07/07 10:50:40 http2: decoded hpack field header field "x-content-type-options" = "nosniff"
2021/07/07 10:50:40 http2: decoded hpack field header field "x-frame-options" = "deny"
2021/07/07 10:50:40 http2: decoded hpack field header field "x-xss-protection" = "1; mode=block"
2021/07/07 10:50:40 http2: Transport received HEADERS flags=END_HEADERS stream=9 len=300
2021/07/07 10:50:40 http2: Framer 0xc000596620: read DATA stream=9 len=4334 data="ath\":\"01fa09bc82s7t4qrxzyqns5seg/1/BOX_10_IX_1.S0155\"}},{\"data\":{\"type\":\"created\",\"path\":\"01fa09bc82s7t4qrxzyqns5seg/"}},{\"data\":{\"type\":\"created\",\"path\":\"01fa09bc82s7t4qrxzyqns5seg/"}},{\"data\":{\"type" (4078 bytes omitted)
2021/07/07 10:50:40 http2: Transport received DATA stream=9 len=4334 data="ath\":\"01fa09bc82s7t4qrxzyqns5seg/"}},{\"data\":{\"type\":\"created\",\"path\":\"01fa09bc82s7t4qrxzyqns5seg"}},{\"data\":{\"type\":\"created\",\"path\":\"01fa09bc82s7t4qrxzyqns5seg"}},{\"data\":{\"type" (4078 bytes omitted)

We will print response or not :)
2021/07/07 10:50:40 http2: Framer 0xc000596620: wrote WINDOW_UPDATE stream=9 len=4 incr=7680
2021/07/07 10:50:40 http2: Framer 0xc000596620: wrote WINDOW_UPDATE stream=9 len=4 incr=4846
2021/07/07 10:50:41 http2: Transport readFrame error on conn 0xc000602900: (*net.OpError) read tcp 10.132.0.28:50518->52.151.247.134:443: read: connection reset by peer
&{Status:200 OK StatusCode:200 Proto:HTTP/2.0 ProtoMajor:2 ProtoMinor:0 Header:map[Access-Control-Allow-Methods:[OPTIONS, GET, POST, PUT, PATCH, DELETE] Cache-Control:[no-cache, no-store, must-revalidate] Content-Security-Policy:[default-src 'none'] Content-Type:[application/json] Date:[Wed, 07 Jul 2021 10:50:40 GMT] Expires:[0] Pragma:[no-cache] Strict-Transport-Security:[max-age=15724800; includeSubDomains] X-Content-Type-Options:[nosniff] X-Frame-Options:[deny] X-Xss-Protection:[1; mode=block]] Body:0xc000415080 ContentLength:-1 TransferEncoding:[] Close:false Uncompressed:false Trailer:map[] Request:0xc000e7e800 TLS:0xc0005904d0}
failed to dump response
2021/07/07 10:50:41 http2: Framer 0xc000596620: wrote RST_STREAM stream=9 len=4 ErrCode=CANCEL
[2021-07-07 10:50:41.075] DEBUG  failed: http2: server sent GOAWAY and closed the connection; LastStreamID=9, ErrCode=NO_ERROR, debug="",  code 500
[2021-07-07 10:50:41.075] ERR0R failed .....`

What did you expect to see?

I expected to get an error

What did you see instead?

I see status 200, start read the body and only then see error

mknyszek commented 3 years ago

Are you able to share a small reproducer program to help us understand the issue?

As it stands, it's hard to say what's going wrong here.

CC @neild via https://dev.golang.org/owners

MakDon commented 3 years ago

Is there a possibility that you make too much request (or too frequently) so you are blocked by the server?

I've meet this problem when using http 1.1, and adding a http keep alive header solved my problem.

yushni commented 3 years ago

@MakDon, yes I do a huge amount of requests. As far as I know, http2 doesn't support the keep-alive header. Anyway, I set up the EnableKeepAlive on the server-side and set IdleConnTimeout to 0 (unlimited) client-side.

@mknyszek it is complicated, I don't have steps on how it is possible to reproduce locally. It happens only in one working environment

gopherbot commented 2 years ago

Timed out in state WaitingForInfo. Closing.

(I am just a bot, though. Please speak up if this is a mistake or you have the requested information.)