Skip to content

net/http/httputil: ReverseProxy doesn't proxy grpc without help due to 'te' header handling #21096

New issue
New issue
Closed
Closed
net/http/httputil: ReverseProxy doesn't proxy grpc without help due to 'te' header handling#21096
Labels
FrozenDueToAgeNeedsFixThe path to resolution is known, but the work has not been done.
Milestone
 
Go1.11
@groob

Description

@groob
groob
opened on Jul 20, 2017

Please answer these questions before submitting your issue. Thanks!

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

Go 1.8.3 (but can reproduce with 1.9beta2.

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

darwin and linux

What did you do?

Tried to use the http2 transport to talk to a remote http2 server.
https://play.golang.org/p/W_HbQGJZK9

The server on the other end is the grpc helloworld example.
When running against the grpc-go implementation, the code works.
When running agains ruby or python(both backed by C code) I get the INTERNAL_ERROR response described above. Logging on the server side itself is silent.

Note, the HTTP POST is only to more easily reproduce the issue. What I'm trying to do instead is use httputil.ReverseProxy to proxy grpc traffic: https://play.golang.org/p/micZul79Ow
This succeeds if the upstream server is in Go

C server examples: https://github.com/grpc/grpc/tree/master/examples (connecting to these fails)
grpc-go examples: https://github.com/grpc/grpc-go/tree/master/examples (connecting to this server succeeds)

What did you expect to see?

An HTTP response.

What did you see instead?

GODEBUG=http2debug=2 go run main.go                                                                                                                                                                    
2017/07/19 23:34:05 http2: Transport creating client conn 0xc42013c000 to [::1]:8082
2017/07/19 23:34:05 http2: Framer 0xc42014e000: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2017/07/19 23:34:05 http2: Framer 0xc42014e000: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2017/07/19 23:34:05 http2: Transport encoding header ":authority" = "localhost:8082"
2017/07/19 23:34:05 http2: Transport encoding header ":method" = "POST"
2017/07/19 23:34:05 http2: Transport encoding header ":path" = "/"
2017/07/19 23:34:05 http2: Transport encoding header ":scheme" = "https"
2017/07/19 23:34:05 http2: Transport encoding header "content-type" = "application/grpc"
2017/07/19 23:34:05 http2: Transport encoding header "content-length" = "5"
2017/07/19 23:34:05 http2: Transport encoding header "accept-encoding" = "gzip"
2017/07/19 23:34:05 http2: Transport encoding header "user-agent" = "Go-http-client/2.0"
2017/07/19 23:34:05 http2: Framer 0xc42014e000: wrote HEADERS flags=END_HEADERS stream=1 len=51
2017/07/19 23:34:05 http2: Framer 0xc42014e000: wrote DATA stream=1 len=5 data="hello"
2017/07/19 23:34:05 http2: Framer 0xc42014e000: read SETTINGS len=24, settings: INITIAL_WINDOW_SIZE=65535, MAX_FRAME_SIZE=65538, MAX_HEADER_LIST_SIZE=16384, UNKNOWN_SETTING_65027=1
2017/07/19 23:34:05 http2: Framer 0xc42014e000: wrote DATA flags=END_STREAM stream=1 len=0 data=""
2017/07/19 23:34:05 http2: Transport received SETTINGS len=24, settings: INITIAL_WINDOW_SIZE=65535, MAX_FRAME_SIZE=65538, MAX_HEADER_LIST_SIZE=16384, UNKNOWN_SETTING_65027=1
2017/07/19 23:34:05 Unhandled Setting: [MAX_HEADER_LIST_SIZE = 16384]
2017/07/19 23:34:05 Unhandled Setting: [UNKNOWN_SETTING_65027 = 1]
2017/07/19 23:34:05 http2: Framer 0xc42014e000: wrote SETTINGS flags=ACK len=0
2017/07/19 23:34:05 http2: Framer 0xc42014e000: read SETTINGS flags=ACK len=0
2017/07/19 23:34:05 http2: Transport received SETTINGS flags=ACK len=0
2017/07/19 23:34:05 http2: Framer 0xc42014e000: read RST_STREAM stream=1 len=4 ErrCode=INTERNAL_ERROR
2017/07/19 23:34:05 http2: Transport received RST_STREAM stream=1 len=4 ErrCode=INTERNAL_ERROR
2017/07/19 23:34:05 http2: Framer 0xc42014e000: read HEADERS flags=END_STREAM|END_HEADERS stream=1 len=83
2017/07/19 23:34:05 http2: decoded hpack field header field ":status" = "200"
2017/07/19 23:34:05 http2: decoded hpack field header field "content-type" = "application/grpc"
2017/07/19 23:34:05 RoundTrip failure: stream error: stream ID 1; INTERNAL_ERROR
2017/07/19 23:34:05 http2: decoded hpack field header field "grpc-status" = "1"
2017/07/19 23:34:05 http2: decoded hpack field header field "grpc-message" = "Cancelled"
2017/07/19 23:34:05 http2: Transport received HEADERS flags=END_STREAM|END_HEADERS stream=1 len=83
2017/07/19 23:34:05 Post https://localhost:8082: stream error: stream ID 1; INTERNAL_ERROR

Activity

bradfitz

bradfitz commented on Jul 20, 2017

@bradfitz
bradfitz
on Jul 20, 2017
Contributor

I bet it doesn't like the :path of / you're sending.

But that would have nothing to do with Go's HTTP/2 support.

groob

groob commented on Jul 20, 2017

@groob
groob
on Jul 20, 2017 · edited by groob
ContributorAuthor

Here is the debug output of the proxy version:

func proxyForGRPC(backendURL string) (*httputil.ReverseProxy, error) {
	u, err := url.Parse(backendURL)
	if err != nil {
		return nil, err
	}
	u.Scheme = "https" // enforce https scheme on urls for htt2
	dial := func(network, addr string, cfg *tls.Config) (net.Conn, error) {
		return net.Dial(network, addr)
	}
	transport := &http2.Transport{

		DialTLS: dial,
	}
	p := httputil.NewSingleHostReverseProxy(u)
	p.Transport = transport
	return p, nil
}

proxying to the ruby grpc greeter server.

2017/07/20 01:19:17 http2: server connection from [::1]:63477 on 0xc4200835f0
2017/07/20 01:19:17 http2: Framer 0xc4201da2a0: wrote SETTINGS len=24, settings: MAX_FRAME_SIZE=1048576, MAX_CONCURRENT_STREAMS=250, MAX_HEADER_LIST_SIZE=1048896, INITIAL_WINDOW_SIZE=1048576
2017/07/20 01:19:17 http2: server: client [::1]:63477 said hello
2017/07/20 01:19:17 http2: Framer 0xc4201da2a0: wrote WINDOW_UPDATE len=4 (conn) incr=983041
2017/07/20 01:19:17 http2: Framer 0xc4201da2a0: read SETTINGS len=0
2017/07/20 01:19:17 http2: server read frame SETTINGS len=0
2017/07/20 01:19:17 http2: Framer 0xc4201da2a0: wrote SETTINGS flags=ACK len=0
2017/07/20 01:19:17 http2: Framer 0xc4201da2a0: read HEADERS flags=END_HEADERS stream=1 len=73
2017/07/20 01:19:17 http2: decoded hpack field header field ":method" = "POST"
2017/07/20 01:19:17 http2: decoded hpack field header field ":scheme" = "https"
2017/07/20 01:19:17 http2: decoded hpack field header field ":path" = "/helloworld.Greeter/SayHello"
2017/07/20 01:19:17 http2: decoded hpack field header field ":authority" = "localhost:8083"
2017/07/20 01:19:17 http2: decoded hpack field header field "content-type" = "application/grpc"
2017/07/20 01:19:17 http2: decoded hpack field header field "user-agent" = "grpc-go/1.5.0"
2017/07/20 01:19:17 http2: decoded hpack field header field "te" = "trailers"
2017/07/20 01:19:17 http2: server read frame HEADERS flags=END_HEADERS stream=1 len=73
2017/07/20 01:19:17 http2: Framer 0xc4201da2a0: read DATA flags=END_STREAM stream=1 len=12 data="\x00\x00\x00\x00\a\n\x05world"
2017/07/20 01:19:17 http2: server read frame DATA flags=END_STREAM stream=1 len=12 data="\x00\x00\x00\x00\a\n\x05world"
2017/07/20 01:19:17 http2: Framer 0xc4201da2a0: read SETTINGS flags=ACK len=0
2017/07/20 01:19:17 http2: server read frame SETTINGS flags=ACK len=0
2017/07/20 01:19:17 http2: Transport creating client conn 0xc42008a9c0 to [::1]:8082
2017/07/20 01:19:17 http2: Framer 0xc4201da540: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2017/07/20 01:19:17 http2: Framer 0xc4201da540: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2017/07/20 01:19:17 http2: Transport encoding header ":authority" = "localhost:8083"
2017/07/20 01:19:17 http2: Transport encoding header ":method" = "POST"
2017/07/20 01:19:17 http2: Transport encoding header ":path" = "/helloworld.Greeter/SayHello"
2017/07/20 01:19:17 http2: Transport encoding header ":scheme" = "https"
2017/07/20 01:19:17 http2: Transport encoding header "x-forwarded-for" = "::1"
2017/07/20 01:19:17 http2: Transport encoding header "content-type" = "application/grpc"
2017/07/20 01:19:17 http2: Transport encoding header "user-agent" = "grpc-go/1.5.0"
2017/07/20 01:19:17 http2: Transport encoding header "accept-encoding" = "gzip"
2017/07/20 01:19:17 http2: Framer 0xc4201da540: wrote HEADERS flags=END_HEADERS stream=1 len=84
2017/07/20 01:19:17 http2: Framer 0xc4201da540: wrote DATA stream=1 len=12 data="\x00\x00\x00\x00\a\n\x05world"
2017/07/20 01:19:17 http2: Framer 0xc4201da540: read SETTINGS len=24, settings: INITIAL_WINDOW_SIZE=65535, MAX_FRAME_SIZE=65545, MAX_HEADER_LIST_SIZE=16384, UNKNOWN_SETTING_65027=1
2017/07/20 01:19:17 http2: Framer 0xc4201da2a0: wrote WINDOW_UPDATE len=4 (conn) incr=12
2017/07/20 01:19:17 http2: Transport received SETTINGS len=24, settings: INITIAL_WINDOW_SIZE=65535, MAX_FRAME_SIZE=65545, MAX_HEADER_LIST_SIZE=16384, UNKNOWN_SETTING_65027=1
2017/07/20 01:19:17 http2: Framer 0xc4201da540: wrote DATA flags=END_STREAM stream=1 len=0 data=""
2017/07/20 01:19:17 Unhandled Setting: [MAX_HEADER_LIST_SIZE = 16384]
2017/07/20 01:19:17 Unhandled Setting: [UNKNOWN_SETTING_65027 = 1]
2017/07/20 01:19:17 http2: Framer 0xc4201da540: wrote SETTINGS flags=ACK len=0
2017/07/20 01:19:17 http2: Framer 0xc4201da540: read SETTINGS flags=ACK len=0
2017/07/20 01:19:17 http2: Transport received SETTINGS flags=ACK len=0
2017/07/20 01:19:17 http2: Framer 0xc4201da540: read RST_STREAM stream=1 len=4 ErrCode=INTERNAL_ERROR
2017/07/20 01:19:17 http2: Transport received RST_STREAM stream=1 len=4 ErrCode=INTERNAL_ERROR
2017/07/20 01:19:17 http2: Framer 0xc4201da540: read HEADERS flags=END_STREAM|END_HEADERS stream=1 len=83
2017/07/20 01:19:17 http2: decoded hpack field header field ":status" = "200"
2017/07/20 01:19:17 http2: decoded hpack field header field "content-type" = "application/grpc"
2017/07/20 01:19:17 http2: decoded hpack field header field "grpc-status" = "1"
2017/07/20 01:19:17 http2: decoded hpack field header field "grpc-message" = "Cancelled"
2017/07/20 01:19:17 http2: Transport received HEADERS flags=END_STREAM|END_HEADERS stream=1 len=83
2017/07/20 01:19:17 http2: Framer 0xc4201da540: read RST_STREAM stream=1 len=4 ErrCode=NO_ERROR
2017/07/20 01:19:17 http2: Transport received RST_STREAM stream=1 len=4 ErrCode=NO_ERROR
2017/07/20 01:19:17 RoundTrip failure: stream error: stream ID 1; INTERNAL_ERROR
2017/07/20 01:19:17 http: proxy error: stream error: stream ID 1; INTERNAL_ERROR
2017/07/20 01:19:17 http2: server encoding header ":status" = "502"
2017/07/20 01:19:17 http2: server encoding header "content-type" = "text/plain; charset=utf-8"
2017/07/20 01:19:17 http2: server encoding header "content-length" = "0"
2017/07/20 01:19:17 http2: server encoding header "date" = "Thu, 20 Jul 2017 05:19:17 GMT"
2017/07/20 01:19:17 http2: Framer 0xc4201da2a0: wrote HEADERS flags=END_STREAM|END_HEADERS stream=1 len=51
2017/07/20 01:19:17 http2: Framer 0xc4201da2a0: read RST_STREAM stream=1 len=4 ErrCode=CANCEL
2017/07/20 01:19:17 http2: server read frame RST_STREAM stream=1 len=4 ErrCode=CANCEL
groob

groob commented on Jul 20, 2017

@groob
groob
on Jul 20, 2017
ContributorAuthor

And this is what happens when the remote is a grpc-go server:

2017/07/20 01:18:26 http2: server connection from [::1]:63450 on 0xc420085520
2017/07/20 01:18:26 http2: Framer 0xc4201dc2a0: wrote SETTINGS len=24, settings: MAX_FRAME_SIZE=1048576, MAX_CONCURRENT_STREAMS=250, MAX_HEADER_LIST_SIZE=1048896, INITIAL_WINDOW_SIZE=1048576
2017/07/20 01:18:26 http2: server: client [::1]:63450 said hello
2017/07/20 01:18:26 http2: Framer 0xc4201dc2a0: wrote WINDOW_UPDATE len=4 (conn) incr=983041
2017/07/20 01:18:26 http2: Framer 0xc4201dc2a0: read SETTINGS len=0
2017/07/20 01:18:26 http2: server read frame SETTINGS len=0
2017/07/20 01:18:26 http2: Framer 0xc4201dc2a0: wrote SETTINGS flags=ACK len=0
2017/07/20 01:18:26 http2: Framer 0xc4201dc2a0: read HEADERS flags=END_HEADERS stream=1 len=73
2017/07/20 01:18:26 http2: decoded hpack field header field ":method" = "POST"
2017/07/20 01:18:26 http2: decoded hpack field header field ":scheme" = "https"
2017/07/20 01:18:26 http2: decoded hpack field header field ":path" = "/helloworld.Greeter/SayHello"
2017/07/20 01:18:26 http2: decoded hpack field header field ":authority" = "localhost:8083"
2017/07/20 01:18:26 http2: decoded hpack field header field "content-type" = "application/grpc"
2017/07/20 01:18:26 http2: decoded hpack field header field "user-agent" = "grpc-go/1.5.0"
2017/07/20 01:18:26 http2: decoded hpack field header field "te" = "trailers"
2017/07/20 01:18:26 http2: server read frame HEADERS flags=END_HEADERS stream=1 len=73
2017/07/20 01:18:26 http2: Framer 0xc4201dc2a0: read DATA flags=END_STREAM stream=1 len=12 data="\x00\x00\x00\x00\a\n\x05world"
2017/07/20 01:18:26 http2: server read frame DATA flags=END_STREAM stream=1 len=12 data="\x00\x00\x00\x00\a\n\x05world"
2017/07/20 01:18:26 http2: Framer 0xc4201dc2a0: read SETTINGS flags=ACK len=0
2017/07/20 01:18:26 http2: server read frame SETTINGS flags=ACK len=0
2017/07/20 01:18:26 http2: Transport creating client conn 0xc42008a9c0 to [::1]:8082
2017/07/20 01:18:26 http2: Framer 0xc4201dc540: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2017/07/20 01:18:26 http2: Framer 0xc4201dc540: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2017/07/20 01:18:26 http2: Transport encoding header ":authority" = "localhost:8083"
2017/07/20 01:18:26 http2: Framer 0xc4201dc540: read SETTINGS len=0
2017/07/20 01:18:26 http2: Transport encoding header ":method" = "POST"
2017/07/20 01:18:26 http2: Transport encoding header ":path" = "/helloworld.Greeter/SayHello"
2017/07/20 01:18:26 http2: Transport encoding header ":scheme" = "https"
2017/07/20 01:18:26 http2: Transport encoding header "user-agent" = "grpc-go/1.5.0"
2017/07/20 01:18:26 http2: Transport encoding header "x-forwarded-for" = "::1"
2017/07/20 01:18:26 http2: Transport received SETTINGS len=0
2017/07/20 01:18:26 http2: Transport encoding header "content-type" = "application/grpc"
2017/07/20 01:18:26 http2: Transport encoding header "accept-encoding" = "gzip"
2017/07/20 01:18:26 http2: Framer 0xc4201dc540: wrote HEADERS flags=END_HEADERS stream=1 len=84
2017/07/20 01:18:26 http2: Framer 0xc4201dc540: wrote SETTINGS flags=ACK len=0
2017/07/20 01:18:26 http2: Framer 0xc4201dc540: read SETTINGS flags=ACK len=0
2017/07/20 01:18:26 http2: Transport received SETTINGS flags=ACK len=0
2017/07/20 01:18:26 http2: Framer 0xc4201dc540: wrote DATA stream=1 len=12 data="\x00\x00\x00\x00\a\n\x05world"
2017/07/20 01:18:26 http2: Framer 0xc4201dc2a0: wrote WINDOW_UPDATE len=4 (conn) incr=12
2017/07/20 01:18:26 http2: Framer 0xc4201dc540: wrote DATA flags=END_STREAM stream=1 len=0 data=""
2017/07/20 01:18:26 http2: Framer 0xc4201dc540: read WINDOW_UPDATE len=4 (conn) incr=12
2017/07/20 01:18:26 http2: Transport received WINDOW_UPDATE len=4 (conn) incr=12
2017/07/20 01:18:26 http2: Framer 0xc4201dc540: read PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2017/07/20 01:18:26 http2: Transport received PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2017/07/20 01:18:26 http2: Framer 0xc4201dc540: wrote PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2017/07/20 01:18:26 http2: Framer 0xc4201dc540: read HEADERS flags=END_HEADERS stream=1 len=14
2017/07/20 01:18:26 http2: decoded hpack field header field ":status" = "200"
2017/07/20 01:18:26 http2: decoded hpack field header field "content-type" = "application/grpc"
2017/07/20 01:18:26 http2: Transport received HEADERS flags=END_HEADERS stream=1 len=14
2017/07/20 01:18:26 http2: Framer 0xc4201dc540: read DATA stream=1 len=18 data="\x00\x00\x00\x00\r\n\vHello world"
2017/07/20 01:18:26 http2: Transport received DATA stream=1 len=18 data="\x00\x00\x00\x00\r\n\vHello world"
2017/07/20 01:18:26 http2: Framer 0xc4201dc540: read HEADERS flags=END_STREAM|END_HEADERS stream=1 len=24
2017/07/20 01:18:26 http2: decoded hpack field header field "grpc-status" = "0"
2017/07/20 01:18:26 http2: decoded hpack field header field "grpc-message" = ""
2017/07/20 01:18:26 http2: Transport received HEADERS flags=END_STREAM|END_HEADERS stream=1 len=24
2017/07/20 01:18:26 http2: server encoding header ":status" = "200"
2017/07/20 01:18:26 http2: server encoding header "content-type" = "application/grpc"
2017/07/20 01:18:26 http2: server encoding header "content-length" = "18"
2017/07/20 01:18:26 http2: server encoding header "date" = "Thu, 20 Jul 2017 05:18:26 GMT"
2017/07/20 01:18:26 http2: Framer 0xc4201dc2a0: wrote HEADERS flags=END_HEADERS stream=1 len=42
2017/07/20 01:18:26 http2: Framer 0xc4201dc2a0: wrote DATA stream=1 len=18 data="\x00\x00\x00\x00\r\n\vHello world"
2017/07/20 01:18:26 http2: server encoding header "grpc-message" = ""
2017/07/20 01:18:26 http2: server encoding header "grpc-status" = "0"
2017/07/20 01:18:26 http2: Framer 0xc4201dc2a0: wrote HEADERS flags=END_STREAM|END_HEADERS stream=1 len=24
2017/07/20 01:18:26 http2: Framer 0xc4201dc2a0: read WINDOW_UPDATE len=4 (conn) incr=18
2017/07/20 01:18:26 http2: server read frame WINDOW_UPDATE len=4 (conn) incr=18
2017/07/20 01:18:26 http2: Framer 0xc4201dc2a0: read PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2017/07/20 01:18:26 http2: server read frame PING len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"
2017/07/20 01:18:26 http2: Framer 0xc4201dc2a0: wrote PING flags=ACK len=8 ping="\x02\x04\x10\x10\t\x0e\a\a"```
bradfitz
changed the title [-]x/net/http2 transport results in stream error INTERNAL_ERROR [/-] [+]x/net/http2: transport results in stream error INTERNAL_ERROR when proxying to C grpc server [/+] on Jul 20, 2017
groob

groob commented on Jul 20, 2017

@groob
groob
on Jul 20, 2017
ContributorAuthor

Here's something. I figured out how to enable http tracing on the ruby server:
GRPC_TRACE=http

D0720 01:34:57.102142000 140736940794816 ev_posix.c:121]               Using polling engine: poll
D0720 01:34:57.102229000 140736940794816 dns_resolver.c:316]           Using native dns resolver
I0720 01:34:57.102439000 140736940794816 server.c:984]                 Completion queue which is not of type GRPC_CQ_NEXT is being registered as a server-completion-queue
D0720 01:34:57.104157000 123145437982720 rb_channel.c:696]             GRPC_RUBY: run_poll_channels_loop - create connection polling thread
D0720 01:34:57.104181000 123145437982720 rb_channel.c:620]             GRPC_RUBY: run_poll_channels_loop_no_gil - begin
D0720 01:35:04.216769000 140736940794816 chttp2_transport.c:811]       W:0x7ff795800c00 SERVER state IDLE -> WRITING [push_setting]
D0720 01:35:04.216805000 140736940794816 chttp2_transport.c:811]       W:0x7ff795800c00 SERVER state WRITING -> WRITING+MORE [push_setting]
D0720 01:35:04.216903000 140736940794816 chttp2_transport.c:811]       W:0x7ff795800c00 SERVER state WRITING+MORE -> WRITING [begin writing]
D0720 01:35:04.216932000 140736940794816 chttp2_transport.c:811]       W:0x7ff795800c00 SERVER state WRITING -> IDLE [finish writing]
D0720 01:35:04.216975000 140736940794816 frame_settings.c:228]         CHTTP2:SVR:ipv6:[::1]:63784: got setting ENABLE_PUSH = 0
D0720 01:35:04.216982000 140736940794816 frame_settings.c:222]         adding 4128769 for initial_window change
D0720 01:35:04.216987000 140736940794816 frame_settings.c:228]         CHTTP2:SVR:ipv6:[::1]:63784: got setting INITIAL_WINDOW_SIZE = 4194304
D0720 01:35:04.216991000 140736940794816 frame_settings.c:228]         CHTTP2:SVR:ipv6:[::1]:63784: got setting MAX_HEADER_LIST_SIZE = 10485760
D0720 01:35:04.217011000 140736940794816 chttp2_transport.c:1497]      perform_stream_op[s=0x7ff79682c4c8]: [UNCOVERED] RECV_INITIAL_METADATA
I0720 01:35:04.217296000 140736940794816 parsing.c:499]                HTTP:1:HDR:SVR: :authority: 6c 6f 63 61 6c 68 6f 73 74 3a 38 30 38 33 'localhost:8083'
I0720 01:35:04.217309000 140736940794816 parsing.c:499]                HTTP:1:HDR:SVR: :method: 50 4f 53 54 'POST'
I0720 01:35:04.217322000 140736940794816 parsing.c:499]                HTTP:1:HDR:SVR: :path: 2f 68 65 6c 6c 6f 77 6f 72 6c 64 2e 47 72 65 65 74 65 72 2f 53 61 79 48 65 6c 6c 6f '/helloworld.Greeter/SayHello'
I0720 01:35:04.217327000 140736940794816 parsing.c:499]                HTTP:1:HDR:SVR: :scheme: 68 74 74 70 73 'https'
I0720 01:35:04.217333000 140736940794816 parsing.c:499]                HTTP:1:HDR:SVR: content-type: 61 70 70 6c 69 63 61 74 69 6f 6e 2f 67 72 70 63 'application/grpc'
I0720 01:35:04.217339000 140736940794816 parsing.c:499]                HTTP:1:HDR:SVR: user-agent: 67 72 70 63 2d 67 6f 2f 31 2e 35 2e 30 'grpc-go/1.5.0'
I0720 01:35:04.217346000 140736940794816 parsing.c:499]                HTTP:1:HDR:SVR: x-forwarded-for: 3a 3a 31 '::1'
I0720 01:35:04.217351000 140736940794816 parsing.c:499]                HTTP:1:HDR:SVR: accept-encoding: 67 7a 69 70 'gzip'
D0720 01:35:04.217360000 140736940794816 chttp2_transport.c:811]       W:0x7ff795800c00 SERVER state IDLE -> WRITING [send_ping]
D0720 01:35:04.217369000 140736940794816 chttp2_transport.c:1254]      perform_stream_op_locked: [UNCOVERED] RECV_INITIAL_METADATA; on_complete = 0x7ff79682cbe8
D0720 01:35:04.217421000 140736940794816 chttp2_transport.c:1497]      perform_stream_op[s=0x7ff79682c4c8]: [UNCOVERED] CANCEL:{"created":"@1500528904.217380000","description":"Missing :authority or :path","file":"src/core/lib/surface/server.c","file_line":754,"referenced_errors":[{"created":"@1500528904.217376000","description":"Failed processing incoming headers","file":"src/core/ext/filters/http/server/http_server_filter.c","file_line":102,"referenced_errors":[{"created":"@1500528904.217375000","description":"Missing header","file":"src/core/ext/filters/http/server/http_server_filter.c","file_line":157,"key":"te"}]}]}
D0720 01:35:04.217430000 140736940794816 chttp2_transport.c:1109]      complete_closure_step: 0x7ff79682cbe8 refs=0 flags=0x0000 desc=op->on_complete err="No Error"
D0720 01:35:04.217437000 140736940794816 chttp2_transport.c:1497]      perform_stream_op[s=0x7ff79682c4c8]: [UNCOVERED] CANCEL:"Cancelled"
D0720 01:35:04.217444000 140736940794816 chttp2_transport.c:1254]      perform_stream_op_locked: [UNCOVERED] CANCEL:{"created":"@1500528904.217380000","description":"Missing :authority or :path","file":"src/core/lib/surface/server.c","file_line":754,"referenced_errors":[{"created":"@1500528904.217376000","description":"Failed processing incoming headers","file":"src/core/ext/filters/http/server/http_server_filter.c","file_line":102,"referenced_errors":[{"created":"@1500528904.217375000","description":"Missing header","file":"src/core/ext/filters/http/server/http_server_filter.c","file_line":157,"key":"te"}]}]}; on_complete = 0x7ff794f31a50
D0720 01:35:04.217459000 140736940794816 chttp2_transport.c:811]       W:0x7ff795800c00 SERVER state WRITING -> WRITING+MORE [rst_stream]
D0720 01:35:04.217467000 140736940794816 chttp2_transport.c:1109]      complete_closure_step: 0x7ff794f31a50 refs=0 flags=0x0000 desc=op->on_complete err="No Error"
D0720 01:35:04.217473000 140736940794816 chttp2_transport.c:1254]      perform_stream_op_locked: [UNCOVERED] CANCEL:"Cancelled"; on_complete = 0x7ff794f5c340
D0720 01:35:04.217525000 140736940794816 chttp2_transport.c:1109]      complete_closure_step: 0x7ff794f5c340 refs=0 flags=0x0000 desc=op->on_complete err="No Error"
D0720 01:35:04.217541000 140736940794816 chttp2_transport.c:811]       W:0x7ff795800c00 SERVER state WRITING+MORE -> WRITING [begin writing]
D0720 01:35:04.217568000 140736940794816 chttp2_transport.c:811]       W:0x7ff795800c00 SERVER state WRITING -> IDLE [finish writing]
bradfitz

bradfitz commented on Jul 20, 2017

@bradfitz
bradfitz
on Jul 20, 2017
Contributor

It's missing the "te" header.

The https://grpc.io/docs/guides/wire.html does say:

TE → “te” “trailers” # Used to detect incompatible proxies

I guess you're an incompatible proxy! :-)

I forget which layer's job it is to strip/add/handle that. But that's what should be investigated here.

/cc @tombergan

groob

groob commented on Jul 20, 2017

@groob
groob
on Jul 20, 2017
ContributorAuthor

Yep, commenting out Te in the httputil.ReverseProxy makes the C server behave as expected.

go/src/net/http/httputil/reverseproxy.go

Line 135 in 3498012

"Te", // canonicalized version of "TE"

Doesn't sound like the right solution for a proxy to keep that header though. Should I open a issue with grpc/grpc?

groob

groob commented on Jul 20, 2017

@groob
groob
on Jul 20, 2017 · edited by groob
ContributorAuthor

Found this article from the nginx blog https://nghttp2.org/blog/2015/03/24/proxying-grpc-with-nghttpx/

So in HTTP/1.1, trailer fields are only allowed in chunked transfer encoding. In HTTP/2, chunked transfer encoding is deprecated because it has more elegant framing and thanks to it, trailer fields are always allowed.

gRPC does not work without “TE” header field.

groob

groob commented on Jul 21, 2017

@groob
groob
on Jul 21, 2017
ContributorAuthor

@bradfitz is it too late in the 1.9 cycle or would you accept a CL to update this behavior in httputil/reverseproxy.go?

Something like this is what I had in mind:

diff --git a/src/net/http/httputil/reverseproxy.go b/src/net/http/httputil/reverseproxy.go
index 0d514f529b..4473657542 100644
--- a/src/net/http/httputil/reverseproxy.go
+++ b/src/net/http/httputil/reverseproxy.go
@@ -183,6 +183,11 @@ func (p *ReverseProxy) ServeHTTP(rw http.ResponseWriter, req *http.Request) {
 	// important is "Connection" because we want a persistent
 	// connection, regardless of what the client sent to us.
 	for _, h := range hopHeaders {
+		if outreq.ProtoMajor == 2 &&
+			strings.Contains(outreq.Header.Get("Content-Type"), "application/grpc") &&
+			h == "Te" {
+			continue
+		}
 		if outreq.Header.Get(h) != "" {
 			outreq.Header.Del(h)
 		}
bradfitz

bradfitz commented on Jul 21, 2017

@bradfitz
bradfitz
on Jul 21, 2017
Contributor

It's way too late. But your proxy can add those lines.

It's not obvious that we want to add application-specific hacks to reverseproxy.go.

Let's think about it during Go 1.10 development.

bradfitz
changed the title [-]x/net/http2: transport results in stream error INTERNAL_ERROR when proxying to C grpc server [/-] [+]net/http/httputil: ReverseProxy doesn't proxy grpc without help due to 'te' header handling[/+] on Jul 21, 2017
bradfitz
added
NeedsDecisionFeedback is required from experts, contributors, and/or the community before a change can be made.
on Jul 21, 2017
bradfitz
assigned
tombergan
on Jul 21, 2017
bradfitz
added this to the Go1.10 milestone on Jul 21, 2017
bradfitz

bradfitz commented on Dec 4, 2017

@bradfitz
bradfitz
on Dec 4, 2017
Contributor

Pushing to Go 1.11.

@tombergan, do you know what's right here?

8 remaining items

juliens
mentioned this in 2 issues on Jun 15, 2018
Cas-pian

Cas-pian commented on Jul 25, 2018

@Cas-pian
Cas-pian
on Jul 25, 2018

@gopherbot I've tested the go1.11beta2, the "Te" header in the client still missing when request backend server, I'm using traefik. Thanks.

bradfitz

bradfitz commented on Jul 25, 2018

@bradfitz
bradfitz
on Jul 25, 2018
Contributor

@Cas-pian, you probably didn't recompile your application or didn't do so with the right version of Go.

Cas-pian

Cas-pian commented on Jul 25, 2018

@Cas-pian
Cas-pian
on Jul 25, 2018

@bradfitz Thanks for your reply. I've recompile my application. And I found the application didn't use your function. I've fixed it. Thanks again!

idefixcert

idefixcert commented on Jan 16, 2019

@idefixcert
idefixcert
on Jan 16, 2019 · edited by idefixcert

I have the same problem but cant find a solution:
I have a ProxyServer written in go

func main() {
	log.SetPrefix("[proxy] ")
	log.SetOutput(os.Stdout)
	if upstream == "" {
		log.Fatal("ERROR: missing argument upstream ")
	}
	url, _ := url.Parse(upstream)
	proxy := &Upstream{target: url, proxy: httputil.NewSingleHostReverseProxy(url)}
	mux := http.NewServeMux()
	mux.HandleFunc("/", proxy.handle)
	log.Fatal(http.ListenAndServeTLS(httpsSocket, httpsCert, httpsKey, mux))
}

type Upstream struct {
	target *url.URL
	proxy  *httputil.ReverseProxy
}

func (p *Upstream) handle(w http.ResponseWriter, r *http.Request) {
	p.proxy.ServeHTTP(w, r)
}

If I make a call from gnmi server to client, I get:

[proxy] 2019/01/16 12:34:57 http: proxy error: net/http: HTTP/1.x transport connection broken: write tcp 127.0.0.1:55595->127.0.0.1:10161: write: broken pipe
[proxy] 2019/01/16 12:35:15 http: proxy error: net/http: HTTP/1.x transport connection broken: malformed HTTP response "\x00\x00\x00\x04\x00\x00\x00\x00\x00"
[proxy] 2019/01/16 12:35:31 http: proxy error: net/http: HTTP/1.x transport connection broken: malformed HTTP response "\x00\x00\x00\x04\x00\x00\x00\x00\x00"

Any hints?
buger
mentioned this on Feb 11, 2019
buger
added a commit that references this issue on Feb 11, 2019

Fix gRPC proxying

00113fd
buger
mentioned this on Feb 11, 2019
furkansenharputlu
added a commit that references this issue on Feb 15, 2019

Fix gRPC proxying

56f3a87
furkansenharputlu
mentioned this on Feb 15, 2019
buger
added a commit that references this issue on Feb 15, 2019

Fix gRPC and add test (#2119)

c589132
golang
locked and limited conversation to collaborators on Jan 16, 2020
gopherbot
added
FrozenDueToAge
on Jan 16, 2020
rsc
unassigned
bradfitz
on Jun 23, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    FrozenDueToAgeNeedsFixThe path to resolution is known, but the work has not been done.

    Type

    No type

    Projects

    No projects

    Milestone

    Relationships

    None yet

      Development

      No branches or pull requests

        Participants

        @bradfitz@groob@idefixcert@Cas-pian@gopherbot

        Issue actions
          net/http/httputil: ReverseProxy doesn't proxy grpc without help due to 'te' header handling · Issue #21096 · golang/go