test: cancelling a stream

[oliverpool]

Related to #789 and #791.

According to @jhump in #789 (comment)

If you want to abort the RPC before the server's response has been received, one must cancel the context.Context that was used to create the RPC. Cancelling an RPC this way will trigger a cancellation error in the server.

However when http2 is enabled, cancelling the context does not suffice to unblock stream.Close().

The stream.Close calltree indicates that it is blocked in discard(reader io.Reader) (add a -timeout 500ms to go test to get a dump).

When http2 is not enabled, it seems to behave correctly.

#791 would fix this.

[jhump]

Hmmm, this seems like a bug in the HTTP/2 support in net/http. Canceling the context associated with the http.Request should abort the operation via a HTTP/2 RST_STREAM frame. I would expect the response body reader (that is being drained) to abort when that happens.

I did a quick search and was unable to find any existing issues in github.com/golang/go that describe this, so I may need to play around a little more and file such a bug (if I can convince myself this is a bug in the net/http runtime and not in connect-go).

[oliverpool]

The rebase confirms that #791 solves the initial issue.

The only remaining issue is the following:

• create an http2 enabled server
• send a stream
• close the stream (it now gets timely closed ✔️ )
• close the server (the server hangs for 10s 🐛 )

If http2 is disabled, the bug does not appear.

Might be related to https://thrawn01.org/posts/a-golang-http-server-refused-to-shutdown

(from a quick look, the httptest.Server does not configure shutdown. I need to take a deeper look, but don't have time right now)

[jhump]

@oliverpool, I just pulled down this branch and see the opposite: HTTP/2 works just fine but it's when HTTP/2 is disabled that it hangs.

I suspect the reason is that HTTP 1.1 does not have a way for the server to tell the client to "go away", other than to add a "Connection: Close" response header to a response. So I think the way HTTP 1.1 servers shutdown is to await a request on an idle connection and then add that header to the response (or add it to responses for all requests that are in-progress at the time the shutdown call is made). And if there are no incoming requests, then they eventually close the connection after an idle timeout.

I was able to get it to pass with a few changes:

1. Set the server config's WriteTimeout to one second. Without this, it takes longer for the server handler to get an I/O timeout error from calls to stream.Send.
2. Increase the close threshold from one second to three seconds. Even though the write timeout is only one second, it still seems to take some time for the server to acknowledge the error. There must be some level of buffering, though I'm not sure where (connect-go doesn't buffer: stream.Send from the server will directly write the data via the net/http.ResponseWriter). 🤷

With the above, the test passes with both HTTP 1.1 and HTTP/2.

[oliverpool]

HTTP/2 works just fine but it's when HTTP/2 is disabled that it hangs.

You are right! I oversaw this somehow.

I suspect the reason is that HTTP 1.1 does not have a way for the server to tell the client to "go away"

But here the problem is that the client wants to tell the server to stop. The following reproducer indicates that this issue present in the stdlib:

func TestHang(t *testing.T) {
	s := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		rc := http.NewResponseController(w)
		n := byte(0)
		for {
			if n > 10 {
				return
			}
			t.Log("write", n)
			_, err := w.Write([]byte{n})
			if err != nil {
				t.Log("bye", err)
				return
			}
			if n <= 2 {
				rc.Flush() // if we flush, we get the failure a bit earlier
			}
			
			time.Sleep(time.Second)
			n++
		}
	}))

	ctx, cancel := context.WithCancel(context.Background())
	req, err := http.NewRequestWithContext(ctx, "GET", s.URL, nil)
	assert.Nil(t, err)

	go func() {
		rsp, err := s.Client().Do(req)
		assert.Nil(t, err)
		t.Log(io.Copy(os.Stdout, rsp.Body))
	}()

	time.Sleep(10 * time.Millisecond)
	cancel()
	t.Log("cancelled")

	startClosing := time.Now()
	s.Close()
	assert.True(t, time.Since(startClosing) < time.Second, assert.Sprintf("server.Close took too long: %s", time.Since(startClosing)))
}

[oliverpool]

I found a solution: the server must take into account the context (net/http.ResponseWriter.Write succeeds even if the context is cancelled): c3fdd5a