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

x/net/http2: Server.ReadTimeout does not fire for HTTP/2 requests #49837

Closed
davecheney opened this issue Nov 29, 2021 · 10 comments
Closed

x/net/http2: Server.ReadTimeout does not fire for HTTP/2 requests #49837

davecheney opened this issue Nov 29, 2021 · 10 comments
Assignees
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done.
Milestone

Comments

@davecheney
Copy link
Contributor

davecheney commented Nov 29, 2021

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

$ go version 1.17.3

Does this issue reproduce with the latest release?

yes

What did you do?

package main

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

func handler(w http.ResponseWriter, r *http.Request) {
        log.Println("handler started")
        start := time.Now()
        buf, err := io.ReadAll(r.Body)
        log.Printf("read %d in %v, err: %v", len(buf), time.Since(start), err)
}

type slowReader struct {
        delay time.Duration
        io.Reader
}

func (sr *slowReader) Read(buf []byte) (int, error) {
        time.Sleep(sr.delay)
        return sr.Reader.Read(buf)
}

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

        resp, err := sv.Client().Post(sv.URL+"/", "text/plain", &slowReader{
                delay:  5 * time.Second,
                Reader: strings.NewReader("hello, HTTP/2"),
        })
        if err != nil {
                log.Fatal(err)
        }
        defer resp.Body.Close()
}

What did you expect to see?

After 1 second, some error from io.ReadAll in handler indicating the request had timed out during reading.

What did you see instead?

(~/devel/http2bug) % go run main.go
2021/11/29 14:57:45 handler started
2021/11/29 14:57:55 read 13 in 10.00982654s, err: <nil>

The call to io.ReadAll completed in 10 seconds with no error.

@davecheney davecheney added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Nov 29, 2021
@davecheney davecheney added this to the Go1.18 milestone Nov 29, 2021
@davecheney
Copy link
Contributor Author

/cc @aojea

@aojea
Copy link
Contributor

aojea commented Nov 29, 2021

This seems to be the expected behavior, I can see that for ReadTimeout is the same as IdleTimeout for http2,

https://github.com/golang/net/blob/d455829e376dcf0ca6aca82a86d093afbcc6a8ee/http2/server.go#L229-L234

and doesn't take the body into consideration

	// ReadTimeout is the maximum duration for reading the entire
	// request, including the body. A zero or negative value means
	// there will be no timeout.
	//
	// Because ReadTimeout does not let Handlers make per-request
	// decisions on each request body's acceptable deadline or
	// upload rate, most users will prefer to use
	// ReadHeaderTimeout. It is valid to use them both.
	ReadTimeout time.Duration

there is also a test that checks that the handler is not affected by the timeout https://github.com/golang/net/blob/d455829e376dcf0ca6aca82a86d093afbcc6a8ee/http2/server_test.go#L3891-L3917

It seems this comment from @bradfitz explains the decision
#14204 (comment)

... anyway, if my understanding is wrong I'm happy to help if I have some guidance 😅

@davecheney
Copy link
Contributor Author

Thanks for finding the link to the previous discussion. IMO if this is the intended behaviour then the comment on ReadTimeout probably needs to be updated.

	// ReadTimeout is the maximum duration for reading the entire
	// request, including the body. A zero or negative value means
	// there will be no timeout.

This isn't correct in the HTTP/2 context. At best, if the user has set WriteTimeout then it will fire at some point and tear down the stream, but ReadTimeout is ineffective in HTTP/2 contexts.

@ianlancetaylor
Copy link
Contributor

CC @neild

@heschi heschi modified the milestones: Go1.18, Go1.19 Mar 15, 2022
@ianlancetaylor
Copy link
Contributor

Rolling forward to 1.20. Please comment if you disagree. Thanks.

@ianlancetaylor ianlancetaylor modified the milestones: Go1.19, Go1.20 Jun 24, 2022
@neild neild self-assigned this Oct 28, 2022
@neild neild added NeedsFix The path to resolution is known, but the work has not been done. and removed Documentation NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Oct 28, 2022
@neild
Copy link
Contributor

neild commented Oct 28, 2022

Sorry for missing this when it was originally filed.

So far as I can tell, Server.ReadTimeout is simply not implemented for HTTP/2 at the moment. It should be. Working on a fix now.

@gopherbot
Copy link

Change https://go.dev/cl/446255 mentions this issue: net/http: add tests for Server.ReadTimeout and server.WriteTimeout

@gopherbot
Copy link

Change https://go.dev/cl/446256 mentions this issue: http2: support Server.ReadTimeout

gopherbot pushed a commit to golang/net that referenced this issue Nov 4, 2022
Return an error when reading from the request body in a server
handler after Server.ReadTimeout expires.

Tested by net/http CL 446255.

For golang/go#49837

Change-Id: Idcc3d92209f944bd7fead832525fd563b50bcebc
Reviewed-on: https://go-review.googlesource.com/c/net/+/446256
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
Reviewed-by: Bryan Mills <bcmills@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
Run-TryBot: Damien Neil <dneil@google.com>
gopherbot pushed a commit that referenced this issue Nov 10, 2022
We don't seem to have tests verifying that handler reads from the
request body or writes to the response body time out properly.
Add some.

For #49837
For #56478

Change-Id: I0828edd6c86b071073fd1b22ccbb24f86114ab94
Reviewed-on: https://go-review.googlesource.com/c/go/+/446255
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
Reviewed-by: Bryan Mills <bcmills@google.com>
Run-TryBot: Damien Neil <dneil@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
@gopherbot
Copy link

Change https://go.dev/cl/449935 mentions this issue: all: update vendored golang.org/x/net to v0.2.0

@neild
Copy link
Contributor

neild commented Nov 15, 2022

Fixed in golang.org/x/net v0.2.0, will be in go1.20.

@neild neild closed this as completed Nov 15, 2022
WeiminShang added a commit to WeiminShang/net that referenced this issue Nov 16, 2022
Return an error when reading from the request body in a server
handler after Server.ReadTimeout expires.

Tested by net/http CL 446255.

For golang/go#49837

Change-Id: Idcc3d92209f944bd7fead832525fd563b50bcebc
Reviewed-on: https://go-review.googlesource.com/c/net/+/446256
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
Reviewed-by: Bryan Mills <bcmills@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
Run-TryBot: Damien Neil <dneil@google.com>
gopherbot pushed a commit that referenced this issue Nov 22, 2022
Update net/http to enable tests that pass with the latest update
to the vendored x/net.

Update a few tests:

Windows apparently doesn't guarantee that time.Since(time.Now())
is >=0, so to set a definitely-expired write deadline, use a time
firmly in the past rather than now.

Put a backoff loop on TestServerReadTimeout to avoid failures
when the timeout expires mid-TLS-handshake. (The TLS handshake
timeout is set to min(ReadTimeout, WriteTimeout, ReadHeaderTimeout);
there's no way to set a long TLS handshake timeout and a short
read timeout.)

Don't close the http.Server in TestServerWriteTimeout while the
handler may still be executing, since this can result in us
getting the wrong error.

Change the GOOS=js fake net implementation to properly return
ErrDeadlineExceeded when a read/write deadline is exceeded,
rather than EAGAIN.

For #49837
For #54136

Change-Id: Id8a4ff6ac58336ff212dda3c8799b320cd6b9c19
Reviewed-on: https://go-review.googlesource.com/c/go/+/449935
Reviewed-by: Bryan Mills <bcmills@google.com>
Run-TryBot: Damien Neil <dneil@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
@golang golang locked and limited conversation to collaborators Nov 15, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done.
Projects
Development

No branches or pull requests

6 participants