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

net/http: reusing http.Request and closing the response body should not result in a request cancelled #21838

Closed
zachgersh opened this issue Sep 11, 2017 · 5 comments
Closed

net/http: reusing http.Request and closing the response body should not result in a request cancelled #21838

zachgersh opened this issue Sep 11, 2017 · 5 comments
Labels
FrozenDueToAge

Comments

@zachgersh
Copy link

zachgersh commented Sep 11, 2017 •
edited

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

Been around a long time (probably since go 1.4?)

Does this issue reproduce with the latest release?

yes, reproduces with 1.9

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

darwin (should also happen on other archs are well)

What did you do?

When attempting to make an HTTP Request twice I end up getting an error on my second attempt due to my request being cancelled. The way that I saw some solve this is by reading the entire response body before making the next request. This should not be necessary as calling Close() should rain the response body anyway.

This code is an example that will fail:

package main

import "net/http"

func main() {
	req, _ := http.NewRequest("GET", "http://www.example.com", nil)
	res, err := http.DefaultClient.Do(req)
	if err != nil {
		panic(err)
	}

	err = res.Body.Close()
	if err != nil {
		panic(err)
	}

	// this is where things start to go sideways

	res, err = http.DefaultClient.Do(req)
	if err != nil {
		panic(err)
	}

	// we won't even make it here
}

What did you expect to see?

I can successfully make the second request without getting a request cancelled error.

What did you see instead?

My request was cancelled with something along the lines of

net/http: request cancelled
@tombergan
Copy link
Contributor

Does this issue reproduce with the latest release?
Definitely

To clarify for future reference, the "latest release" you tested against is 1.9, correct?

@tombergan tombergan changed the title Reusing http.Request and Closing the Response Body Should not Result in a Request Cancelled. net/http: reusing http.Request and closing the response body should not result in a request cancelled Sep 11, 2017
@zachgersh
Copy link
Author

@tombergan you are right, updated.

@odeke-em
Copy link
Member

This issue isn't always deterministically producible. Most of the time I can reproduce it but at times it succeeds i.e about 1/6th of the time, so something to look into too when working on a fix for it.

Script:

package main

import (
	"log"
	"net/http"
)

func main() {
	req, _ := http.NewRequest("GET", "http://www.example.com", nil)
	res, err := http.DefaultClient.Do(req)
	if err != nil {
		log.Fatalf("1. %v", err)
	}

	err = res.Body.Close()
	if err != nil {
		log.Fatalf("2. %v", err)
	}

	// this is where things start to go sideways

	res, err = http.DefaultClient.Do(req)
	if err != nil {
		log.Fatalf("3. %v", err)
	}

	log.Printf("Terminus!: %#v\n", res)
}
  • Bash script runner
for ((i=0; i < 30; i++)) do echo -e "Start of run #$i\n" && go run main.go && echo -e "\n\nEnd of run #$i\n\n" && sleep 2;done

Result:

Start of run #0

2017/09/11 15:49:34 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #1

2017/09/11 15:49:37 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #2

2017/09/11 15:49:39 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #3

2017/09/11 15:49:41 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #4

2017/09/11 15:49:42 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #5

2017/09/11 15:49:44 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #6

2017/09/11 15:49:46 Terminus!: &http.Response{Status:"200 OK", StatusCode:200, Proto:"HTTP/1.1", ProtoMajor:1, ProtoMinor:1, Header:http.Header{"Server":[]string{"ECS (mdw/1275)"}, "Content-Type":[]string{"text/html"}, "Date":[]string{"Mon, 11 Sep 2017 21:49:46 GMT"}, "Etag":[]string{"\"359670651+gzip\""}, "Last-Modified":[]string{"Fri, 09 Aug 2013 23:54:35 GMT"}, "Accept-Ranges":[]string{"bytes"}, "Cache-Control":[]string{"max-age=604800"}, "Expires":[]string{"Mon, 18 Sep 2017 21:49:46 GMT"}, "Vary":[]string{"Accept-Encoding"}, "X-Cache":[]string{"HIT"}}, Body:(*http.gzipReader)(0xc420174060), ContentLength:-1, TransferEncoding:[]string(nil), Close:false, Uncompressed:true, Trailer:http.Header(nil), Request:(*http.Request)(0xc4200f8000), TLS:(*tls.ConnectionState)(nil)}


End of run #6


Start of run #7

2017/09/11 15:49:50 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #8

2017/09/11 15:49:52 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #9

2017/09/11 15:49:54 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #10

2017/09/11 15:49:56 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #11

2017/09/11 15:49:58 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #12

2017/09/11 15:50:00 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #13

2017/09/11 15:50:02 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #14

2017/09/11 15:50:04 Terminus!: &http.Response{Status:"200 OK", StatusCode:200, Proto:"HTTP/1.1", ProtoMajor:1, ProtoMinor:1, Header:http.Header{"Etag":[]string{"\"359670651+gzip\""}, "Last-Modified":[]string{"Fri, 09 Aug 2013 23:54:35 GMT"}, "X-Cache":[]string{"HIT"}, "Cache-Control":[]string{"max-age=604800"}, "Content-Type":[]string{"text/html"}, "Date":[]string{"Mon, 11 Sep 2017 21:50:04 GMT"}, "Server":[]string{"ECS (mdw/1275)"}, "Vary":[]string{"Accept-Encoding"}, "Accept-Ranges":[]string{"bytes"}, "Expires":[]string{"Mon, 18 Sep 2017 21:50:04 GMT"}}, Body:(*http.gzipReader)(0xc4200e04e0), ContentLength:-1, TransferEncoding:[]string(nil), Close:false, Uncompressed:true, Trailer:http.Header(nil), Request:(*http.Request)(0xc4200f8000), TLS:(*tls.ConnectionState)(nil)}


