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

net/http: connection reuse does not work happily with normal use of json package #20528

Open
jvshahid opened this Issue May 30, 2017 · 23 comments

Comments

Projects
None yet
9 participants
@jvshahid
Contributor

jvshahid commented May 30, 2017

Please answer these questions before submitting your issue. Thanks!

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

go 1.8.1

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

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"

What did you do?

Used json.NewDecoder(resp.Body) to read the body of an http response. The http request was using TLS. This is a playground app demonstrating the issue

What did you expect to see?

I expected the tls connection reused on subsequent requests

What did you see instead?

The tls connection is discarded and a new connection is opened for every request

I also started a thread on the mailing list

@ianlancetaylor ianlancetaylor changed the title from json.NewDecoder(resp.Body) would not close the response body to encoding/json: NewDecoder(resp.Body) would not close the response body Jun 16, 2017

@ianlancetaylor

This comment has been minimized.

Contributor

ianlancetaylor commented Jun 16, 2017

I don't see anything to fix here. You're right: json.Decoder does not call the Close method on its argument. But I don't see any reason to expect it to do so. And I don't see any special difficulty in calling Close when you are done with the Decoder.

What is there to fix here?

@dcheney-atlassian

This comment has been minimized.

dcheney-atlassian commented Jun 16, 2017

Additionally, if json.Decoder closed its reader that would make it impossible to use it for streaming http responses that include multiple json documents in a single http body.

@jvshahid

This comment has been minimized.

Contributor

jvshahid commented Jun 16, 2017

@ianlancetaylor & @dcheney-atlassian this isn't about calling Close on the response body. In fact the sample app on playground closes the body in a defer. This issue is trying to address connection reuse when a chunk reader is being used. Even when Close is called, TLS connections aren't being re-used for subsequent requests since response body isn't fully drained (as explained in the issue and the golang mailing list)

This has previously been an interesting use case for the golang team, e.g. see google/go-github#317 and the fix that was pushed by @bradfitz to fix it. As a result, I was expecting to see the golang team interested in fixing this issue as well, but may be that's not the case.

Furthermore, a quick search on github shows that lot of other golang developers are expecting this pattern to work without having to drain the response body. After careful examination of the search results, it seems some developers have ran into this issue and are manually draining the response body .

@bradfitz bradfitz changed the title from encoding/json: NewDecoder(resp.Body) would not close the response body to net/http: connection reuse does not work happily with normal use of json package Jun 16, 2017

@bradfitz bradfitz self-assigned this Jun 16, 2017

@bradfitz bradfitz added this to the Go1.9 milestone Jun 16, 2017

@bradfitz

This comment has been minimized.

Member

bradfitz commented Jun 16, 2017

Something weird is going on here.

The code & tests try hard already to make this work. I'm pretty sure this used to work.

