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

Jump to bottom

x/net/http2: Transport loops forever if peer sends a graceful shutdown upon connect forever #31405

Closed
marianrh opened this issue Apr 11, 2019 · 4 comments
Closed

x/net/http2: Transport loops forever if peer sends a graceful shutdown upon connect forever #31405

marianrh opened this issue Apr 11, 2019 · 4 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.

Comments

@marianrh
Copy link

marianrh commented Apr 11, 2019 •
edited

What did you do?

Running the program below causes http.Get() to loop. It seems to establish an infinite number of connections to the target server and only stops when some system or network limit is reached.
The URL in question can be accessed without problems in browsers and using curl or wget.

package main

import (
	"log"
	"net/http"
)

func main() {
	_, err := http.Get("https://www.herold.at/")
	if err != nil {
		log.Fatal("doing request:", err)
	}

	log.Print("request done")
}

What did you expect to see?

I expected the request to finish without error and request done to be printed.

What did you see instead?

http.Get() never returns. A quickly rising number of established connections to the target server is seen via ss. After a few seconds, hundreds of connections are established:

$ ss -tarp | grep -c "ESTAB .* www\.herold\.at"
322

Does this issue reproduce with the latest release (go1.12.3)?

Yes

System details

The problem was reproduced on various systems, all on x64 architecture:

  • go1.11.5 on RHEL 7.6
  • go1.10.4 on Ubuntu 18.04
  • go1.10.4 on Ubuntu 19.04 Beta
  • go1.12.3 on Ubuntu 18.04
@agnivade
Copy link
Contributor

agnivade commented Apr 11, 2019 •
edited

Happens when the http2 client code path is taken.

GODEBUG=http2client=0 go run arr.go
2019/04/11 14:05:06 request done

Debug logs -

GODEBUG=http2debug=2 go run arr.go
2019/04/11 14:05:21 http2: Transport failed to get client conn for www.herold.at:443: http2: no cached connection was available
2019/04/11 14:05:22 http2: Transport creating client conn 0xc000152780 to 194.146.186.138:443
2019/04/11 14:05:22 http2: Framer 0xc0001b3dc0: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2019/04/11 14:05:22 http2: Framer 0xc0001b3dc0: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2019/04/11 14:05:22 http2: Transport encoding header ":authority" = "www.herold.at"
2019/04/11 14:05:22 http2: Transport encoding header ":method" = "GET"
2019/04/11 14:05:22 http2: Transport encoding header ":path" = "/"
2019/04/11 14:05:22 http2: Transport encoding header ":scheme" = "https"
2019/04/11 14:05:22 http2: Transport encoding header "accept-encoding" = "gzip"
2019/04/11 14:05:22 http2: Transport encoding header "user-agent" = "Go-http-client/2.0"
2019/04/11 14:05:22 http2: Framer 0xc0001b3dc0: wrote HEADERS flags=END_STREAM|END_HEADERS stream=1 len=35
2019/04/11 14:05:22 http2: Framer 0xc0001b3dc0: read SETTINGS len=18, settings: MAX_CONCURRENT_STREAMS=10, INITIAL_WINDOW_SIZE=32768, MAX_HEADER_LIST_SIZE=32768
2019/04/11 14:05:22 http2: Transport received SETTINGS len=18, settings: MAX_CONCURRENT_STREAMS=10, INITIAL_WINDOW_SIZE=32768, MAX_HEADER_LIST_SIZE=32768
2019/04/11 14:05:22 http2: Framer 0xc0001b3dc0: wrote SETTINGS flags=ACK len=0
2019/04/11 14:05:22 http2: Framer 0xc0001b3dc0: read GOAWAY len=8 LastStreamID=0 ErrCode=NO_ERROR Debug=""
2019/04/11 14:05:22 http2: Transport received GOAWAY len=8 LastStreamID=0 ErrCode=NO_ERROR Debug=""
2019/04/11 14:05:22 http2: Transport failed to get client conn for www.herold.at:443: http2: no cached connection was available
2019/04/11 14:05:23 http2: Transport creating client conn 0xc00032a180 to 194.146.186.138:443
2019/04/11 14:05:23 http2: Framer 0xc0002e08c0: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2019/04/11 14:05:23 http2: Framer 0xc0002e08c0: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2019/04/11 14:05:23 http2: Transport encoding header ":authority" = "www.herold.at"
2019/04/11 14:05:23 http2: Transport encoding header ":method" = "GET"
2019/04/11 14:05:23 http2: Framer 0xc0002e08c0: read SETTINGS len=18, settings: MAX_CONCURRENT_STREAMS=10, INITIAL_WINDOW_SIZE=32768, MAX_HEADER_LIST_SIZE=32768
2019/04/11 14:05:23 http2: Transport received SETTINGS len=18, settings: MAX_CONCURRENT_STREAMS=10, INITIAL_WINDOW_SIZE=32768, MAX_HEADER_LIST_SIZE=32768
2019/04/11 14:05:23 http2: Transport encoding header ":path" = "/"
2019/04/11 14:05:23 http2: Transport encoding header ":scheme" = "https"
2019/04/11 14:05:23 http2: Transport encoding header "accept-encoding" = "gzip"
2019/04/11 14:05:23 http2: Transport encoding header "user-agent" = "Go-http-client/2.0"
2019/04/11 14:05:23 http2: Framer 0xc0002e08c0: wrote HEADERS flags=END_STREAM|END_HEADERS stream=1 len=35
2019/04/11 14:05:23 http2: Framer 0xc0002e08c0: wrote SETTINGS flags=ACK len=0
2019/04/11 14:05:23 http2: Framer 0xc0002e08c0: read GOAWAY len=8 LastStreamID=0 ErrCode=NO_ERROR Debug=""
2019/04/11 14:05:23 http2: Transport received GOAWAY len=8 LastStreamID=0 ErrCode=NO_ERROR Debug=""
2019/04/11 14:05:23 http2: Transport failed to get client conn for www.herold.at:443: http2: no cached connection was available

