net/http/httputil: ReverseProxy fails to proxy h2c

[jaricftw]

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

$ go version
go1.12.7 darwin/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
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/jzhan/Library/Caches/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/jzhan/gocode"
GOPROXY=""
GORACE=""
GOROOT="/usr/local/Cellar/go/1.12.7/libexec"
GOTMPDIR=""
GOTOOLDIR="/usr/local/Cellar/go/1.12.7/libexec/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD=""
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 -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/ks/z0q9byf97yl5jmf11cj3dyvw0000gn/T/go-build934546059=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

I am trying to test the behavior of h2c forwarding using httputil.Reverseproxy.

Wrote a repro-test: https://github.com/jaricftw/go-http2-reverseproxy/blob/master/http2_test.go#L25, which tests:
1). h2c client -> h2c Server
2). h2c client -> httputil.Reverseproxy -> h2c Server

What did you expect to see?

Both tests pass

What did you see instead?

1. passes
2. always fails with error:

Get http://127.0.0.1:17777: read tcp 127.0.0.1:63779->127.0.0.1:17777: read: connection reset by peer

or

Get http://127.0.0.1:17777: unexpected EOF

With GODEBUG=http2debug=2 set:

~ go-http2-reverseproxy $ GODEBUG=http2debug=2 go test -v -run  TestHTTP2/via_proxy
=== RUN   TestHTTP2
=== RUN   TestHTTP2/via_proxy
2019/08/03 22:46:08 http2: Transport creating client conn 0xc000001500 to 127.0.0.1:17777
2019/08/03 22:46:08 http2: Framer 0xc0001a0000: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2019/08/03 22:46:08 http2: Framer 0xc0001a0000: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2019/08/03 22:46:08 http2: Transport encoding header ":authority" = "127.0.0.1:17777"
2019/08/03 22:46:08 http2: Transport encoding header ":method" = "GET"
2019/08/03 22:46:08 http2: Transport encoding header ":path" = "/"
2019/08/03 22:46:08 http2: Transport encoding header ":scheme" = "http"
2019/08/03 22:46:08 http2: Transport encoding header "accept-encoding" = "gzip"
2019/08/03 22:46:08 http2: Transport encoding header "user-agent" = "Go-http-client/2.0"
2019/08/03 22:46:08 http2: Framer 0xc0001a0000: wrote HEADERS flags=END_STREAM|END_HEADERS stream=3 len=36
2019/08/03 22:46:08 http2: Transport creating client conn 0xc000083b00 to 127.0.0.1:7777
2019/08/03 22:46:08 http2: Framer 0xc0001a01c0: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2019/08/03 22:46:08 http2: Framer 0xc0001a01c0: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2019/08/03 22:46:08 http2: Transport encoding header ":authority" = "localhost:7777"
2019/08/03 22:46:08 http2: Transport encoding header ":method" = "PRI"
2019/08/03 22:46:08 http2: Transport encoding header ":path" = "/%2A"
2019/08/03 22:46:08 http2: Transport encoding header ":scheme" = "http"
2019/08/03 22:46:08 http2: Transport encoding header "x-forwarded-for" = "127.0.0.1"
2019/08/03 22:46:08 http2: Transport encoding header "accept-encoding" = "gzip"
2019/08/03 22:46:08 h2c: attempting h2c with prior knowledge.
2019/08/03 22:46:08 http2: Framer 0xc0001a01c0: wrote HEADERS flags=END_STREAM|END_HEADERS stream=3 len=49
2019/08/03 22:46:08 http2: server connection from 127.0.0.1:63832 on 0xc0001f40d0
2019/08/03 22:46:08 http2: Framer 0xc0001fe000: wrote SETTINGS len=24, settings: MAX_FRAME_SIZE=1048576, MAX_CONCURRENT_STREAMS=250, MAX_HEADER_LIST_SIZE=1048896, INITIAL_WINDOW_SIZE=1048576
2019/08/03 22:46:08 http2: server: client 127.0.0.1:63832 said hello
2019/08/03 22:46:08 http2: Framer 0xc0001fe000: wrote WINDOW_UPDATE len=4 (conn) incr=983041
2019/08/03 22:46:08 http2: Framer 0xc0001a01c0: read SETTINGS len=24, settings: MAX_FRAME_SIZE=1048576, MAX_CONCURRENT_STREAMS=250, MAX_HEADER_LIST_SIZE=1048896, INITIAL_WINDOW_SIZE=1048576
2019/08/03 22:46:08 http2: server: client 127.0.0.1:63832 said hello
2019/08/03 22:46:08 http2: Framer 0xc0001fe000: wrote WINDOW_UPDATE len=4 (conn) incr=983041
2019/08/03 22:46:08 http2: Framer 0xc0001a01c0: read SETTINGS len=24, settings: MAX_FRAME_SIZE=1048576, MAX_CONCURRENT_STREAMS=250, MAX_HEADER_LIST_SIZE=1048896, INITIAL_WINDOW_SIZE=1048576
2019/08/03 22:46:08 http2: Transport received SETTINGS len=24, settings: MAX_FRAME_SIZE=1048576, MAX_CONCURRENT_STREAMS=250, MAX_HEADER_LIST_SIZE=1048896, INITIAL_WINDOW_SIZE=1048576
2019/08/03 22:46:08 http2: Framer 0xc0001fe000: read SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2019/08/03 22:46:08 http2: Framer 0xc0001a01c0: wrote SETTINGS flags=ACK len=0
2019/08/03 22:46:08 http2: server read frame SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2019/08/03 22:46:08 http2: Framer 0xc0001a01c0: read WINDOW_UPDATE len=4 (conn) incr=983041
2019/08/03 22:46:08 http2: server processing setting [ENABLE_PUSH = 0]
2019/08/03 22:46:08 http2: server processing setting [INITIAL_WINDOW_SIZE = 4194304]
2019/08/03 22:46:08 http2: Transport received WINDOW_UPDATE len=4 (conn) incr=983041
2019/08/03 22:46:08 http2: server processing setting [MAX_HEADER_LIST_SIZE = 10485760]
2019/08/03 22:46:08 http2: Framer 0xc0001fe000: wrote SETTINGS flags=ACK len=0
2019/08/03 22:46:08 http2: Framer 0xc0001fe000: read WINDOW_UPDATE len=4 (conn) incr=1073741824
2019/08/03 22:46:08 http2: server read frame WINDOW_UPDATE len=4 (conn) incr=1073741824
2019/08/03 22:46:08 http2: Framer 0xc0001fe000: read HEADERS flags=END_STREAM|END_HEADERS stream=3 len=49
2019/08/03 22:46:08 http2: Framer 0xc0001a01c0: read SETTINGS flags=ACK len=0
2019/08/03 22:46:08 http2: Transport received SETTINGS flags=ACK len=0
2019/08/03 22:46:08 http2: decoded hpack field header field ":authority" = "localhost:7777"
2019/08/03 22:46:08 http2: decoded hpack field header field ":method" = "PRI"
2019/08/03 22:46:08 http2: decoded hpack field header field ":path" = "/%2A"
2019/08/03 22:46:08 http2: decoded hpack field header field ":scheme" = "http"
2019/08/03 22:46:08 http2: decoded hpack field header field "x-forwarded-for" = "127.0.0.1"
2019/08/03 22:46:08 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/08/03 22:46:08 http2: server read frame HEADERS flags=END_STREAM|END_HEADERS stream=3 len=49
2019/08/03 22:46:08 http2: Framer 0xc0001fe000: read SETTINGS flags=ACK len=0
2019/08/03 22:46:08 http2: server read frame SETTINGS flags=ACK len=0
2019/08/03 22:46:08 http2: server encoding header ":status" = "200"
2019/08/03 22:46:08 http2: server encoding header "content-type" = "text/plain; charset=utf-8"
2019/08/03 22:46:08 http2: server encoding header "content-length" = "21"
2019/08/03 22:46:08 http2: server encoding header "date" = "Sun, 04 Aug 2019 05:46:08 GMT"
2019/08/03 22:46:08 http2: Framer 0xc0001fe000: wrote HEADERS flags=END_HEADERS stream=3 len=49
2019/08/03 22:46:08 http2: Framer 0xc0001fe000: wrote DATA flags=END_STREAM stream=3 len=21 data="hello world HTTP/2.0\n"
2019/08/03 22:46:08 http2: Framer 0xc0001a01c0: read HEADERS flags=END_HEADERS stream=3 len=49
2019/08/03 22:46:08 http2: decoded hpack field header field ":status" = "200"
2019/08/03 22:46:08 http2: decoded hpack field header field "content-type" = "text/plain; charset=utf-8"
2019/08/03 22:46:08 http2: decoded hpack field header field "content-length" = "21"
2019/08/03 22:46:08 http2: decoded hpack field header field "date" = "Sun, 04 Aug 2019 05:46:08 GMT"
2019/08/03 22:46:08 http2: Transport received HEADERS flags=END_HEADERS stream=3 len=49
2019/08/03 22:46:08 http2: Framer 0xc0001a01c0: read DATA flags=END_STREAM stream=3 len=21 data="hello world HTTP/2.0\n"
2019/08/03 22:46:08 http2: Transport received DATA flags=END_STREAM stream=3 len=21 data="hello world HTTP/2.0\n"
2019/08/03 22:46:08 http2: Transport readFrame error on conn 0xc000001500: (*net.OpError) read tcp 127.0.0.1:63831->127.0.0.1:17777: read: connection reset by peer
2019/08/03 22:46:08 RoundTrip failure: read tcp 127.0.0.1:63831->127.0.0.1:17777: read: connection reset by peer
--- FAIL: TestHTTP2 (0.01s)
    --- FAIL: TestHTTP2/via_proxy (0.01s)
        require.go:794:
                Error Trace:    http2_test.go:62
                Error:          Received unexpected error:
                                Get http://127.0.0.1:17777: read tcp 127.0.0.1:63831->127.0.0.1:17777: read: connection reset by peer
                Test:           TestHTTP2/via_proxy
FAIL
exit status 1

It seems the reverseProxy successfully got the response from the backend server, but close the connection to the client before returning the response.

Am I missing anything, or httputil.Reverseproxy doesn't work with h2c? Thanks.

[andybons]

@bradfitz

[bradfitz]

ReverseProxy proxies requests, not transports.

A ReverseProxy is just a net/http.Handler that you can run on an HTTP server (which might speak 3 protocol versions times TLS or not). But the ReverseProxy does its backend request using the provided https://golang.org/pkg/net/http/httputil/#ReverseProxy.Transport and whatever transport it selects. There's no design goal or effort for those two transports to be the same. They very often are not (e.g. HTTP/2 TLS to the world, but HTTP/1.1 plaintext internally).

Am I missing anything, or httputil.Reverseproxy doesn't work with h2c? Thanks.

It does if you configure both halves to do so, yes.

[jaricftw]

@bradfitz Thank you, that makes sense!