End of run #14


Start of run #15

2017/09/11 15:50:08 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #16

2017/09/11 15:50:10 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #17

2017/09/11 15:50:12 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #18

2017/09/11 15:50:14 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #19

2017/09/11 15:50:16 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #20

2017/09/11 15:50:18 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #21

2017/09/11 15:50:20 Terminus!: &http.Response{Status:"200 OK", StatusCode:200, Proto:"HTTP/1.1", ProtoMajor:1, ProtoMinor:1, Header:http.Header{"Last-Modified":[]string{"Fri, 09 Aug 2013 23:54:35 GMT"}, "Vary":[]string{"Accept-Encoding"}, "X-Cache":[]string{"HIT"}, "Content-Type":[]string{"text/html"}, "Expires":[]string{"Mon, 18 Sep 2017 21:50:20 GMT"}, "Cache-Control":[]string{"max-age=604800"}, "Date":[]string{"Mon, 11 Sep 2017 21:50:20 GMT"}, "Etag":[]string{"\"359670651+gzip\""}, "Server":[]string{"ECS (mdw/1275)"}, "Accept-Ranges":[]string{"bytes"}}, Body:(*http.gzipReader)(0xc4201180a0), ContentLength:-1, TransferEncoding:[]string(nil), Close:false, Uncompressed:true, Trailer:http.Header(nil), Request:(*http.Request)(0xc4200f8000), TLS:(*tls.ConnectionState)(nil)}


End of run #21


Start of run #22

2017/09/11 15:50:24 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #23

2017/09/11 15:50:26 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #24

2017/09/11 15:50:27 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #25

2017/09/11 15:50:29 Terminus!: &http.Response{Status:"200 OK", StatusCode:200, Proto:"HTTP/1.1", ProtoMajor:1, ProtoMinor:1, Header:http.Header{"Accept-Ranges":[]string{"bytes"}, "Content-Type":[]string{"text/html"}, "Expires":[]string{"Mon, 18 Sep 2017 21:50:29 GMT"}, "Last-Modified":[]string{"Fri, 09 Aug 2013 23:54:35 GMT"}, "X-Cache":[]string{"HIT"}, "Cache-Control":[]string{"max-age=604800"}, "Date":[]string{"Mon, 11 Sep 2017 21:50:29 GMT"}, "Etag":[]string{"\"359670651+gzip\""}, "Server":[]string{"ECS (mdw/1275)"}, "Vary":[]string{"Accept-Encoding"}}, Body:(*http.gzipReader)(0xc420102160), ContentLength:-1, TransferEncoding:[]string(nil), Close:false, Uncompressed:true, Trailer:http.Header(nil), Request:(*http.Request)(0xc4200f8000), TLS:(*tls.ConnectionState)(nil)}


End of run #25


Start of run #26

2017/09/11 15:50:33 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #27

2017/09/11 15:50:35 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #28

2017/09/11 15:50:37 3. Get http://www.example.com: net/http: request canceled
exit status 1
Start of run #29

2017/09/11 15:50:39 Terminus!: &http.Response{Status:"200 OK", StatusCode:200, Proto:"HTTP/1.1", ProtoMajor:1, ProtoMinor:1, Header:http.Header{"Vary":[]string{"Accept-Encoding"}, "X-Cache":[]string{"HIT"}, "Accept-Ranges":[]string{"bytes"}, "Cache-Control":[]string{"max-age=604800"}, "Expires":[]string{"Mon, 18 Sep 2017 21:50:39 GMT"}, "Server":[]string{"ECS (mdw/1275)"}, "Last-Modified":[]string{"Fri, 09 Aug 2013 23:54:35 GMT"}, "Content-Type":[]string{"text/html"}, "Date":[]string{"Mon, 11 Sep 2017 21:50:39 GMT"}, "Etag":[]string{"\"359670651+gzip\""}}, Body:(*http.gzipReader)(0xc420158060), ContentLength:-1, TransferEncoding:[]string(nil), Close:false, Uncompressed:true, Trailer:http.Header(nil), Request:(*http.Request)(0xc4200fa000), TLS:(*tls.ConnectionState)(nil)}


End of run #29

@gopherbot
Copy link

Change https://golang.org/cl/62891 mentions this issue: net/http: allow reuse of http.Request objects

@zachgersh
Copy link
Author

@odeke-em yeah, I would expect that the succeeding 1/6th of the time would be to the machine going just slow enough that you end up resetting the canceller.

You can make it succeed in the example above all the time just by adding a time.Sleep to the code (then it succeeds 100% of the time).

Think the solution we arrived at was as straightforward as we could make it :D

@golang golang locked and limited conversation to collaborators Sep 12, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@zachgersh @odeke-em @gopherbot @tombergan