net/http: Request context is not canceled when `Server.WriteTimeout` is reached #59602

zepatrik · 2023-04-13T14:09:51Z

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

$ go version
go version go1.19.5 linux/amd64

Does this issue reproduce with the latest release?

yes

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

go env Output

$ go env
GO111MODULE="on"
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/patrik/.cache/go-build"
GOENV="/home/patrik/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/patrik/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/patrik/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/lib/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/lib/go/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.19.5"
GCCGO="gccgo"
GOAMD64="v1"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/patrik/git/oathkeeper/go.mod"
GOWORK=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build1543900704=/tmp/go-build -gno-record-gcc-switches"

What did you do?

func TestWriteTimeoutCancellation(t *testing.T) {
	backend := httptest.NewUnstartedServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		r.Body.Close() // to show that it is not https://github.com/golang/go/issues/23262

		time.Sleep(1 * time.Second)
		_, err := w.Write([]byte("ok"))
		ctxErr := r.Context().Err()

		_, _ = ctxErr, err // breakpoint here to see the errors, they are both nil
	}))
	backend.Config.WriteTimeout = 500 * time.Millisecond
	backend.EnableHTTP2 = true // you can also try false

	backend.Start()
	defer backend.Close()

	start := time.Now()
	res, err := backend.Client().Get(backend.URL)
	t.Logf("took %s", time.Since(start)) // for me this always takes 1s, although the write timeout is 500ms
	_, _ = res, err // breakpoint here, err is EOF, res is nil
}

What did you expect to see?

Client side: all requests are cancelled latest after the write timeout, why wait until the handler is done to not receive the result?
Handler side: r.Context() is cancelled, so it can stop handling because the result is not returned anyway

I have seen #21389 which is kinda related, but not the same issue. I do understand that w.Write() does not immediately return an error because of buffering. I would expect the request context to be canceled immediately though.

What did you see instead?

Client: request took 1s, although the write timeout is 500ms
Handler: no way to tell whether the timeout was triggered, potentially expensive or destructive work continues

As is, I don't understand the use of WriteTimeout at all. It seems there is no effect, except for maybe big responses that might already be partially received by the client (see traefik/traefik#9191 (comment)).

I don't think this is a duplicate of #23262 because I see the behavior also when closing the body immediately.

Workaround

It seems pretty simple to just write a middleware that wraps the request context with a timeout:

func timeoutMiddleware(timeout time.Duration, next http.Handler) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		ctx, cancel := context.WithTimeout(r.Context(), timeout)
		defer cancel()
		r = r.WithContext(ctx)
		next.ServeHTTP(w, r)
	})
}

cc @alnr

The text was updated successfully, but these errors were encountered:

seankhliao · 2023-04-13T17:15:22Z

note there's already TimeoutHandler https://pkg.go.dev/net/http#TimeoutHandler

dr2chase · 2023-04-13T17:43:59Z

@neild

zepatrik · 2023-04-17T08:33:32Z

@seankhliao thanks for pointing to the net.TimeoutHandler. The problem is the way it communicates that the timeout was reached:

After such a timeout, writes by h to its ResponseWriter will return ErrHandlerTimeout.

In my case I have a handler that basically does:

validate & parse request
do some database calls
write result

In this case what I need is the request context to be cancelled on timeout to abort the expensive and potentially destructive database calls. During the database calls I typically don't write any response data, so I would not notice that the TimeoutHandler already "cancelled" the request.

seankhliao · 2023-04-17T10:54:18Z

It does cancel the request context
https://cs.opensource.google/go/go/+/refs/tags/go1.20.3:src/net/http/server.go;l=3379

zepatrik · 2023-04-17T14:12:23Z

Ah thanks for pointing that out, I guess that should be added to the docs.

The general question of when and why to use WriteTimeout remains, as the request is not aborted after WriteTimeout. Somehow it is really weird that the client only experiences a connection drop after the handler returns, even if that is way beyond the WriteTimeout. I and others find that very strange:

A sleep longer than WriteTimeout before writing the response results in the client getting no data, but the client still takes the sleep-time to disconnect rather than the timeout-time, which seems very strange to me.

https://adam-p.ca/blog/2022/01/golang-http-server-timeouts/

So yes, in this particular case, the responsiveness goal of using a WriteTimeout is completely defeated, so it basically does not work.

traefik/traefik#9191 (comment)

To me it looks like one has to use the net.TimeoutHandler instead of the server's WriteTimeout, because either there is a major misconception about the WriteTimeout out there or there is a bug. I really cannot see how setting WriteTimeout protects my server's resources.

alnr · 2023-04-17T15:32:25Z

I think net.TimeoutHandler works correctly and is useful.

But really the server should also cancel the request context for other handlers (not registered through TimeoutHandler) when the WriteTimeout is hit, shouldn't it?

neild · 2023-04-17T16:16:48Z

Perhaps it would make sense to cancel the request context when the write timeout is exceeded, since it is no longer possible for the handler to respond after that point. I'm not certain how practical this is to change at this point.

The Request.Context documentation is fairly clear on when the request context is canceled:

For incoming server requests, the context is canceled when the client's connection closes, the request is canceled (with HTTP/2), or when the ServeHTTP method returns.

This does not include when the read or write timeout on a request is exceeded.

dr2chase added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Apr 13, 2023

kwilczynski mentioned this issue Jul 9, 2023

APPSRE-7875: Add request timeout handler app-sre/gabi#57

Merged

alnr mentioned this issue Oct 11, 2023

fix: increase connection-level timeouts and shutdown timeouts ory/kratos#3570

Merged

flxbk mentioned this issue Mar 8, 2024

[query-frontend] /active_series: cancel request context when write deadline is reached grafana/mimir#7569

Merged

4 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

net/http: Request context is not canceled when `Server.WriteTimeout` is reached #59602

net/http: Request context is not canceled when `Server.WriteTimeout` is reached #59602

zepatrik commented Apr 13, 2023 •

edited

seankhliao commented Apr 13, 2023

dr2chase commented Apr 13, 2023

zepatrik commented Apr 17, 2023

seankhliao commented Apr 17, 2023

zepatrik commented Apr 17, 2023 •

edited

alnr commented Apr 17, 2023

neild commented Apr 17, 2023

net/http: Request context is not canceled when Server.WriteTimeout is reached #59602

net/http: Request context is not canceled when Server.WriteTimeout is reached #59602

Comments

zepatrik commented Apr 13, 2023 • edited

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

Does this issue reproduce with the latest release?

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

What did you do?

What did you expect to see?

What did you see instead?

Workaround

seankhliao commented Apr 13, 2023

dr2chase commented Apr 13, 2023

zepatrik commented Apr 17, 2023

seankhliao commented Apr 17, 2023

zepatrik commented Apr 17, 2023 • edited

alnr commented Apr 17, 2023

neild commented Apr 17, 2023

net/http: Request context is not canceled when `Server.WriteTimeout` is reached #59602

net/http: Request context is not canceled when `Server.WriteTimeout` is reached #59602

zepatrik commented Apr 13, 2023 •

edited

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

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

zepatrik commented Apr 17, 2023 •

edited