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

x/net/http2: high RAM usage after closing response bodies early with HTTP2 connections #20448

Closed
jacobsa opened this issue May 22, 2017 · 14 comments
Milestone

Comments

@jacobsa
Copy link
Contributor

jacobsa commented May 22, 2017

> go version
go version go1.8.1 darwin/amd64

The HTTP/2 client appears to use a large amount of memory when the user opens several serial requests to the same server, reading a small amount from each very large response body, and then closing the body.

This was discovered in GoogleCloudPlatform/gcsfuse#227. gcsfuse is a fuse file system for Google Cloud Storage. Because the file system doesn't know how much of the GCS object is going to be read, when it detects what appears to be a sequential read through a file handle, it opens an HTTP request to GCS for the entire object, consuming what the client reads sequentially and then cancelling the request by closing the response body. The user in that issue noticed that making 500 such request serially causes gcsfuse to use 2 GiB of memory, even after closing all response bodies and performing garbage collection.

While on an airplane without Wi-Fi I managed to reproduce this in a self-contained program. The program starts a server with a handler that returns 1 GiB of data. Then it repeatedly makes GET requests where the client reads 10 MiB and then closes the body. The client optionally sleeps between reads from the response body, simulating a reasonable bandwidth internet connection. Afterward the program dumps a memory profile.

You can run it like this, using a little utility I wrote to easily see peak memory usage:

> go get -u github.com/jacobsa/cputime
> go get -u golang.org/x/net/http2
> go run $GOROOT/src/crypto/tls/generate_cert.go --host=localhost
> cputime ./reproduce --slow_client=[true|false] --http2=[true|false]

Here are the max RSS results I get:

  • HTTP/1, fast client: 12.62 MiB
  • HTTP/1, slow client: 11.29 MiB
  • HTTP/2, fast client: 19.13 MiB
  • HTTP/2, slow client: 450.80 MiB (!!)

450 MiB is insane, given that only one request is in flight at a time. I see that http.http2transportDefaultStreamFlow is 4 MiB, so I would expect at most 8 MiB of buffer usage for send and receive buffers, plus a few megs of overhead from the program itself.

According to the memory profile, pretty much all of that 450 MiB is in the pipe buffer written to by the client read loop. Note that the high usage persists even if I call runtime.GC several times after making each request.

I don't think the client is doing anything against the rules according to the package documentation (but please correct me if I'm wrong). So memory usage this high seems like a bug.

(By the way, the bandwidth achieved when using HTTP/2 is also generally lower than HTTP/1, and is much more variable. Should I file an issue for the poor performance too?)

@odeke-em odeke-em changed the title net/http2: high RAM usage after closing response bodies early /x/net/http2: high RAM usage after closing response bodies early with HTTP2 connections May 22, 2017
@odeke-em
Copy link
Member

/cc HTTP folks @bradfitz @tombergan and then compiler+runtime squad @josharian @aclements

@josharian
Copy link
Contributor

josharian commented May 22, 2017

Possibly related: #19469, #18336.

@aclements
Copy link
Member

At a glance, it sounds like the pipe buffer might simply not have the back-pressure that it needs, so the client side of the connection is filling it up with much of the 1GB response even though only 10MB is being drained. I wouldn't guess that this is a compiler/runtime issue unless there's evidence that the HTTP/2 client implementation shouldn't be retaining that memory.

@tombergan
Copy link
Contributor

I haven't had a chance to try running reproduce.go, but I believe the problem is that we keep writing to cs.bufPipe after the response body is closed if the server has more data to send. Note that we never set cs.bufPipe.b to nil, and closing a response body fails future Reads but not future Writes. I bet this problem wouldn't exist if the request was canceled rather than closed (not that I suggest doing that, this is clearly a bug).

https://github.com/golang/net/blob/master/http2/transport.go#L1669
https://github.com/golang/net/blob/master/http2/transport.go#L1705

@gopherbot
Copy link

CL https://golang.org/cl/43810 mentions this issue.

