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.

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

x/net/http2: timeouts not respected on malformed data frames #57851

Open
danslo opened this issue Jan 17, 2023 · 10 comments
Open

x/net/http2: timeouts not respected on malformed data frames #57851

danslo opened this issue Jan 17, 2023 · 10 comments
Assignees
@neild
Labels
NeedsFix The path to resolution is known, but the work has not been done.
Milestone
Unreleased

Comments

@danslo
Copy link

danslo commented Jan 17, 2023 •
edited

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

$ go version
go version go1.19.4 darwin/amd64

Does this issue reproduce with the latest release?

Yes.

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

Darwin / ARM64 / AMD64, but also reproduced on Linux / AMD64.

What did you do?

Run the following code with server that completes TLS handshake, but then just sends random raw data.
In other words, our client never receives frame with flags=END_STREAM.

func main() {
    ctx, cancel := context.WithTimeout(context.Background(), time.Duration(3*time.Second))
    defer cancel()
    cl := &http.Client{Timeout: 3 * time.Second}
    req, _ := http.NewRequestWithContext(ctx, "GET", os.Args[1], nil)
    cl.Do(req)
}

What did you expect to see?

After 3 seconds, the connection is aborted.

What did you see instead?

The connection hangs indefinitely.

Additional Context

We've seen this happen with Cloudflare in front of a non-http(s) backend.
In this case we assume it is wrongly configured to point at a SSH daemon.
Even in that case, we should not hang forever.

Running with GODEBUG=http2debug=2:

2023/01/17 19:17:30 http2: Transport failed to get client conn for <snip>:443: http2: no cached connection was available
2023/01/17 19:17:30 http2: Transport creating client conn 0xc0000a8180 to [<snip>]:443
2023/01/17 19:17:30 http2: Framer 0xc0000e0460: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2023/01/17 19:17:30 http2: Framer 0xc0000e0460: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2023/01/17 19:17:30 http2: Transport encoding header ":authority" = "<snip>"
2023/01/17 19:17:30 http2: Transport encoding header ":method" = "GET"
2023/01/17 19:17:30 http2: Transport encoding header ":path" = "/"
2023/01/17 19:17:30 http2: Transport encoding header ":scheme" = "https"
2023/01/17 19:17:30 http2: Transport encoding header "accept-encoding" = "gzip"
2023/01/17 19:17:30 http2: Transport encoding header "user-agent" = "Go-http-client/2.0"
2023/01/17 19:17:30 http2: Framer 0xc0000e0460: wrote HEADERS flags=END_STREAM|END_HEADERS stream=1 len=39
2023/01/17 19:17:30 http2: Framer 0xc0000e0460: read SETTINGS len=18, settings: MAX_CONCURRENT_STREAMS=256, INITIAL_WINDOW_SIZE=65536, MAX_FRAME_SIZE=16777215
2023/01/17 19:17:30 http2: Transport received SETTINGS len=18, settings: MAX_CONCURRENT_STREAMS=256, INITIAL_WINDOW_SIZE=65536, MAX_FRAME_SIZE=16777215
2023/01/17 19:17:30 http2: Framer 0xc0000e0460: wrote SETTINGS flags=ACK len=0
2023/01/17 19:17:30 http2: Framer 0xc0000e0460: read WINDOW_UPDATE len=4 (conn) incr=2147418112
2023/01/17 19:17:30 http2: Transport received WINDOW_UPDATE len=4 (conn) incr=2147418112
2023/01/17 19:17:30 http2: Framer 0xc0000e0460: read SETTINGS flags=ACK len=0
2023/01/17 19:17:30 http2: Transport received SETTINGS flags=ACK len=0
2023/01/17 19:17:30 http2: Framer 0xc0000e0460: read HEADERS flags=END_HEADERS stream=1 len=417
2023/01/17 19:17:30 http2: decoded hpack field header field ":status" = "101"
2023/01/17 19:17:30 http2: decoded hpack field header field "date" = "Tue, 17 Jan 2023 18:17:31 GMT"
2023/01/17 19:17:30 http2: decoded hpack field header field "cf-cache-status" = "DYNAMIC"
2023/01/17 19:17:30 http2: decoded hpack field header field "report-to" = "{\"endpoints\":[{\"url\":\"https:\\/\\/a.nel.cloudflare.com\\/report\\/v3?s=<snip>\"}],\"group\":\"cf-nel\",\"max_age\":604800}"
2023/01/17 19:17:30 http2: decoded hpack field header field "nel" = "{\"success_fraction\":0,\"report_to\":\"cf-nel\",\"max_age\":604800}"
2023/01/17 19:17:30 http2: decoded hpack field header field "server" = "cloudflare"
2023/01/17 19:17:30 http2: decoded hpack field header field "cf-ray" = "78b116903a38731a-LHR"
2023/01/17 19:17:30 http2: decoded hpack field header field "alt-svc" = "h3=\":443\"; ma=86400, h3-29=\":443\"; ma=86400"
2023/01/17 19:17:30 http2: Transport received HEADERS flags=END_HEADERS stream=1 len=417
2023/01/17 19:17:30 http2: Framer 0xc0000e0460: read DATA stream=1 len=41 data="SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.5\r\n"
2023/01/17 19:17:30 http2: Transport received DATA stream=1 len=41 data="SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.5\r\n"

x/net/http2 also provides a ReadIdleTimeout and PingTimeout. According to the docs:

ReadIdleTimeout is the timeout after which a health check using ping frame will be carried out if no frame is received on the connection.

PingTimeout is the timeout after which the connection will be closed if a response to Ping is not received.

