Go version

go version go1.22.5 linux/amd64

Output of go env in your module/workspace:

N/A

What did you do?

I have published a small reproducer to this repository: https://github.com/uhthomas/go-unsolicited-http

The instructions are in the README, but for brevity:

Run the server:

code ###### main.go 
package main

import (
    "context"
    "flag"
    "fmt"
    "io"
    "log"
    "net/http"
    "sync/atomic"
)

type Server struct {
    requestCount uint64
}

func (s *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) {
    requestID := atomic.AddUint64(&s.requestCount, 1)

    if f, ok := w.(http.Flusher); ok {
        f.Flush()
    }

    res, err := http.Get("https://go.dev")
    if err != nil {
        panic(err)
    }

    n, err := io.Copy(w, res.Body)

    fmt.Printf("%d: %d bytes written, err=%v\n", requestID, n, err)
}

func Main(ctx context.Context) error {
    addr := flag.String("addr", ":8080", "address to listen on")
    flag.Parse()

    log.Println("listening on", *addr)

    return http.ListenAndServe(*addr, &Server{})
}

func main() {
    if err := Main(context.Background()); err != nil {
        log.Fatal(err)
    }
}

❯ go run github.com/uhthomas/go-unsolicited-http/cmd/server@main

Run the client:

code ###### main.go 
package main

import (
    "context"
    "fmt"
    "log"
    "net/http"
    "time"
)

func Main(ctx context.Context) error {
    for i := 0; ; i++ {
        fmt.Println("attempt", i)

        if _, err := http.Head("http://localhost:8080"); err != nil {
            return fmt.Errorf("head: %w", err)
        }

        time.Sleep(200 * time.Millisecond)
    }
}

func main() {
    if err := Main(context.Background()); err != nil {
        log.Fatal(err)
    }
}

❯ go run github.com/uhthomas/go-unsolicited-http/cmd/client@main

What did you see happen?

Server:

1: 54 bytes written, err=<nil>
2: 0 bytes written, err=readfrom tcp [::1]:8080->[::1]:48336: write tcp [::1]:8080->[::1]:48336: write: broken pipe
3: 54 bytes written, err=<nil>
4: 54 bytes written, err=<nil>
5: 54 bytes written, err=<nil>
6: 54 bytes written, err=<nil>
7: 54 bytes written, err=<nil>
8: 54 bytes written, err=<nil>
9: 54 bytes written, err=<nil>
10: 0 bytes written, err=readfrom tcp [::1]:8080->[::1]:33742: write tcp [::1]:8080->[::1]:33742: write: broken pipe

Client:

attempt 0
2024/07/26 16:17:17 Unsolicited response received on idle HTTP channel starting with "<!DOCTYPE html>\n<html>\n  <head>\n    <title>Thomas</tit"; err=<nil>
attempt 1
2024/07/26 16:17:17 Unsolicited response received on idle HTTP channel starting with "<!DOCTYPE html>\n<html>\n  <head>\n    <title>Thomas</tit"; err=<nil>
attempt 2
2024/07/26 16:17:17 Unsolicited response received on idle HTTP channel starting with "<!DOCTYPE html>\n<html>\n  <head>\n    <title>Thomas</tit"; err=<nil>
attempt 3
2024/07/26 16:17:17 Unsolicited response received on idle HTTP channel starting with "<!DOCTYPE html>\n<html>\n  <head>\n    <title>Thomas</tit"; err=<nil>
attempt 4
2024/07/26 16:17:17 Unsolicited response received on idle HTTP channel starting with "<!DOCTYPE html>\n<html>\n  <head>\n    <title>Thomas</tit"; err=<nil>
attempt 5
2024/07/26 16:17:17 Unsolicited response received on idle HTTP channel starting with "<!DOCTYPE html>\n<html>\n  <head>\n    <title>Thomas</tit"; err=<nil>
attempt 6
attempt 7
2024/07/26 16:17:18 do: Head "http://localhost:8080": net/http: HTTP/1.x transport connection broken: malformed HTTP status code "html>"
exit status 1

What did you expect to see?

There should be no Unsolicited response received on idle HTTP channel starting with messages, and the request should not fail with net/http: HTTP/1.x transport connection broken: malformed HTTP status code "html>".

Comment From: gabyhelp

Related Issues and Documentation

(Emoji vote if this was helpful or unhelpful; more detailed feedback welcome in this discussion.)

Comment From: uhthomas

https://github.com/golang/go/issues/19895 is one of the only matches for "Unsolicited response received on idle HTTP channel starting with" and claims the HTTP server to be misbehaving.

Comment From: seankhliao

Your server is indeed misbehaving by writing data when it receives a HEAD request.

Comment From: uhthomas

Sure, but it should not cause this sort of behavior at all. It's quite problematic, and inconsistent. Under many circumstances, there are no issues with writing a response to a HEAD request, even if it's wrong. It should not affect other connections to the server, which it does, and it should not leak data between connections, which it does. Please can this be reopened and considered more fairly?

Comment From: mvdan

@seankhliao where is that documented in the net/http docs? A quick skim doesn't show me anything, even if HEAD responses not containing a body could be common knowledge.

Assuming you're right about that assumption, I would imagine that calling Write on https://pkg.go.dev/net/http#ResponseWriter for a HEAD request should result in either a clear error or panic, and not anything like corruption or data races or confusing errors.

Comment From: terinjokes

To me the issue here looks like a Go HTTP client receiving a body in response to an HEAD request, and then the established HTTP/1.1 connection was reused for another request, where it tried to read the previously sent body as the start of the new response. This could happen regardless of the server implementation.

