Open
Description
Go version
go version go1.22.2 linux/amd64
Output of go env
in your module/workspace:
GO111MODULE=''
GOARCH='amd64'
GOBIN=''
GOCACHE='<some-path>/.cache/go-build'
GOENV='<some-path>/.config/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='amd64'
GOHOSTOS='linux'
GOINSECURE=''
GOMODCACHE='<some-path>/go/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='<some-path>/go'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/usr/lib/go'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/usr/lib/go/pkg/tool/linux_amd64'
GOVCS=''
GOVERSION='go1.22.2'
GCCGO='gccgo'
GOAMD64='v1'
AR='ar'
CC='gcc'
CXX='g++'
CGO_ENABLED='1'
GOMOD='<some-path>/go.mod'
GOWORK=''
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=/tmp/go-build4138323568=/tmp/go-build -gno-record-gcc-switches'
What did you do?
Implement a trivial net/http Server that listens via HTTPS (using a self-signed cert for dev purposes) and responds with a fixed 5KB response:
package main
import (
"io"
"log"
"net/http"
"strings"
)
func main() {
http.HandleFunc("GET /{$}", func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "text/plain; charset=utf-8")
response := strings.Repeat("A", 5000) + "\n"
if n, err := io.WriteString(w, response); err != nil {
log.Printf("Failed to send response, wrote %d/%d bytes: %v", n, len(response), err)
} else {
log.Printf("Sent %d/%d response bytes", n, len(response))
}
})
log.Println("Listening")
log.Fatal(http.ListenAndServeTLS("127.0.0.1:8443", "server.cer.pem", "server.key.pem", nil))
}
What did you see happen?
When hitting the server with:
$ curl -k -I https://127.0.0.1:8443/
The response is as expected (i.e. code 200 but empty), but the server logs an error:
$ go run .
2024/04/13 17:21:22 Listening
2024/04/13 17:21:23 Failed to send response, wrote 4096/5001 bytes: http2: request body closed due to handler exiting
What did you expect to see?
No error logged.
Note that an error is only logged when using HTTP/2, and only when the response exceeds 4096 bytes.
Interestingly, a different error is logged if I remove the explicit setting of the Content-Type header (in which case the same header+value still ends up in the response, presumably because net/http auto-detects the content type):
2024/04/13 17:44:48 Failed to send response, wrote 4096/5001 bytes: short write
Metadata
Metadata
Assignees
Labels
Type
Projects
Relationships
Development
No branches or pull requests
Activity
c4rlo commentedon Apr 13, 2024
Looking into this a bit more, what seems to be happening is that
ResponseWriter.Write
ends up callinghttp2responseWriterState.writeChunk
. That one has some special handling that should make it swallow Writes for HEAD requests:go/src/net/http/h2_bundle.go
Lines 6514 to 6516 in 519f6a0
However, it never gets that far. Instead, because
!rws.sentHeader
, it first callsrws.conn.writeHeaders
, and that one queues the write and then – for some reason – gets to thisselect
case:go/src/net/http/h2_bundle.go
Lines 6245 to 6246 in 519f6a0
That
http2errStreamClosed
then gets translated into a different error up the stack inhttp2chunkWriter.Write
:go/src/net/http/h2_bundle.go
Lines 6401 to 6405 in 519f6a0
And that
cw.rws.stream.closeErr
ends up being the error we see (e.g. "http2: request body closed due to handler exiting" =http2errHandlerComplete
).That's as far as I got for now.
c4rlo commentedon Apr 13, 2024
Ok, let's go deeper. We already mentioned that
http2responseWriterState.writeChunk
callsrws.conn.writeHeaders
. In doing so, it passes it ahttp2writeResHeaders
struct, one of whose fields isendStream
. In the HEAD case, that gets set totrue
by this:go/src/net/http/h2_bundle.go
Line 6497 in 519f6a0
Let's now turn to
http2serverConn.serve
; after some initialisation, it consists of afor
/select
loop, with one of theselect
cases being:go/src/net/http/h2_bundle.go
Lines 4777 to 4778 in 519f6a0
Ok, so after writing each frame (we presume), it calls
sc.wroteFrame
. Looking into that, we see:go/src/net/http/h2_bundle.go
Line 5118 in 519f6a0
And
http2writeEndsStream
checks theendStream
field mentioned above, hence returnstrue
. It then ends up here (in my testing):go/src/net/http/h2_bundle.go
Lines 5141 to 5142 in 519f6a0
And one of the things that
http2serverConn.closeStream
does is:go/src/net/http/h2_bundle.go
Line 5499 in 519f6a0
Which (
cw
being of a type that is a thin wrapper around a channel) probably explains why we get into thecase <-st.cw
inhttp2serverConn.writeHeaders
as mentioned in my previous comment.Summarising:
writeChunk
callswriteHeaders
in such a way that it closes the stream immediately afterwards, which (indirectly) causeswriteHeaders
to returnhttp2errStreamClosed
. AndwriteChunk
is seemingly not expecting that, hence it passes that error on to its caller.c4rlo commentedon Apr 13, 2024
The following seems to be a fix – it fixes my example, at least:
c4rlo commentedon Apr 14, 2024
If the maintainers agree that this fix goes in the right direction, I'd be happy to contribute it to the
x/net/http2
package (I'm aware that's where the standard libary'sh2_bundle.go
is taken from).seankhliao commentedon Apr 14, 2024
cc @neild
neild commentedon Apr 16, 2024
You're sending a HEAD request to a handler that writes a response body.
HEAD requests don't have a response body, of course, so the server needs to discard it.
There seems to be some divergence in how the HTTP/1 and HTTP/2 servers deal with the case of a handler writing a body in response to a HEAD request. (None of this is in my working memory, so I'm going off of a quick glance at the code, and I may be getting some of the details wrong.)
Both the HTTP/1 and HTTP/2 paths will buffer writes to the response body. If the entire body fits in the response buffer, then the server will send a
Content-Length
header based on how much was written before the handler exited. If the body doesn't fit in the response buffer, or if the handler flushes the buffer explicitly, then the server will send headers when the buffer fills. In this case it won't send aContent-Length
unless the handler provided one.Once the server has sent headers in response to a HEAD request, there's no point in the handler writing more of the response body--the server doesn't have anything to do with it, and all it can do is discard the bytes.
The HTTP/1
ResponseWriter
silently discards the response bytes and returns success.The HTTP/2
ResponseWriter
discards the response bytes and returns an error. The error is confusing and wrong: "http2: response body closed due to handler exiting", but the handler hasn't exited.I think returning an error is the better behavior here, since it lets the handler exit quickly. (Perhaps we should change the HTTP/1 server to do so as well, although Hyrum's Law probably applies here.) The error shouldn't lie about the handler being complete when it isn't, and ideally would explain what's going on: "stream closed" would be terse but accurate, "response body for HEAD request closed" might be more explanatory.
I don't think suppressing the error is the right option, though.
c4rlo commentedon Apr 17, 2024
Fair point. However, there are also good arguments for why not returning an error is the right thing:
On balance, silently discarding writes for HTTP/2 (matching HTTP/1 behaviour) seems like the better way forward to me.
Or if we want to return an error, then I feel like we should find some way to make this the behaviour for both HTTP/1 and HTTP/2 – which as you point out is a breaking change (albeit of undocumented behaviour) so requires care.
neild commentedon Apr 18, 2024
But a naive GET handler does do the right thing for HEAD requests: The server responds to the HEAD request with appropriate headers.
ResponseWriter.Write returning an error is a normal and expected condition, indicating that the handler can stop writing the response body because the client isn't reading it. This happens when a connection breaks mid-response (due to a network error, the client going away, or--in HTTP/2--the client canceling the request), or in this case when the response isn't being sent to the client at all.
Changing the HTTP/2 server to silently discard writes seems like a strict degradation of functionality.
c4rlo commentedon Apr 21, 2024
True. Apart from the potentially confusing error trace in the logs (which is how I stumbled on this).
Regarding your comparison with other errors returned from
ResponseWriter.Write
: well, those are for transient conditions, whereas here we are systematically returning an error for a particular case where nothing even went wrong.So yeah, it would certainly help to improve the error message wording. Something like "not writing data in response to HEAD request" maybe.
Ideally, also introduce a dedicated
Err*
value for this, enabling users to suppress it (in a non-brittle way). Given that this case is just part of the expected behaviour, and does not indicate any bad/abortive/unusual behaviour by either client, server, the network, or anything else.I agree, there are downsides to doing this (causing the handler to do unnecessary work, and being a change in behaviour).
On the other hand, just tweaking the error message as suggested above also leaves the downside that (some) users will end up writing extra lines of code to suppress these non-error errors, and that it does not address (pre-existing) the inconsistency between HTTP/1 and HTTP/2.
But given that I seem to be the first one reporting this, that may be a reasonable trade-off; it would certainly be the more conservative change.
c4rlo commentedon Apr 28, 2024
If the maintainers prefer the approach of merely tweaking the error message (and possibly exposing that
error
value as a publicErr*
variable), I'd be happy to have a go at implementing it.c4rlo commentedon May 11, 2024
Checking in here. Still happy to help out, once there is agreement from the maintainers on what the fix should look like.