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: Transport hangs on malformed response headers #16572

Closed
icing opened this issue Aug 2, 2016 · 35 comments
Closed

x/net/http2: Transport hangs on malformed response headers #16572

icing opened this issue Aug 2, 2016 · 35 comments

Comments

@icing
Copy link

icing commented Aug 2, 2016

Please answer these questions before submitting your issue. Thanks!

  1. What version of Go are you using (go version)?
    go1.7rc4
  2. What operating system and processor architecture are you using (go env)?
    OS X ( 15.6.0 Darwin Kernel Version 15.6.0: Thu Jun 23 18:25:34 PDT 2016; root:xnu-3248.60.10~1/RELEASE_X86_64 x86_64)
  3. What did you do?
    Tested the http2 implementation of go against Apache mod_h2, using a simple GET on a python CGI.
  4. What did you expect to see?
    The output from the CGI.
  5. What did you see instead?
    Go did hang and did not produce any results. The difference between a stuck GET and a successful one seems to be the EOF handling. On most responses Apache sets the EOF flag on the last DATA frame. However with CGI processes, the EOF is only encountered when the last DATA has already been written. In this case, Apache send a last DATA frame with length 0 and EOF=1. This seems to be ignored by the go implemenation, keeping it waiting.

Additionally to that, Apache will close the connection after a timeout, but the go client still will not return although the connection was properly closed.

@Lukasa
Copy link

Lukasa commented Aug 2, 2016

@icing Hmm, let me add some detail to this. Running the same version of Go on a different OS (go version gives go version go1.7rc4 linux/amd64), and hitting https://shootout.lukasa.co.uk/.well-known/h2interop/state, I get the following debug output:

root@72cc5ec48c33:/usr/src/myapp# env GODEBUG=http2debug=2 go run main.go
2016/08/02 13:44:36 http2: Transport failed to get client conn for shootout.lukasa.co.uk:443: http2: no cached connection was available
2016/08/02 13:44:36 http2: Transport creating client conn to 139.59.179.124:443
2016/08/02 13:44:36 http2: Framer 0xc420300e40: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2016/08/02 13:44:36 http2: Framer 0xc420300e40: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2016/08/02 13:44:36 http2: Transport encoding header ":authority" = "shootout.lukasa.co.uk"
2016/08/02 13:44:36 http2: Transport encoding header ":method" = "GET"
2016/08/02 13:44:36 http2: Transport encoding header ":path" = "/.well-known/h2interop/state"
2016/08/02 13:44:36 http2: Transport encoding header ":scheme" = "https"
2016/08/02 13:44:36 http2: Transport encoding header "accept-encoding" = "gzip"
2016/08/02 13:44:36 http2: Transport encoding header "user-agent" = "Go-http-client/2.0"
2016/08/02 13:44:36 http2: Framer 0xc420300e40: wrote HEADERS flags=END_STREAM|END_HEADERS stream=1 len=61
2016/08/02 13:44:36 http2: Framer 0xc420300e40: read SETTINGS len=30, settings: HEADER_TABLE_SIZE=4096, ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=65535, MAX_FRAME_SIZE=16384, MAX_CONCURRENT_STREAMS=100
2016/08/02 13:44:36 http2: Transport received SETTINGS len=30, settings: HEADER_TABLE_SIZE=4096, ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=65535, MAX_FRAME_SIZE=16384, MAX_CONCURRENT_STREAMS=100
2016/08/02 13:44:36 Unhandled Setting: [HEADER_TABLE_SIZE = 4096]
2016/08/02 13:44:36 Unhandled Setting: [ENABLE_PUSH = 0]
2016/08/02 13:44:36 http2: Framer 0xc420300e40: wrote SETTINGS flags=ACK len=0
2016/08/02 13:44:36 http2: Framer 0xc420300e40: read SETTINGS flags=ACK len=0
2016/08/02 13:44:36 http2: Transport received SETTINGS flags=ACK len=0
2016/08/02 13:44:36 http2: Framer 0xc420300e40: read HEADERS flags=END_HEADERS stream=1 len=98
2016/08/02 13:44:36 http2: Transport received HEADERS flags=END_HEADERS stream=1 len=98
2016/08/02 13:44:36 http2: Framer 0xc420300e40: read DATA stream=1 len=1370 data="{\n    \"threads\": 1, \n    \"settings\": {\n        \"SETTINGS_HEADER_TABLE_SIZE\": 4096, \n        \"SETTINGS_ENABLE_PUSH\": 0, \n        \"SETTINGS_INITIAL_WINDOW_SIZE\": 65535, \n        \"SETTINGS_MAX_FRAME_SIZE\": 16384, \n        \"SETTINGS_MAX_CONCURRENT_STREAMS\": 10" (1114 bytes omitted)
2016/08/02 13:44:36 http2: Transport received DATA stream=1 len=1370 data="{\n    \"threads\": 1, \n    \"settings\": {\n        \"SETTINGS_HEADER_TABLE_SIZE\": 4096, \n        \"SETTINGS_ENABLE_PUSH\": 0, \n        \"SETTINGS_INITIAL_WINDOW_SIZE\": 65535, \n        \"SETTINGS_MAX_FRAME_SIZE\": 16384, \n        \"SETTINGS_MAX_CONCURRENT_STREAMS\": 10" (1114 bytes omitted)
2016/08/02 13:44:36 http2: Framer 0xc420300e40: read DATA flags=END_STREAM stream=1 len=0 data=""
2016/08/02 13:44:36 http2: Transport received DATA flags=END_STREAM stream=1 len=0 data=""
{
    "threads": 1, 
    "settings": {
        "SETTINGS_HEADER_TABLE_SIZE": 4096, 
        "SETTINGS_ENABLE_PUSH": 0, 
        "SETTINGS_INITIAL_WINDOW_SIZE": 65535, 
        "SETTINGS_MAX_FRAME_SIZE": 16384, 
        "SETTINGS_MAX_CONCURRENT_STREAMS": 100
    }, 
    "peerSettings": {
        "SETTINGS_HEADER_TABLE_SIZE": 4096, 
        "SETTINGS_ENABLE_PUSH": 0, 
        "SETTINGS_INITIAL_WINDOW_SIZE": 4194304, 
        "SETTINGS_MAX_FRAME_SIZE": 16384, 
        "SETTINGS_MAX_CONCURRENT_STREAMS": 4294967297
    }, 
    "sentGoAway": false, 
    "connFlowOut": 1073807359, 
    "connFlowIn": 65535, 
    "maxSeenStreamID": 1, 
    "streams": {
        "1": {
            "state": "HALF_CLOSED_REMOTE", 
            "flowIn": 65535, 
            "flowOut": 4194304
        }
    }, 
    "hpack": {
        "inbound_table_size": 239, 
        "inbound_dynamic_header_table": [
            [
                "user-agent", 
                "Go-http-client/2.0"
            ], 
            [
                "accept-encoding", 
                "gzip"
            ], 
            [
                ":path", 
                "/.well-known/h2interop/state"
            ], 
            [
                ":authority", 
                "shootout.lukasa.co.uk"
            ]
        ], 
        "outbound_table_size": 0, 
        "outbound_dynamic_header_table": []
    }

This output shows Go receiving an END_STREAM on a empty DATA frame and producing the output regardless.

Do you have the output with the GODEBUG=http2debug=2 environment variable set?

@bradfitz
Copy link
Contributor

bradfitz commented Aug 2, 2016

Yeah, I can't reproduce. And the code looks fine, and we have tests for this, too.

@icing, the GODEBUG=http2debug=2 output would be super helpful. Thanks!

@bradfitz bradfitz added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Aug 2, 2016
@bradfitz bradfitz changed the title go http2 client sometimes hangs on GET looking for EOF x/net/http2: Transport sometimes hangs on GET against Apache CGI? Aug 2, 2016
@icing
Copy link
Author

icing commented Aug 2, 2016

Hmm, interesting...

2016/08/02 15:50:20 http2: Transport creating client conn to 127.0.0.1:12346
2016/08/02 15:50:20 http2: Framer 0xc4201d8fc0: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2016/08/02 15:50:20 http2: Framer 0xc4201d8fc0: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2016/08/02 15:50:20 http2: Framer 0xc4201d8fc0: read SETTINGS len=6, settings: MAX_CONCURRENT_STREAMS=100
2016/08/02 15:50:20 http2: Framer 0xc4201d8fc0: wrote SETTINGS flags=ACK len=0
2016/08/02 15:50:20 http2: Transport encoding header ":authority" = "test.example.org:12346"
2016/08/02 15:50:20 http2: Transport encoding header ":method" = "GET"
2016/08/02 15:50:20 http2: Transport encoding header ":path" = "/upload.py"
2016/08/02 15:50:20 http2: Transport encoding header ":scheme" = "https"
2016/08/02 15:50:20 http2: Transport encoding header "accept-encoding" = "gzip"
2016/08/02 15:50:20 http2: Transport encoding header "user-agent" = "Go-http-client/2.0"
2016/08/02 15:50:20 http2: Framer 0xc4201d8fc0: wrote HEADERS flags=END_STREAM|END_HEADERS stream=1 len=50
2016/08/02 15:50:20 http2: Framer 0xc4201d8fc0: read WINDOW_UPDATE len=4 (conn) incr=2147418112
2016/08/02 15:50:20 http2: Transport received WINDOW_UPDATE len=4 (conn) incr=2147418112
2016/08/02 15:50:20 http2: Framer 0xc4201d8fc0: read SETTINGS flags=ACK len=0
2016/08/02 15:50:20 http2: Transport received SETTINGS flags=ACK len=0
2016/08/02 15:50:20 http2: Framer 0xc4201d8fc0: read HEADERS flags=END_HEADERS stream=1 len=78
2016/08/02 15:50:20 Transport readFrame error: (http2.StreamError) stream error: stream ID 1; PROTOCOL_ERROR
2016/08/02 15:50:20 http2: Framer 0xc4201d8fc0: read DATA stream=1 len=219 data="    <html><body>\n    <p>        Upload File<form method=\"POST\" enctype=\"multipart/form-data\">\n        <input type=\"file\" name=\"file\">\n        <button type=\"submit\">Upload</button></form>\n        </p>\n    </body></html>\n"
2016/08/02 15:50:20 http2: Transport received DATA stream=1 len=219 data="    <html><body>\n    <p>        Upload File<form method=\"POST\" enctype=\"multipart/form-data\">\n        <input type=\"file\" name=\"file\">\n        <button type=\"submit\">Upload</button></form>\n        </p>\n    </body></html>\n"
2016/08/02 15:50:20 http2: Framer 0xc4201d8fc0: read DATA flags=END_STREAM stream=1 len=0 data=""
2016/08/02 15:50:20 http2: Transport received DATA flags=END_STREAM stream=1 len=0 data=""
2016/08/02 15:50:30 http2: Framer 0xc4201d8fc0: read GOAWAY len=15 LastStreamID=1 ErrCode=NO_ERROR Debug="timeout"
2016/08/02 15:50:30 http2: Transport received GOAWAY len=15 LastStreamID=1 ErrCode=NO_ERROR Debug="timeout"
2016/08/02 15:50:30 Transport readFrame error: (*errors.errorString) EOF

The same GET with curl:

curl -k https://test.example.org:12346/upload.py -O

produces

-rw-r--r--+  1 xxx  xxxx     219  2 Aug 15:52 upload.py

@icing
Copy link
Author

icing commented Aug 2, 2016

How nghttp client sees it:

nghttp -vvvv https://test.example.org:12346/upload.py
[  0.002] Connected
The negotiated protocol: h2
[  0.012] recv SETTINGS frame <length=6, flags=0x00, stream_id=0>
          (niv=1)
          [SETTINGS_MAX_CONCURRENT_STREAMS(0x03):100]
[  0.012] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
          (window_size_increment=2147418112)
[  0.012] send SETTINGS frame <length=12, flags=0x00, stream_id=0>
          (niv=2)
          [SETTINGS_MAX_CONCURRENT_STREAMS(0x03):100]
          [SETTINGS_INITIAL_WINDOW_SIZE(0x04):65535]
[  0.012] send SETTINGS frame <length=0, flags=0x01, stream_id=0>
          ; ACK
          (niv=0)
[  0.012] send PRIORITY frame <length=5, flags=0x00, stream_id=3>
          (dep_stream_id=0, weight=201, exclusive=0)
[  0.012] send PRIORITY frame <length=5, flags=0x00, stream_id=5>
          (dep_stream_id=0, weight=101, exclusive=0)
[  0.012] send PRIORITY frame <length=5, flags=0x00, stream_id=7>
          (dep_stream_id=0, weight=1, exclusive=0)
[  0.012] send PRIORITY frame <length=5, flags=0x00, stream_id=9>
          (dep_stream_id=7, weight=1, exclusive=0)
[  0.012] send PRIORITY frame <length=5, flags=0x00, stream_id=11>
          (dep_stream_id=3, weight=1, exclusive=0)
[  0.012] send HEADERS frame <length=53, flags=0x25, stream_id=13>
          ; END_STREAM | END_HEADERS | PRIORITY
          (padlen=0, dep_stream_id=11, weight=16, exclusive=0)
          ; Open new stream
          :method: GET
          :path: /upload.py
          :scheme: https
          :authority: test.example.org:12346
          accept: */*
          accept-encoding: gzip, deflate
          user-agent: nghttp2/1.9.1
[  0.012] recv SETTINGS frame <length=0, flags=0x01, stream_id=0>
          ; ACK
          (niv=0)
[  0.076] recv (stream_id=13) :status: 200
[  0.076] recv (stream_id=13) date: Tue, 02 Aug 2016 13:57:33 GMT
[  0.076] recv (stream_id=13) server: Apache/2.5.0-dev (Unix) OpenSSL/1.0.2g
[  0.076] recv HEADERS frame <length=78, flags=0x04, stream_id=13>
          ; END_HEADERS
          (padlen=0)
          ; First response header
[  0.076] recv (stream_id=13, length=219, srecv=219, crecv=219) DATA
    <html><body>
    <p>        Upload File<form method="POST" enctype="multipart/form-data">
        <input type="file" name="file">
        <button type="submit">Upload</button></form>
        </p>
    </body></html>
[  0.076] recv DATA frame <length=219, flags=0x00, stream_id=13>
[  0.076] recv DATA frame <length=0, flags=0x01, stream_id=13>
          ; END_STREAM
[  0.076] send GOAWAY frame <length=8, flags=0x00, stream_id=0>
          (last_stream_id=0, error_code=NO_ERROR(0x00), opaque_data(0)=[])

@Lukasa
Copy link

Lukasa commented Aug 2, 2016

There looks like an error happening when Go is receiving your HEADERS frame. Something in the validation code seems confused.

@icing
Copy link
Author

icing commented Aug 2, 2016

Correct, error is reported before DATA is read. Hmm. Let me know if I can provide anything else useful.

@bradfitz
Copy link
Contributor

bradfitz commented Aug 2, 2016

Yeah, it doesn't like your headers. I've mailed out https://go-review.googlesource.com/25401 to add more logging about why.

Can you patch that in? The relevant diff is:

diff --git a/http2/frame.go b/http2/frame.go
index bd50d09..6769907 100644
--- a/http2/frame.go
+++ b/http2/frame.go
@@ -1419,6 +1419,9 @@ func (fr *Framer) readMetaFrame(hf *HeadersFrame) (*MetaHeadersFrame, error) {
        hdec.SetEmitEnabled(true)
        hdec.SetMaxStringLength(fr.maxHeaderStringLen())
        hdec.SetEmitFunc(func(hf hpack.HeaderField) {
+               if VerboseLogs && logFrameReads {
+                       log.Printf("http2: decoded hpack field %+v", hf)
+               }
                if !httplex.ValidHeaderFieldValue(hf.Value) {
                        invalid = headerFieldValueError(hf.Value)
                }
@@ -1477,10 +1480,16 @@ func (fr *Framer) readMetaFrame(hf *HeadersFrame) (*MetaHeadersFrame, error) {
        }
        if invalid != nil {
                fr.errDetail = invalid
+               if VerboseLogs {
+                       log.Printf("http2: invalid header: %v", invalid)
+               }
                return nil, StreamError{mh.StreamID, ErrCodeProtocol}
        }
        if err := mh.checkPseudos(); err != nil {
                fr.errDetail = err
+               if VerboseLogs {
+                       log.Printf("http2: invalid pseudo headers: %v", err)
+               }
                return nil, StreamError{mh.StreamID, ErrCodeProtocol}
        }
        return mh, nil

I have an Apache mod_h2 docker container now, though, but without CGI. I'll try and reproduce too.

@icing
Copy link
Author

icing commented Aug 2, 2016

I am using the prebuilt package for rc4. Can I get that in without building go locally? (gonoob)

gopherbot pushed a commit to golang/net that referenced this issue Aug 2, 2016
To help debug golang/go#16572

Change-Id: Ia154faedd243a06a4110f6e6a4885b7cd0a04e1f
Reviewed-on: https://go-review.googlesource.com/25401
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
@bradfitz
Copy link
Contributor

bradfitz commented Aug 2, 2016

@icing, I just submitted it. You can now run:

$ go get -u golang.org/x/net/http2

And then re-run your client program. (using code that looks like #16519 (comment))

@bradfitz
Copy link
Contributor

bradfitz commented Aug 2, 2016

(That is, you can keep using the prebuilt rc4 package, but don't use its built-in copy of http2, use the golang.org/x/net/http2 one.... think of those as mod_http2 vs mod_h2, respectively)

@icing
Copy link
Author

icing commented Aug 2, 2016

Of course, the problem lies in the python code... ^^

GODEBUG=http2debug=2 go run test/go/get.go https://test.example.org:12346/upload.py
2016/08/02 16:31:43 http2: Transport creating client conn to 127.0.0.1:12346
2016/08/02 16:31:43 http2: Framer 0xc4201c4fc0: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2016/08/02 16:31:43 http2: Framer 0xc4201c4fc0: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2016/08/02 16:31:43 http2: Transport encoding header ":authority" = "test.example.org:12346"
2016/08/02 16:31:43 http2: Transport encoding header ":method" = "GET"
2016/08/02 16:31:43 http2: Transport encoding header ":path" = "/upload.py"
2016/08/02 16:31:43 http2: Transport encoding header ":scheme" = "https"
2016/08/02 16:31:43 http2: Transport encoding header "accept-encoding" = "gzip"
2016/08/02 16:31:43 http2: Transport encoding header "user-agent" = "Go-http-client/2.0"
2016/08/02 16:31:43 http2: Framer 0xc4201c4fc0: read SETTINGS len=6, settings: MAX_CONCURRENT_STREAMS=100
2016/08/02 16:31:43 http2: Framer 0xc4201c4fc0: wrote HEADERS flags=END_STREAM|END_HEADERS stream=1 len=50
2016/08/02 16:31:43 http2: Transport received SETTINGS len=6, settings: MAX_CONCURRENT_STREAMS=100
2016/08/02 16:31:43 http2: Framer 0xc4201c4fc0: wrote SETTINGS flags=ACK len=0
2016/08/02 16:31:43 http2: Framer 0xc4201c4fc0: read WINDOW_UPDATE len=4 (conn) incr=2147418112
2016/08/02 16:31:43 http2: Transport received WINDOW_UPDATE len=4 (conn) incr=2147418112
2016/08/02 16:31:43 http2: Framer 0xc4201c4fc0: read SETTINGS flags=ACK len=0
2016/08/02 16:31:43 http2: Transport received SETTINGS flags=ACK len=0
2016/08/02 16:31:43 http2: Framer 0xc4201c4fc0: read HEADERS flags=END_HEADERS stream=1 len=78
2016/08/02 16:31:43 http2: decoded hpack field header field ":status" = "200"
2016/08/02 16:31:43 http2: decoded hpack field header field "date" = "Tue, 02 Aug 2016 14:31:43 GMT"
2016/08/02 16:31:43 http2: decoded hpack field header field "server" = "Apache/2.5.0-dev (Unix) OpenSSL/1.0.2g"
2016/08/02 16:31:43 http2: decoded hpack field header field "    content-type" = "text/html"
2016/08/02 16:31:43 http2: invalid header: invalid header field name "    content-type"
2016/08/02 16:31:43 Transport readFrame error: (http2.StreamError) stream error: stream ID 1; PROTOCOL_ERROR
2016/08/02 16:31:43 http2: Framer 0xc4201c4fc0: read DATA stream=1 len=219 data="    <html><body>\n    <p>        Upload File<form method=\"POST\" enctype=\"multipart/form-data\">\n        <input type=\"file\" name=\"file\">\n        <button type=\"submit\">Upload</button></form>\n        </p>\n    </body></html>\n"
2016/08/02 16:31:43 http2: Transport received DATA stream=1 len=219 data="    <html><body>\n    <p>        Upload File<form method=\"POST\" enctype=\"multipart/form-data\">\n        <input type=\"file\" name=\"file\">\n        <button type=\"submit\">Upload</button></form>\n        </p>\n    </body></html>\n"
2016/08/02 16:31:43 http2: Framer 0xc4201c4fc0: wrote WINDOW_UPDATE len=4 (conn) incr=219
2016/08/02 16:31:43 http2: Framer 0xc4201c4fc0: read DATA flags=END_STREAM stream=1 len=0 data=""
2016/08/02 16:31:43 http2: Transport received DATA flags=END_STREAM stream=1 len=0 data=""

If I remove the leading space from the content-type header, go is fine with it.

Interestingly, nghttp seems to just silently omit this header and report nothing suspicious. Another reason to test with different clients...

I think the choking by go on such headers is just fine. I'll add an issue for mod_h2 to trim headers before sending them on a h2 stream, since they might come from unreliable sources, such as a python script...

@icing
Copy link
Author

icing commented Aug 2, 2016

Sorry for all the excitement.

@tatsuhiro-t
Copy link

The reason why nghttp2 ignores these header fields is that there are so many misguided header field in the internet, and just treating them hard error breaks web browsing if nghttp2 is used as forward proxy.

@tatsuhiro-t
Copy link

There is still problem here. Go client just hangs in this case. It should terminate stream, or connection instead of freezing.

@bradfitz
Copy link
Contributor

bradfitz commented Aug 2, 2016

The reason why nghttp2 ignores these header fields is that there are so many misguided header field in the internet, and just treating them hard error breaks web browsing if nghttp2 is used as forward proxy.

I think that's kinda wrong. Misguided header fields can only exist on the Internet if too-forgiving implementations allow them to exist. And so far that's only been the case for often-ill-defined HTTP/1. With HTTP/2 we get a clean start with defined rules. I think we should follow the rules, and make it the job of the HTTP/1<->HTTP/2 proxies to make the policies decisions on what to strip. But on the wire, HTTP/2 is clear about what is permitted.

There is still problem here. Go client just hangs in this case. It should terminate stream, or connection instead of freezing.

Indeed. I'm looking into that now. The stream error should be reported to the user.

@Lukasa
Copy link

Lukasa commented Aug 2, 2016

Agreed with @tatsuhiro-t here: not only should the stream error be reported to the user, but a RST_STREAM frame should be emitted, which it isn't being.

@icing
Copy link
Author

icing commented Aug 2, 2016

@tatsuhiro-t whatever the proxy does, it would be good if the library, by default, will not accept such headers. The decision to discard/trim/fail on such headers should be done by the user of nghttp2, IMHO.

@tatsuhiro-t
Copy link

I think that's kinda wrong. Misguided header fields can only exist on the Internet if too-forgiving implementations allow them to exist. And so far that's only been the case for often-ill-defined HTTP/1. With HTTP/2 we get a clean start with defined rules. I think we should follow the rules, and make it the job of the HTTP/1<->HTTP/2 proxies to make the policies decisions on what to strip. But on the wire, HTTP/2 is clear about what is permitted.

Well, probably I had few words ,but I totally agree with you. And what nghttp2 does is what you described. The bad header field is just ignored and stripped.

@icing
Copy link
Author

icing commented Aug 2, 2016

I think it is not stripped, but sent onwards to the poor go client. ;-)

@bradfitz
Copy link
Contributor

bradfitz commented Aug 2, 2016

Well, probably I had few words ,but I totally agree with you. And what nghttp2 does is what you described. The bad header field is just ignored and stripped.

That's not what it sounds like. I disagree it should be ignored and stripped. I think it should be an error, as it's not a valid HTTP header field.

The HTTP/2 spec references the HTTP/1 spec which says a header-field is a token and token is https://tools.ietf.org/html/rfc7230#section-3.2.6 which doesn't include spaces.

@tatsuhiro-t
Copy link

@icing Stripping header is occurred when nghttp2 received header fields. For transmission, nghttp2 does not check header fields, and rather it is application's job to make sure that header is all right. We decided to do this because application most likely validates what it sends, and validating them in nghttp2 could be redundant. But I'm ok to add those checks to nghttp2.

@icing
Copy link
Author

icing commented Aug 2, 2016

@tatsuhiro-t it would be nice and lazy people like myself, who do not check enough, find out earlier.

@tatsuhiro-t
Copy link

@bradfitz I'd like to make it error.. but when we deployed HTTP/2 forward proxy on public internet, I occasionally hit those sites that send invalid header fields, and they just stop working if we make it error and tear down the stream.

@tatsuhiro-t
Copy link

@icing Right, let's discuss it in nghttp2 issue thread

@Lukasa
Copy link

Lukasa commented Aug 2, 2016

It could be optional: hyper-h2 is growing flags that will let users optionally turn off header validation, but it defaults to "strict". nghttp2 could do this as well.

@bradfitz
Copy link
Contributor

bradfitz commented Aug 2, 2016

@tatsuhiro-t, then nghttp2 is part of the problem, if you saw that garbage on h2, since it contributes to the idea that garbage is okay. If you only saw the garbage on h1, then it's the proxy's job to clean or ignore things before translation to h2. Where is the nghttp2 bug?

@icing
Copy link
Author

icing commented Aug 2, 2016

Well, let's stay constructive. I think we all start testing more interop between different implementations and that is a good thing. I am about to add go version >= 1.7 tests to my regression tests and would like to add hyper too.

If a public facing Apache mod_h2 with some trivial config would help you, let me know. Can be arranged.

@bradfitz
Copy link
Contributor

bradfitz commented Aug 2, 2016

Yeah, I want to do more interop testing too. I'll start a separate thread.

I've fixed this Go issue in https://golang.org/cl/25402

@tatsuhiro-t
Copy link

I also have a patch for nghttp2 to reproduce this issue 100%, and the proposed patch fixed this hanging issue. Thank you.

@gopherbot
Copy link

CL https://golang.org/cl/25402 mentions this issue.

@bradfitz
Copy link
Contributor

bradfitz commented Aug 2, 2016

Well, let's stay constructive.

Sorry, I didn't mean to be come across as adversarial or disparage either @tatsuhiro-t or nghttp2. I was just trying to argue the point that if a protocol is new and is trying to be strict (as HTTP/2 is, especially compared to super-sloppy HTTP/1), implementations of the protocol must also be super strict, especially in the early days, otherwise all the strict wording in the spec is useless and a de-facto reality emerges and all of our implementations will forever have to deal with everybody's corner cases. And I don't think we would enjoy that.

I haven't looked at the nghttp2 or Apache APIs and where the responsibility boundaries are, but I'm just very anxious about the idea of a library deciding to hide garbage from upper layers, when the garbage is specified in the specs as illegal.

Go's http2 package is strict by default, but the Framer has AllowIllegalReads and AllowIllegalWrites (https://godoc.org/golang.org/x/net/http2#Framer) specifically to allow people to write testing tools to generate and accept garbage. But we never hide garbage from the user. We just return errors instead, hoping that causes push-back to the other side to be stricter.

@icing
Copy link
Author

icing commented Aug 2, 2016

Totally agree. mod_h2 has to translate between the worlds as there is tons of legacy stuff out there running in the server and it needs to be more strict in that.

Am 02.08.2016 um 18:57 schrieb Brad Fitzpatrick notifications@github.com:

Well, let's stay constructive.

Sorry, I didn't mean to be come across as adversarial or disparage either @tatsuhiro-t or nghttp2. I was just trying to argue the point that if a protocol is new and is trying to be strict (as HTTP/2 is, especially compared to super-sloppy HTTP/1), implementations of the protocol must also be super strict, especially in the early days, otherwise all the strict wording in the spec is useless and a de-facto reality emerges and all of our implementations will forever have to deal with everybody's corner cases. And I don't think we would enjoy that.

I haven't looked at the nghttp2 or Apache APIs and where the responsibility boundaries are, but I'm just very anxious about the idea of a library deciding to hide garbage from upper layers, when the garbage is specified in the specs as illegal.

Go's http2 package is strict by default, but the Framer has AllowIllegalReads and AllowIllegalWrites (https://godoc.org/golang.org/x/net/http2#Framer) specifically to allow people to write testing tools to generate and accept garbage. But we never hide garbage from the user. We just return errors instead, hoping that causes push-back to the other side to be stricter.


You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub, or mute the thread.

@tatsuhiro-t
Copy link

Never mind, and I understand that my argument for interoperability for bad header is poor because HTTP/2 implementation is brand-new anyway, and I was probably confused by the late night, sorry about that.

Anyway, the discussion is valuable for me, and give me a good insight that the header field handling of nghttp2 could be improved. I created issue nghttp2/nghttp2#642 to review our current behaviour, and we could go with zero tolerance rule. Probably, the best thing as library is give a choice for the application about how to handle these headers. Will see.

Thank you.

@bradfitz
Copy link
Contributor

bradfitz commented Aug 2, 2016

@Lukasa,

Agreed with @tatsuhiro-t here: not only should the stream error be reported to the user, but a RST_STREAM frame should be emitted, which it isn't being.

Done. The change (currently out for review) now sends RST_STREAM back in this case too, with new tests.

@bradfitz bradfitz removed the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Aug 2, 2016
@bradfitz bradfitz self-assigned this Aug 2, 2016
@bradfitz bradfitz added this to the Unreleased milestone Aug 2, 2016
@bradfitz bradfitz changed the title x/net/http2: Transport sometimes hangs on GET against Apache CGI? x/net/http2: Transport hangs on malformed response headers Aug 2, 2016
@Lukasa
Copy link

Lukasa commented Aug 2, 2016

Nice! 🍪

@golang golang locked and limited conversation to collaborators Aug 3, 2017
c3mb0 pushed a commit to c3mb0/net that referenced this issue Apr 2, 2018
If the Transport got a stream error on the response headers, it was
never unblocking the client. Previously, Response.Body reads would be
aborted with the stream error, but RoundTrip itself would never
unblock.

The Transport now also sends a RST_STREAM to the server when we
encounter a stream error.

Also, add a "Cause" field to StreamError with additional detail. The
old code was just returning the detail, without the stream error
header.

Fixes golang/go#16572

Change-Id: Ibecedb5779f17bf98c32787b68eb8a9b850833b3
Reviewed-on: https://go-review.googlesource.com/25402
Run-TryBot: Brad Fitzpatrick <bradfitz@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Andrew Gerrand <adg@golang.org>
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

5 participants