RFC 9110 section 9.3.2. recommends clients close and error when a HEAD response is received with a body to avoid request/response smuggling. Is that something we can consider here?

Comment From: seankhliao

looks like the client (transport) assumes a HEAD request never has a body https://go.googlesource.com/go/+/3959d54c0bd5c92fe0a5e33fedb0595723efc23b/src/net/http/transport.go#2245

cc @neild

Comment From: seankhliao

I suppose #62015 would be the corresponding issue for discarding the body from the server side

Comment From: uhthomas

Thanks for the additional input, and thank you for reopening.

Something I'd really like to understand is why this doesn't happen when writing data in-memory? I could only ever reproduce this when making a HTTP request on the server and writing it back to the client.

Comment From: neild

Some of the above is talking about a body in a HEAD request, and some is talking about a body in the response to a HEAD request. These are completely different things.

HEAD requests may contain a body, but the body has no defined semantics. (RFC 9110, section 9.3.2)

The response to a HEAD request does not contain a body. RFC 9112, section 6.3:

Any response to a HEAD request and any response with a 1xx (Informational), 204 (No Content), or 304 (Not Modified) status code is always terminated by the first empty line after the header fields, regardless of the header fields present in the message, and thus cannot contain a message body or trailer section.

Improperly writing a body leaves a connection in an invalid state, since the client is expecting the next bytes read to be the status line for the next request on the connection.

Thanks for the report, @uhthomas. This is a bug in net/http. The problem is that while an http.ResponseWriter normally discards the body for HEAD requests, ResponseWriter.ReadFrom fails to do so. Triggering this bug requires either calling ReadFrom directly, or using io.Copy to copy to a ResponseWriter from a source with no WriteTo method.

Comment From: uhthomas

@neild Ohh, that answers my previous question, thank you so much for the insight.

Comment From: seankhliao

Sorry, other than my mis-titling I think everything else was about bodies in the response to HEAD.

Should the client / transport need to defend against misbehaving servers?

Comment From: neild

The client does defend against misbehaving servers--that's the "Unsolicited response received on idle HTTP channel" error, which indicates that the server sent something unexpected. Perhaps the error message could be clearer; in this case the bytes read on the idle connection aren't a response,

It's not something that should show up often, though, because a server needs to be quite broken for this to happen.

Comment From: uhthomas

@neild Given this error on the client, I don't think it's doing a very good job of defending against this?

2024/07/26 16:17:18 do: Head "http://localhost:8080": net/http: HTTP/1.x transport connection broken: malformed HTTP status code "html>"

Comment From: neild

What do you think the client should have done in that case? It sent a request, and the server sent an invalid response (which happens to be the body of the previous response).

Comment From: gopherbot

Change https://go.dev/cl/601475 mentions this issue: net/http: don't write HEAD response body in ResponseWriter.ReadFrom

Comment From: terinjokes

In my testing the response was sent as part of the original request, so it was sent before the client sent a second request. As mentioned in https://github.com/golang/go/issues/68609#issuecomment-2253101627 I'd expect a reject and a connection close by the client.

Comment From: seankhliao

Perhaps around here the client could check if there was still buffered content and if so mark it as connection close? I'm guessing that if there was a body, chances of the current buffer having been exactly the header to be quite low.

Comment From: neild

The client will read the extra data and close the connection (that's the "Unsolicited response..." error). If the client is immediately sending another request on the connection, there's a race condition between seeing the extra data and sending the next request.

I don't think it's worth trying to detect this, because there will still be a race condition--there's no way to assert "the server didn't send us anything", because the data it improperly sent might still be in flight. And this only comes up if a server is completely broken. (Which, alas, net/http is.)

chances of the current buffer having been exactly the header to be quite low.

Seems fairly likely to me; it's not uncommon for a server to send headers in one packet and the body in another. In fact, that's exactly what the reproduction case here is doing (flush headers, then copy body).

Comment From: uhthomas

I think given http.Client is used for reverse proxies, and may be connecting to untrusted servers, we should exercise caution and do the right thing here.

Comment From: uhthomas

Some quick data on how often these messages occur in a real environment (time range of 2 days).

Screenshot 2024-07-27 at 01 54 57

Screenshot 2024-07-27 at 01 53 28

Comment From: uhthomas

I tried a couple of things in an attempt to simplify my original reproducer and found that I cannot reproduce the net/http: HTTP/1.x transport connection broken: malformed HTTP status code message, only Unsolicited response received on idle HTTP channel starting with with this:

if rf, ok := w.(io.ReaderFrom); ok {
    n, err := rf.ReadFrom(io.LimitReader(rand.Reader, 1<<10))
    fmt.Printf("%d: %d bytes written, err=%v\n", requestID, n, err)
    return
}

It does however produce the message instantly with:

res, err := http.Get("https://go.dev")
if err != nil {
    panic(err)
}

if rf, ok := w.(io.ReaderFrom); ok {
    n, err := rf.ReadFrom(res.Body)
    fmt.Printf("%d: %d bytes written, err=%v\n", requestID, n, err)
    return
}

Any ideas on why that could be the case?

I also now understand why I couldn't reproduce it with this snippet:

io.Copy(w, strings.NewReader(strings.Repeat("some string", 10)))

*strings.Reader implements io.WriterTo, which has precedence over io.ReaderFrom.

Comment From: uhthomas

@neild Should we reopen this to track work in the HTTP client / transport? I really feel it should be a bit more defensive.

Comment From: uhthomas

I've raised #68653 to track the HTTP client.