service/route53: ListHostedZones hangs and then fails with go1.8

[voutasaurus]

go version:
go version go1.8beta1 darwin/amd64

output of go env:

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/voutasaurus"
GORACE=""
GOROOT="/usr/local/go"
GOTOOLDIR="/usr/local/go/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/v_/gz6l428x5w97h0zrm5m03rlm0000gn/T/go-build211369366=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
CGO_ENABLED="1"
PKG_CONFIG="pkg-config"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"

Minimal code example:

package main

import (
	"log"

	"github.com/aws/aws-sdk-go/aws/session"
	"github.com/aws/aws-sdk-go/service/route53"
)

func main() {
	r53 := route53.New(session.New())
	r, err := r53.ListHostedZones(&route53.ListHostedZonesInput{})
	if err != nil {
		log.Fatal(err)
	}
	log.Println(r)
}

Ran with: AWS_REGION=us-east-1 AWS_PROFILE=default go run main.go

Expected output: The contents of r

Got output:
The terminal hung for about a minute (I didn't time it) and then printed this:

2016/12/06 16:10:04 RequestError: send request failed
caused by: Get https://route53.amazonaws.com/2013-04-01/hostedzone: read tcp 10.1.10.61:60233->54.239.31.171:443: read: connection reset by peer
exit status 1

This may be a bug with go1.8 itself but since the way the AWS library does requests is so convoluted I got stuck at this point trying to understand what was going on. There may be something deprecated in 1.8 that is still in use in the AWS library.

[voutasaurus]

Actually the first time I ran it it hung and then printed

2016/12/06 16:06:18 RequestError: send request failed
caused by: Get https://route53.amazonaws.com/2013-04-01/hostedzone: EOF
exit status 1

[voutasaurus]

To be clear this all works fine with go 1.7.4.

[voutasaurus]

This is with https://github.com/aws/aws-sdk-go/tree/v1.6.0 but I was also getting the issue on an earlier version.

[xibz]

Hello @voutasaurus, thank you for reaching out to us. I'll definitely take a look at 1.8 to see if it is behaving funny. Looking at the 1.8 milestone, I don't see anything that sticks out to why it would fail to send requests.

[jasdel]

@voutasaurus Do you see this with any other service and API or just ListHostedZones?

[voutasaurus]

I thought I was getting it with ChangeResourceRecordSets but I just checked and that appears to be working. So it's only affecting ListHostedZones as far as I can tell. I haven't tried any of the other functions in the route53 library.

[jasdel]

I've been able to reproduce this using 1.8beta1 and not on 1.7.4. Tip of Go also does this. Initially the only difference in the requests I can see so far is that the 1.8beta1 version of the request includes a body with a single 0 character in it for some reason. It looks like the server rejects the request if this is received, which is odd because I would of expected a HTTP status code not socket error.

[jasdel]

Looks like this is a change in behavior in 1.8. It is a bit odd to make a get request with a zero length body, but before this was fine. Now it looks like the zero length is getting written the request's body. Go server seems to handle this fine, but I have a feeling other HTTP servers like Apache my not.

package main

import (
	"bytes"
	"fmt"
	"io/ioutil"
	"net/http"
	"net/http/httptest"
	"net/http/httputil"
)

func main() {
	server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		b, _ := httputil.DumpRequest(r, true)
		fmt.Println("Request")
		fmt.Println(string(b))

		w.WriteHeader(http.StatusOK)
	}))

	req, err := http.NewRequest("GET", server.URL, nil)

	body := bytes.NewReader([]byte{})
	req.Body = ioutil.NopCloser(body)

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

	b, _ := httputil.DumpResponse(resp, true)
	fmt.Println("Response:")
	fmt.Println(string(b))
}

Output:

Request
GET / HTTP/1.1
Host: 127.0.0.1:39813
Transfer-Encoding: chunked
Accept-Encoding: gzip
User-Agent: Go-http-client/1.1

0


Response:
HTTP/1.1 200 OK
Content-Type: text/plain; charset=utf-8
Date: Thu, 08 Dec 2016 21:24:58 GMT
Content-Length: 0

[jasdel]

Arguably the SDK shouldn't be setting the body at all if the length is zero especially for GET, HEAD, and DELETE operations, but fixing this now will still mean users that update to Go 1.8 but not updating the SDK will experience issues.

[voutasaurus]

Thanks jasdel. It sounds like Brad wants to fix it in the http package so I guess the pressure is off for a fix in the sdk.

[voutasaurus]

I take that back, looks like he's saying something different.

[jasdel]

Marking as bug since we can make some fixes on our end to improve this, but I think the change that introduce this into 1.8 may also be at issue.

[bradfitz]

Where is the code in question in aws-sdk-go? I'd like to see exactly what it's doing to inform whether/how to make a fix on Go's side.

[jasdel]

Sure glad to. This process is spread over a few places though.

The SDK will first create a request based on metadata for the API called.

The request's query parameters, headers, and body will be constructed based on the API and protocol. Updating the http.Request value's Headers, URI, and QueryString. The built body is stored in a io.ReadSeeker.

The built body of is then wrapped in an concurrency safe internal reader to allow retrying of the underlying reader without risking race conditions with http.Transport before being assigned to the http.Request.Body field.

The built request will finally be sent via the configured HTTP client.

[jasdel]

Thanks for contacting us about this issue. I pushed a change which corrects this in #991, and this will be included in our next release. Let us know if you run into any issues, or have feedback.

[voutasaurus]

thanks! :)