This might not be fixable for Go 1.9, but I want to understand it before the end of the day (I'm close), and then I'll decide what to do about it.

It looks like an (non-zero, EOF) Read is getting lost somewhere and turning into a (non-zero, nil), tripping up the connection reuse.

@jvshahid

This comment has been minimized.

Contributor

jvshahid commented Jun 16, 2017

It's been a while since I investigated this issue. If I remember correctly a bisect pointed at the fix for #17355 as the first commit to cause the behavior explained in this issue. I think my investigation lead me to believe that it's the tls reader that is causing the issue. It consistently returns the last chunk (the zero bytes chunk) to the chunk reader separately, but I'm not sure why. I tried different payload sizes and the tls reader always returns the last chunk on a separate read. This combined with the fact that the chunk reader doesn't aggressively try to reach EOF is causing this behavior.

@bradfitz

This comment has been minimized.

Member

bradfitz commented Jun 16, 2017

@jvshahid, yup, that's the code I'm re-reading now.

@bradfitz

This comment has been minimized.

Member

bradfitz commented Jun 16, 2017

Slight tangent, or possibly related, I learned while researching this code that json.NewEncoder adds a newline that Marshal doesn't:

https://play.golang.org/p/z9W7ihjlk3

Endoder: "{\"key0\":\"value0\",\"key1\":\"value1\"}\n"
Marshal: "{\"key0\":\"value0\",\"key1\":\"value1\"}"
@jvshahid

This comment has been minimized.

Contributor

jvshahid commented Jun 16, 2017

i modified the app i pasted before to use Marshal instead of NewEncoder().Encode and I'm still seeing the issue. This is the modified app https://play.golang.org/p/FypHvYF-q5

@bradfitz

This comment has been minimized.

Member

bradfitz commented Jun 16, 2017

Yeah, I've been hacking up a dozen variants of it with a bunch of additional logging throughout net/http/*.

@bradfitz

This comment has been minimized.

Member

bradfitz commented Jun 17, 2017

Okay, here's what's happening:

The client side is working as intended after the change for #17355. If it had seen an EOF from read or a 0-byte http/1.1 EOF chunking marker in its buffer, it would've used it. But it never sees one:

The http server buffers the output from Handlers up until a certain size, both to minimize to the number of writes on the wire, and to add a Content-Length header for small-ish writes.

The writes are pretty big here, though. At 412 elements (which works), it's doing a 8042 byte write (pre-chunking+TLS overhead), and at 413 elements (which fails), it's doing a 8062 byte write.

Those are bigger than all the server's various buffers (the 2KB http.Handler buffer), and the conn's buffer. So those get written immediately, before your handler exits, so the server doesn't know that it's the final write, so it can't tack on the EOF chunk yet.

Right after the final big Write to the ResponseWriter from the json.NewEncoder(http.ResponseWriter).Encode(bigMap), the handler exits. This causes the Server to then do another write, to close the chunking layer, and send the final "0\r\n". But it's too late, because your client program has already decoded the object (it had everything it needed, pre-EOF), and closed the Response.Body. Because the Response.Body was closed before seeing an EOF, and because it was sent chunked instead of with a content-length, the client has no idea how much might remain, so it closes the connection just as the EOF chunk is arriving.

Note that all of this only happens with certain response sizes, and not even necessarily with all large responses. It just depends on things line up and get flushed out.

There are two possible fixes, possibly both:

  • in the absence of an explicit http.Flusher.Flush from the Handler, the Server could always hold on to a few buffered bytes, to prevent the client from getting everything in one packet. That would cause the final EOF packet on the wire to contain, say, the final "}\n" of the JSON object, as well as the 0\r\n EOF chunking marker.

  • the Transport could go back to its old behavior (with a better implementation) of waiting for a bit (50 ms?) for the EOF before throwing the connection away, reading at most a few bytes.

But neither of these are critical for Go 1.9, so moving to Go 1.10.

@bradfitz bradfitz modified the milestones: Go1.10, Go1.9 Jun 17, 2017

@bradfitz bradfitz removed their assignment Jun 17, 2017

@jvshahid

This comment has been minimized.

Contributor

jvshahid commented Jun 17, 2017

Thanks @bradfitz for looking into it

@dcheney-atlassian

This comment has been minimized.

dcheney-atlassian commented Jun 19, 2017

@Kinghack

This comment has been minimized.

Contributor

Kinghack commented Jun 23, 2017

if this one is not urgent, could I try this?

@bradfitz

This comment has been minimized.

Member

bradfitz commented Jun 23, 2017

No need to ask. You're permitted to try to fix any of our bugs. :-)

@gopherbot

This comment has been minimized.

gopherbot commented Aug 15, 2017

Change https://golang.org/cl/55613 mentions this issue: net/http: hold some data when data size is larger than connection buffer

@tombergan

This comment has been minimized.

Contributor

tombergan commented Aug 15, 2017

There are two possible fixes, possibly both:

  1. in the absence of an explicit http.Flusher.Flush from the Handler, the Server could always hold on to a few buffered bytes, to prevent the client from getting everything in one packet. That would cause the final EOF packet on the wire to contain, say, the final "}\n" of the JSON object, as well as the 0\r\n EOF chunking marker.

  2. the Transport could go back to its old behavior (with a better implementation) of waiting for a bit (50 ms?) for the EOF before throwing the connection away, reading at most a few bytes.

Chiming in from https://golang.org/cl/55613: I would vote against (1) alone because it works only if the server is Go. It's entirely possible that a non-Go server has the same behavior, which will only lead to us fixing this again on the client. So I think the fix should go in the client, e.g., (2). I'm okay with doing (1) as well if someone has an argument that such a server change would be generally useful for non-Go clients.

Waiting a hard-coded N ms for the final empty chunk makes me a bit uneasy. If we chose N too small, we miss the final chunk, but too large and it would have been faster to open a new connection. Ideally we'd use a "happy eyeballs" approach where we race the final read with a new connection, perhaps starting the new connection dial after a short delay (10ms?). But maybe that is too complex and a hard-coded N ms read is good enough.

@Kinghack

This comment has been minimized.

Contributor

Kinghack commented Aug 16, 2017

I will think about the clients change. I think it would be a bit uneasy to decide N.

@tombergan

This comment has been minimized.

Contributor

tombergan commented Nov 2, 2017

in the absence of an explicit http.Flusher.Flush from the Handler, the Server could always hold on to a few buffered bytes, to prevent the client from getting everything in one packet. That would cause the final EOF packet on the wire to contain, say, the final "}\n" of the JSON object, as well as the 0\r\n EOF chunking marker.

Chiming in again from https://golang.org/cl/55613: Maybe I'm missing something obvious ... I don't understand how exactly this is going to work. The HTTP library has no control over how writes are divided into packets. We could call Write("abc") and get two packets, or Write("ab"); Write("c") and get a single packet. Not to mention, over TLS, we'd actually need to control how bytes fit into TLS records (rather than packets).

It seems like any "fix" that attempts to merge writes into a single packet (or TLS record) is going to be brittle and heavily dependent on the underlying layers.

I still think this needs to be fixed on the client side.

@tombergan

This comment has been minimized.

Contributor

tombergan commented Nov 2, 2017

I have a fix in mind. I'll mail tomorrow.

@Kinghack

This comment has been minimized.

Contributor

Kinghack commented Nov 3, 2017

I have not finished in client side. update just because to sync up with master branch.

@bradfitz bradfitz modified the milestones: Go1.10, Go1.11 Nov 7, 2017

@bradfitz

This comment has been minimized.

Member

bradfitz commented Nov 7, 2017

This is too risky/late for Go 1.10. Moving to Go 1.11.

@trystanj

This comment has been minimized.

trystanj commented Apr 16, 2018

Just chiming in, I experienced this issue and the fix was doing what @jvshahid linked to here. Just to add another datapoint, the server was a Node server, so I agree this should definitely be handled on the client side.

In some cases I never read the body at all (e.g. HTTP status 401 => return a custom error), but did always close it. Adding that catch-all fix solved it completely, though.

@odeke-em

This comment has been minimized.

Member

odeke-em commented Jun 3, 2018

How's it going @tombergan? I am paging you from #20528 (comment)

I have a fix in mind. I'll mail tomorrow.

as CL https://go-review.googlesource.com/c/go/+/55613 has been open for 6 months.
Thank you.

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