So the following was tried:

func main() {
    t2 := &http2.Transport{
        ReadIdleTimeout: 3 * time.Second,
        PingTimeout:     1 * time.Second,
    }
    cl := &http.Client{Transport: t2}
    req, _ := http.NewRequest("GET", os.Args[1], nil)
    cl.Do(req)
}

This still hangs indefinitely.
@cherrymui cherrymui added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jan 18, 2023
@cherrymui cherrymui added this to the Unreleased milestone Jan 18, 2023
@cherrymui
Copy link
Member

cc @neild @tombergan

@danslo
Copy link
Author

danslo commented Jan 18, 2023 •
edited

FWIW the URL in question is https://enablewebdesign.com - let me know if you need any other information or a more local way to reproduce..

curl exits immediately:

$ curl --http2 https://enablewebdesign.com 
curl: (92) HTTP/2 stream 0 was not closed cleanly: PROTOCOL_ERROR (err 1)

@gwillem
Copy link

gwillem commented Jan 18, 2023 •
edited

Verified with go 1.19.5 @ darwin/arm64. For the record, this issue effectively creates a DoS, since there is (afaik?) no other way to enforce a timeout.

@fraenkel
Copy link
Contributor

here is the crux of the issue, a panic

golang.org/x/net/http2.(*ClientConn).readLoop.func1()
	/home/go/src/golang.org/x/net/http2/transport.go:2118 +0x26 fp=0xc000157b48 sp=0xc000157b30 pc=0x7016c6
runtime.deferCallSave(0xc000157c18, 0xc000157fa0?)
	/usr/local/go/src/runtime/panic.go:796 +0x88 fp=0xc000157b58 sp=0xc000157b48 pc=0x4386e8
runtime.runOpenDeferFrame(0xc0004493b0?, 0xc000449360)
	/usr/local/go/src/runtime/panic.go:769 +0x1a5 fp=0xc000157ba0 sp=0xc000157b58 pc=0x438505
panic({0x7dd3a0, 0xb44700})
	/usr/local/go/src/runtime/panic.go:884 +0x212 fp=0xc000157c60 sp=0xc000157ba0 pc=0x438952
runtime.panicmem(...)
	/usr/local/go/src/runtime/panic.go:260
runtime.sigpanic()
	/usr/local/go/src/runtime/signal_unix.go:835 +0x2f6 fp=0xc000157cb0 sp=0xc000157c60 pc=0x44f576
golang.org/x/net/http2.(*pipe).Write(0xc000157d60?, {0xc0001aa1a0?, 0x180?, 0x75?})
	/home/go/src/golang.org/x/net/http2/pipe.go:98 +0x17b fp=0xc000157d38 sp=0xc000157cb0 pc=0x6e6d7b
golang.org/x/net/http2.(*clientConnReadLoop).processData(0xc000157f98, 0xc00007eae0)
	/home/go/src/golang.org/x/net/http2/transport.go:2669 +0x225 fp=0xc000157e00 sp=0xc000157d38 pc=0x704ac5
golang.org/x/net/http2.(*clientConnReadLoop).run(0xc000157f98)
	/home/go/src/golang.org/x/net/http2/transport.go:2258 +0x6e5 fp=0xc000157f60 sp=0xc000157e00 pc=0x702625
golang.org/x/net/http2.(*ClientConn).readLoop(0xc0001b0180)
	/home/go/src/golang.org/x/net/http2/transport.go:2119 +0x6f fp=0xc000157fc8 sp=0xc000157f60 pc=0x70158f
golang.org/x/net/http2.(*Transport).newClientConn.func1()
	/home/go/src/golang.org/x/net/http2/transport.go:817 +0x26 fp=0xc000157fe0 sp=0xc000157fc8 pc=0x6fa566
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1594 +0x1 fp=0xc000157fe8 sp=0xc000157fe0 pc=0x46bde1
created by golang.org/x/net/http2.(*Transport).newClientConn
	/home/go/src/golang.org/x/net/http2/transport.go:817 +0xc5c

@fraenkel
Copy link
Contributor

The actual issue is failing to treat a 101 response as a PROTOCOL_ERROR.

@gopherbot
Copy link

Change https://go.dev/cl/463095 mentions this issue: http2: reject 101 status code

@gopherbot
Copy link

Change https://go.dev/cl/463497 mentions this issue: http2: reject DATA frames read before headers are finished

@neild
Copy link
Contributor

neild commented Jan 26, 2023

I don't think the handling of 101 responses is the problem; we'd encounter the same issue if the server had sent a 102 instead. The issue is that we're trying to process a DATA frame (or what looks like one) before the final headers have been read., which causes an internal panic. The panic is then obscured by a deferred cleanup function that gets stuck waiting on a mutex that was locked when the panic happened.

@neild neild self-assigned this Jan 26, 2023
@neild neild added NeedsFix The path to resolution is known, but the work has not been done. and removed NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Jan 26, 2023
@fraenkel
Copy link
Contributor

Doesn't your fix handle #43965 as well?

@neild
Copy link
Contributor

neild commented Jan 26, 2023

Yes, #43965 looks to be the same thing. And you have a fix for that one in CL https://go.dev/cl/330415 (exact same change as my CL, heh) which seems to have fallen through the Gerrit cracks somehow.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@neild neild

Labels
NeedsFix The path to resolution is known, but the work has not been done.
Projects
None yet
Milestone
Unreleased
Development

No branches or pull requests
6 participants
@neild @danslo @fraenkel @gwillem @gopherbot @cherrymui