net/http: "use of closed network connection" error when reading 1MB or so

[kevinburke]

Originally reported as ipfs/kubo#3855 - my thanks to @timthelion, @whyrusleeping and others for helping debug.

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

Tip go version devel +812b34efae Mon Sep 4 00:07:33 2017 +0000 darwin/amd64

Does this issue reproduce with the latest release?

Yes

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

$ go env
GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/kevin"
GORACE=""
GOROOT="/Users/kevin/go"
GOTOOLDIR="/Users/kevin/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/sf/fsn3_vgd0n98r0jb86bgp83r0000gn/T/go-build607690397=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
CGO_ENABLED="1"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"

What did you do?

Here's a test case exposing the error.

type failReader struct {
	tot   int64
	limit int64
}

func (fr *failReader) Read(b []byte) (int, error) {
	fr.tot += int64(len(b))
	if fr.tot > fr.limit {
		return 0, fmt.Errorf("look at my cool error")
	}

	return len(b), nil
}

func TestConnectionCloseManyFiles(t *testing.T) {
	mux := NewServeMux()
	mux.HandleFunc("/", func(w ResponseWriter, r *Request) {
		buf := make([]byte, 4096)
		var tot int64
		_, err := w.Write([]byte("foobar"))
		if err != nil {
			t.Fatal(err)
		}
		w.(Flusher).Flush()
		for {
			n, err := r.Body.Read(buf)
			if err != nil {
				fmt.Println("read error: ", err)
				fmt.Println("total bytes: ", tot)
				break
			}

			//fmt.Println("total so far: ", tot)
			tot += int64(n)
		}
		_, err = w.Write([]byte("foobar"))
		if err != nil {
			t.Fatal(err)
		}
	})
	s := httptest.NewServer(mux)

	r := &failReader{
		limit: 1*1000*1000,
	}
	req, err := NewRequest("POST", s.URL, r)
	if err != nil {
		panic(err)
	}

	resp, err := DefaultClient.Do(req)
	if err != nil {
		t.Fatal(err)
	}
	defer resp.Body.Close()

	buf := new(bytes.Buffer)
	_, err = io.Copy(buf, resp.Body)
	if err != nil {
		t.Fatal(err)
	}
	if got := buf.String(); got != "foobar" {
		t.Errorf("Write: got %s, want %s", got, "foobar")
	}
}

You can tweak the numbers as you see fit; it takes about a million bytes read to trigger the error.

What did you expect to see?

I expect to see something like

	client_test.go:1836: Post http://127.0.0.1:50390: look at my cool error

What did you see instead?

This odd error:

client_test.go:1843: read tcp 127.0.0.1:50389->127.0.0.1:50388: use of closed network connection

[whyrusleeping]

Thanks @kevinburke, we assumed our code was broken for the longest time.

Reproduces with Go 1.8 and 1.9 (linux/amd64) (not every run, though).

[ldnvnbl]

@whyrusleeping @kevinburke

I read the code find that the "use of closed network connection" error reason is, when net/http write request body to server, it read response from server at the same time with the same tcp connection.

In your test case, the server first flush that lead to DefaultClient.Do(req) return quickly, but net/http write request body with 'failReader' failed (no one handle this error if DefaultClient.Do complete), then the tcp connection will be closed, so you will get that error.

And I read https://www.w3.org/Protocols/rfc2616/rfc2616-sec8.html:

An HTTP/1.1 (or later) client sending a message-body SHOULD monitor the network connection for an error status while it is transmitting the request. If the client sees an error status, it SHOULD immediately cease transmitting the body. If the body is being sent using a "chunked" encoding (section 3.6), a zero length chunk and empty trailer MAY be used to prematurely mark the end of the message. If the body was preceded by a Content-Length header, the client MUST close the connection.

So in this test case, client sent body using a "chunked" encoding. so the right output maybe:

xxxx_test.go:77: Write: got foobarfoobar, want foobar

So the golang has a bug that it not send "chunked" end message when sees error of 'failReader'.

[ianlancetaylor]

CC @bradfitz @tombergan

[tombergan]

So the golang has a bug that it not send "chunked" end message when sees error of 'failReader'.

It sounds like you believe net/http is violating RFC 2616. Can you explain why? I don't see a violation. When Request.Body.Read returns an error, we close the connection, which is allowed. The quoted passage from the RFC says that a client "MAY" send a zero length chunk to prematurely mark the end of the message. This is a MAY. We're not forced to, and in fact, we don't want to because doing so might result in the server incorrectly believing that we have sent the full message.

This is simply a poor error message: We make an effort to prefer the error from Request.Body.Read (see link below), but this effort works only when the Request.Body.Read error happens before the server sends a response. Once the server sends a response, RoundTrip returns and the caller starts reading Response.Body, and the Request.Body.Read error is not propagated to Response.Body.Read.

go/src/net/http/transport.go

Line 1765 in f9cf8e5

// Errors reading from the user's

As evidence for this: When the read limit is low, we get "look at my cool error" from http.DefaultClient.Do. When the read limit is high, we get "use of closed network connection" from io.Copy(buf, resp.Body).

[ldnvnbl]

@tombergan

we don't want to because doing so might result in the server incorrectly believing that we have sent the full message.

This is right, sorry for my invalid comment.

[bradfitz]

What is the request here?

To make Transport.RoundTrip prefer the Request.Body.Read error over the server conn read failure?

The ~million bytes is probably because HTTP/1 servers try to consume their input before replying with any headers. (So the Flush is blocking, reading from the client).

There's also a bug open somewhere to support bidirectional HTTP/1 like HTTP/2's always bidirectional support. (But HTTP/1 would probably need to be opt-in, not on by default).

[bradfitz]

Related: #11745

[bradfitz]

@kevinburke, ping.