@tombergan
Copy link
Contributor

Before https://golang.org/cl/43810:
HTTP/2 fast: 15MB
HTTP/2 slow: 150MB

After https://golang.org/cl/43810:
HTTP/2 fast: 12MB
HTTP/2 slow: 21MB

@bradfitz bradfitz changed the title /x/net/http2: high RAM usage after closing response bodies early with HTTP2 connections x/net/http2: high RAM usage after closing response bodies early with HTTP2 connections May 22, 2017
@bradfitz bradfitz added this to the Go1.9 milestone May 22, 2017
@tombergan
Copy link
Contributor

@jacobsa We have a partial fix (see above). However, note that each HTTP/2 connection has a 1GB flow-control window by default, and currently there isn't a knob to adjust this value.
https://github.com/golang/net/blob/master/http2/transport.go#L37

If the above fix is not good enough for you and you want a separate knob, could you file another bug? Thanks!

@gopherbot
Copy link

CL https://golang.org/cl/43853 mentions this issue.

gopherbot pushed a commit to golang/net that referenced this issue May 22, 2017
Updates golang/go#20448

Change-Id: I6366b0b0b36d81095ab347ca35e1e72169c05c15
Reviewed-on: https://go-review.googlesource.com/43853
Run-TryBot: Brad Fitzpatrick <bradfitz@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Tom Bergan <tombergan@google.com>
@jacobsa
Copy link
Contributor Author

jacobsa commented May 23, 2017

@tombergan: thanks. This is 4 MiB per stream by default though, right? I have thought in the past that it ought to be tunable (it seems way too high for low-latency/bandwidth connections, and too low for high-latency/bandwidth connections), but I've never had a good way to choose a value myself so never filed an issue. If I come up with something better, I will file.

@tombergan
Copy link
Contributor

That's right, 4MB per stream, so with enough concurrent streams, 1GB memory usage can be WAI.

gopherbot pushed a commit to golang/net that referenced this issue May 23, 2017
… closed

After a response body is closed, we keep writing to the bufPipe. This
accumulates bytes that will never be read, wasting memory. The fix is to
discard the buffer on pipe.BreakWithError.

Updates golang/go#20448

Change-Id: Ia2cf46cb8c401fd8091ef3785eb48fe7b188bb57
Reviewed-on: https://go-review.googlesource.com/43810
Run-TryBot: Tom Bergan <tombergan@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
@jacobsa
Copy link
Contributor Author

jacobsa commented May 23, 2017

@tombergan: question about golang/net@1a26cf0: are the existing contents of the pipe buffer also discarded when it is closed (rather than just the future data frames)? It's not clear to me from the CL description.

@tombergan
Copy link
Contributor

Yes, the existing contents of the pipe buffer are discarded when the response body is closed (see line 120 of pipe.go)

@jacobsa
Copy link
Contributor Author

jacobsa commented May 23, 2017

Thanks, I missed that. LGTM.

@gopherbot
Copy link

CL https://golang.org/cl/44006 mentions this issue.

c3mb0 pushed a commit to c3mb0/net that referenced this issue Apr 2, 2018
Updates golang/go#20448

Change-Id: I6366b0b0b36d81095ab347ca35e1e72169c05c15
Reviewed-on: https://go-review.googlesource.com/43853
Run-TryBot: Brad Fitzpatrick <bradfitz@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Tom Bergan <tombergan@google.com>
c3mb0 pushed a commit to c3mb0/net that referenced this issue Apr 2, 2018
… closed

After a response body is closed, we keep writing to the bufPipe. This
accumulates bytes that will never be read, wasting memory. The fix is to
discard the buffer on pipe.BreakWithError.

Updates golang/go#20448

Change-Id: Ia2cf46cb8c401fd8091ef3785eb48fe7b188bb57
Reviewed-on: https://go-review.googlesource.com/43810
Run-TryBot: Tom Bergan <tombergan@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
@golang golang locked and limited conversation to collaborators May 24, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

7 participants