go: x/net/http2: http.Server.WriteTimeout does not fire if the http2 stream's window is out of space.

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

$ go version 1.17.3

Does this issue reproduce with the latest release?

yes

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

What did you do?

package main

import (
	"io"
	"log"
	"net/http"
	"net/http/httptest"
	"strings"
	"time"
)

func handler(w http.ResponseWriter, r *http.Request) {
	data := strings.Repeat("x", 1<<16)
	tick := time.NewTicker(1 * time.Millisecond)
	defer tick.Stop()
	for {
		select {
		case <-tick.C:
			n, err := io.WriteString(w, data)
			log.Printf("wrote %d, err %v", n, err)
			if err != nil {
				return
			}
		case <-r.Context().Done():
			log.Printf("context cancelled")
			return
		}
	}
}

func main() {
	sv := httptest.NewUnstartedServer(http.HandlerFunc(handler))
	sv.EnableHTTP2 = true
	sv.Config.WriteTimeout = 1 * time.Second
	sv.StartTLS()

	resp, err := sv.Client().Get(sv.URL + "/")
	if err != nil {
		log.Fatal(err)
	}
	defer resp.Body.Close()

	select {} // block forever
}

This program creates a HTTP2 service which fills the HTTP/2 stream’s response window by failing to consume any data from the response body. The write deadline should fire after 1 second and terminate the response. It does not.

What did you expect to see?

If the tick rate is increased to 100ms, the write timeout fires

(~/devel/http2bug) % go run .
2021/11/23 13:03:12 wrote 65536, err <nil>
2021/11/23 13:03:13 wrote 65536, err <nil>
2021/11/23 13:03:13 wrote 65536, err <nil>
2021/11/23 13:03:13 wrote 65536, err <nil>
2021/11/23 13:03:13 wrote 65536, err <nil>
2021/11/23 13:03:13 wrote 65536, err <nil>
2021/11/23 13:03:13 wrote 65536, err <nil>
2021/11/23 13:03:13 wrote 65536, err <nil>
2021/11/23 13:03:13 wrote 65536, err <nil>
2021/11/23 13:03:13 wrote 4096, err http2: stream closed

What did you see instead?

If tick is left at 1 ms, permitting it to fill the stream’s response window, handler blocks, no timeout is reported on either the client or the server side.

(~/devel/http2bug) % go run .
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>
2021/11/23 13:03:56 wrote 65536, err <nil>

// output stops

/cc @neild @bradfitz

About this issue

  • Original URL
  • State: closed
  • Created 3 years ago
  • Comments: 23 (13 by maintainers)

Commits related to this issue

Most upvoted comments

@neild @mknyszek @davecheney Because this issue was fixed before go1.18rc1, and we want it in the 1.18.1 release, we should actually just update the vendored x/net in the go repo for 1.18, and ensure this is part of the 1.18 release.

In that case, the steps would be:

  • backport to 1.16 (in addition to the 1.17 backport)
  • close #49922
  • update the vendored x/net on go’s master branch

@davecheney The backport for 1.17 will go in sooner, and we’ll file a separate issue for that. It’ll definitely go into 1.18.1 when the milestone is opened, I just mean that the fix on tip will land in the 1.19 cycle (so when the tree opens in February).

@gopherbot Please open a backport issue for Go 1.17.

@davecheney you are right, I’ve found the problem, is the stream window as you say

I’ll send a patch so you can review