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

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

Comments

Projects
None yet
4 participants
@zachgersh
Copy link

commented Sep 11, 2017

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

This comment has been minimized.

Copy link
Contributor

commented Sep 11, 2017

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

This comment has been minimized.

Copy link
Author

commented Sep 11, 2017

@tombergan you are right, updated.

@odeke-em

This comment has been minimized.

Copy link
Member

commented Sep 11, 2017

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

This comment has been minimized.

Copy link

commented Sep 11, 2017

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

@zachgersh

This comment has been minimized.

Copy link
Author

commented Sep 12, 2017

@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

@gopherbot gopherbot closed this in 78c4dc3 Sep 12, 2017

@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.
You can’t perform that action at this time.