And then it repeats itself till the http2: no cached connection was available error.

EDIT: This is the code I used -

package main

import (
	"io"
	"io/ioutil"
	"log"
	"net/http"
)

func main() {
	res, err := http.Get("https://www.herold.at/")
	if err != nil {
		log.Fatal("doing request:", err)
	}
	defer res.Body.Close()
	io.Copy(ioutil.Discard, res.Body)

	log.Print("request done")
}

@bradfitz @fraenkel @tombergan

@agnivade agnivade changed the title net/http: request to certain server causes client to open infinite number of connections x/net/http2: no cached connection was available Apr 11, 2019
@agnivade agnivade added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Apr 11, 2019
@bradfitz
Copy link
Contributor

Thanks @agnivade for the trace.

That server looks buggy or confused.

On every request it starts a graceful shutdown and says GOAWAY (NO_ERROR), so we retry our request, per the spec.

What server software is that? It seems bogus.

I think we already have another open bug for falling back to HTTP/1 when we notice that an HTTP/2 server is buggy. Maybe somebody could find that bug. But in general, it's better for the ecosystem if we work with the other server software's author(s) and get them to fix it.

@bradfitz bradfitz changed the title x/net/http2: no cached connection was available x/net/http2: Transport loops forever if Server does a graceful shutdown upon connect forever Apr 11, 2019
@bradfitz bradfitz changed the title x/net/http2: Transport loops forever if Server does a graceful shutdown upon connect forever x/net/http2: Transport loops forever if peer sends a graceful shutdown upon connect forever Apr 11, 2019
@bradfitz
Copy link
Contributor

Oh, it's a Big-IP:

Server: BigIP

We've had problems with Big-IP's HTTP/2 implementation in the past. It's possible it's already fixed but that customer hasn't updated to the latest code.

@marianrh
Copy link
Author

I tested this again (using Go 1.15.7), and the GET request returns correctly now. It seems that either something was changed in Go or the server was fixed. I'm closing this.

@golang golang locked and limited conversation to collaborators Jun 21, 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
4 participants
@bradfitz @agnivade @gopherbot @marianrh