Caddy: Reverse proxying GRPC calls does not work

[targodan]

1. What version of Caddy are you running (caddy -version)?

Caddy 0.9.5

2. What are you trying to do?

I am trying to use caddy as a reverse proxy to a GRPC server.

3. What is your entire Caddyfile?

See 7. below.

4. How did you run Caddy (give the full command and describe the execution environment)?

See 7. below.

5. What did you expect to see?

Working GRPC calls.

6. What did you see instead (give full error messages and/or log)?

No errors or log output of any kind. The grpc-server never receives anything from caddy.

The client only sees that the connection was closed by the (caddy) server before any sensible data could be sent or received.

I have sniffed the traffic using wireshark. The entire communication of one call consists of the following steps:

1. TCP SYN+ACK Client <-> Server
2. HTTP/2 SETTINGS package Client -> Server
3. TCP FIN+ACK Client <-> Server (FIN initiated by the sever)

It seems like caddy doesn't know what to do with a SETTINGS package or doesn't support something requested in that package and just terminates the connection.

I know my way around HTTP/1 a little but I don't really know anything about HTTP/2 or SETTINGS packages. The only thing I found out is that a SETTINGS package does not contain any request (GET/POST etc.) and thus no URL. So caddy can't know to which vserver/middleware it should route the package, thus the problem is most likely not in the proxy middleware but somewhere in the initial connection handling. I haven't looked at the caddy code yet though. I will try to come around to doing that soon.

I have researched GRPC proxing and caddy before and I found these related issues. I have created a new one though because I would consider them related but different enough from this to justify a new issue.

• #631 Apparently grpc proxing does not work out-of-the-box with go1.6
• #54 This seems to ask for a far larger amount of features. I don't need any fancy REST <-> GRPC converter, I simply want to have a caddy server on ports 80/443 and at the same time want to be able to have a grpc server on those ports.

7. How can someone who is starting from scratch reproduce this behavior as minimally as possible?

I have created a little test suite in go, which mostly automates testing if GRPC works. See this repo for the source code, including a Caddyfile with which I tested this.

It provides a go package where you can run go test -v on and it will tell you if everything is working or not.

[abiosoft]

Does HTTP/2 translates to gRPC compatibility ?

[targodan]

I don't know what you mean exactly. gRPC uses HTTP/2 as its transport layer, so it should be possible.

Here is the gRPC documentation about the wire protocol. I have only skimmed it myself but hope to find the time to read it in depth in the next few days.

[targodan]

Ok, I did some further investigating and it seems that caddy is not actually serving http/2 requests.

I went into the initial (*Server).ServeHTTP in here with a debugger and the request showed the method to be "PRI" which is not actually a valid method but is what a http/1 server would parse if a http/2 client tries to connect to it. See here.

Kind of a stupid question, but: Is caddys http/2 compliance actually tested using a client that explicitly uses/requests http/2?

EDIT: Please disregard that question. I have advanced a bit further now.

After some reading I found out that most http/2 implementations (including go's net/http) implementation seems to necessitate tls. Since I was testing it without tls it was handling any incomming connections as http/1.1 connections.

So I tested it again with tls on. Now it seems to reach the gRPC server, but the client echos the error "server closed the stream without sending trailers". I am currently having trouble sniffing the traffic (it uses DH ciphers by default) but I will get back to you once I solved that.

I will also update the test repo once I have cleaned up the latest changes.`

UPDATE: I now managed to sniff the traffic.

On the direct connection a last HEADERS package after the last DATA package is sent by the server to the client. That package is missing in the caddy -> client communication leading to the "server closed the stream without sending trailers" error.

[mholt]

After some reading I found out that most http/2 implementations (including go's net/http) implementation seems to necessitate tls

Yes. :) Spec allows a plaintext variant of HTTP/2 but in practice nobody (really) does this. HTTP/2 in practice requires TLS.

On the direct connection a last HEADERS package after the last DATA package is sent by the server to the client. That package is missing in the caddy -> client communication leading to the "server closed the stream without sending trailers" error.

Perhaps a bug in the recent trailer support that was merged in? I'm just speculating. Maybe @lhecker would know more about this -- he does good work, I'm always glad to have his help. :smile:

[lhecker]

This problem is caused by gRPC's server always sending HTTP/2 frames in a certain fixed pattern. The gRPC client furthermore even relies on that particular behavior. If there's a non-official gRPC solution at either end or in between (like Caddy) it ultimately breaks down.

The gRPC server sends the following frames:

http2: Framer 0xc42013c0e0: wrote HEADERS flags=END_HEADERS stream=9 len=2
http2: Framer 0xc42013c0e0: wrote DATA stream=9 len=28 data="\x00\x00\x00\x00\x17\n\x15This is an echo Test."
http2: Framer 0xc42013c0e0: wrote HEADERS flags=END_STREAM|END_HEADERS stream=9 len=2

Caddy then proxies the above to the gRPC client which receives the following:

http2: Framer 0xc4201a28c0: read DATA flags=END_STREAM stream=1 len=28 data="\x00\x00\x00\x00\x17\n\x15This is an echo Test."

As you might guess it's exactly the same in the eyes of the HTTP/2 protocol, since the HEADERS are empty and the flags are equivalent.
So yeah… The gRPC libs simply implement HTTP/2 quite poorly and thus fail to handle Caddy's frame ordering. 🙄 (BTW: It also fails with other proxies like nghttp2).

You can fix your test repo for instance by deleting this code and replacing it with this:

grpcServer := grpc.NewServer()
pb.RegisterTestServiceServer(grpcServer, &testServiceServer{})
http.ListenAndServeTLS(host, "../server.crt", "../server.key", grpcServer)

This will use grpc-go's ServeHTTP method instead, which uses the proper HTTP/2 implementation of Go's stdlib. The downside is that it's quite a bit slower than Serve (_relatively_ - it's still multiple magnitudes faster than e.g. REST APIs).

I'll try to see if we can tweak our code somehow to make it work out of the box though. But I'm not entirely sure yet if that's possible since we don't control the actual HTTP/2 framing.

[targodan]

Thanks for the feedback! It indeed works with the changes you provided.

[mholt]

See, I told you @lhecker was a wizard! 🎩

Should I close this issue then?

[lhecker]

Alright I found the exact reason why Caddy fails (if someone else wants to debug this as well)… This is the response Caddy receives from the gRPC server:

 1: Framer 0xc42022c8c0: read HEADERS flags=END_HEADERS stream=1 len=14
 2: decoded hpack field header field ":status" = "200"
 3: decoded hpack field header field "content-type" = "application/grpc"
 4: Transport received HEADERS flags=END_HEADERS stream=1 len=14
 5: Framer 0xc42022c8c0: read DATA stream=1 len=28 data="\x00\x00\x00\x00\x17\n\x15This is an echo Test."
 6: Transport received DATA stream=1 len=28 data="\x00\x00\x00\x00\x17\n\x15This is an echo Test."
 7: Framer 0xc42022c8c0: read HEADERS flags=END_STREAM|END_HEADERS stream=1 len=24
 8: decoded hpack field header field "grpc-status" = "0"
 9: decoded hpack field header field "grpc-message" = ""
10: Transport received HEADERS flags=END_STREAM|END_HEADERS stream=1 len=24

Line | Meaning | Caddy code
-----|-------------------|------------
1-4 | response headers | link
5-6 | response body | link
7-10 | response trailers | link

The issue now is that there is no god damn "Trailer" header coming from the gRPC server!
This causes our code to not be aware that any trailers are coming: res.Trailer is nil and len(res.Trailer) will thus return 0.
Since we then don't set the trailer header Go will then _silently_ ignore whatever we set at the end.

If I use ServeHTTP in the gRPC server instead (which again causes it to use the official Go HTTP/2 implementation) it looks a bit different:

  : Framer 0xc420268000: read HEADERS flags=END_HEADERS stream=1 len=41
  : decoded hpack field header field ":status" = "200"
  : decoded hpack field header field "content-type" = "application/grpc"
* : decoded hpack field header field "trailer" = "Grpc-Status"
* : decoded hpack field header field "trailer" = "Grpc-Message"
  : Transport received HEADERS flags=END_HEADERS stream=1 len=41
  : Framer 0xc420268000: read DATA stream=1 len=28 data="\x00\x00\x00\x00\x17\n\x15This is an echo Test."
  : Transport received DATA stream=1 len=28 data="\x00\x00\x00\x00\x17\n\x15This is an echo Test."
  : Framer 0xc420268000: read HEADERS flags=END_STREAM|END_HEADERS stream=1 len=12
  : decoded hpack field header field "grpc-status" = "0"
  : Transport received HEADERS flags=END_STREAM|END_HEADERS stream=1 len=12

Please note the 2 log lines I marked with a star. Apart from that it's nearly identical to the log above.

I think this issue should stay open since it'd be awesome if gRPC worked out of the box, but I'm not sure how to solve this. Or do you, @mholt?

[mholt]

I'm not familiar with gRPC so I'm afraid I don't know how to fix this either :( It's too bad that gRPC doesn't send a trailers header.

Is it safe to assume if the content-type is application/grpc that trailers will be sent?

[lhecker]

Yeah… I also already thought about simply adding a special case just for gRPC. But I noticed just now that the "trailer" header is not a "MUST" but a "SHOULD" in the HTTP RFCs. Even Go's http documentation makes it clear that it should be possible to set trailers without mentioning their names in the "trailer" header first. But strangely it doesn't work in our case.

[mholt]

Hmm. That is odd. Maybe the code we borrowed from the std lib is incomplete, or something?

gRPC does seem popular enough that I wonder if, in the interim, it merits its own special case (an if statement), as long as we tag it with a TODO comment. What do you think? We can either debug what we've got or add a special case. I would help debug if I was available, but I think everyone wants the new site up and running and I'm the bottleneck on that.

[lhecker]

@mholt @targodan Fixed it. lol 😎
It still needs a finishing touch though - I'll submit a PR later today or tomorrow. Spoiler: The trick is using http.TrailerPrefix (search for TrailerPrefix) to set unannounced trailers after writing the body, since otherwise they're ignored by Go. Man… Magic string prefixes… And people say Go has a well engineered stdlib… HA! Surprise: It doesn't. ☹️

Anyways @mholt: Say… How adamant are you about the ordering of these parameters. That a copy operation is not ordered left-to-right grinds my gears to a halt. Really. 😂 I'd really like to change it to src -> dst instead, but if you don't want any unnecessary changes like that I won't touch it of course.

[targodan]

Boy have I stared an avalanche. 😁

I guess this is the moment for praise:
I love caddy and the community around it! You people are just lovely.
@mholt Great work on maintaining this project and I am positively surprised how present you are in each and every issue submitted! 👍
@lhecker Brilliant work too, thanks so much for going way deeper than I would have managed with this problem. 👍

Thanks to you all!

[mholt]

@lhecker Awesome, nice job! I am surprised that it was the header string prefixes. I'm sure there is a reason they did it that way... it does seem a little hacky though. Oh well.

The (dst, src) ordering is that way because, I think, tradition. This is how memcpy works in C. Also, that's how the io package copy's methods are designed. I agree it's a little weird, but that seems to be normal. 🤷‍♂️

I await the PR. :) Bonus points if it has a test!

[lhecker]

@mholt I changed a few more things apart from the above. 😶

For instance I split up ReverseProxy.ServeHTTP() into a ReverseProxy.serveRegular() and ReverseProxy.serveWebsocket() to finally make that method a little bit smaller and easier to read.

I also optimized copyHeader: This just wastes precious CPU cycles while Go is busy canonicalizing the header name. It's unnecessary since the header name is already canonicalized of course (since it's coming from a http.Header and not a random source).
One can just write it as dst[k] = append(dst[k], vv...) which is shorter and faster!
Well… stuff like that. I'll split it up in different commits to make it easier to revert just in case.

Let's review it tomorrow. 🙂

[mholt]

Sounds great @lhecker! Thanks.

[mholt]

@targodan Are you able to build from source? I haven't had a chance to review @lhecker's PR yet but would you be able to build with his patch and see if it works for you?

[targodan]

This didn't seem to fix it. Or I did something wrong.

This is what I did:

git clone https://github.com/mholt/caddy.git
cd caddy
git checkout a2261e610bd27426c2a4f07a066ed706ca0e9e49
cd caddy
./build.bash
sudo ./caddy -conf .......

Then I ran my test again from here and I still got the following error:

client_test.go:163: Error while reading from stream.
client_test.go:164: rpc error: code = Internal desc = server closed the stream without sending trailers

[lhecker]

@mholt @targodan I'm currently in the process of moving which is why I'm so short on time regarding this bug.

---

This didn't seem to fix it. Or I did something wrong.

Either I did something wrong when testing your code or you indeed did something differently or wrong.
Here's what I did:

• I applied the following changes to make the code compile correctly

NOTE: With Go you should try and set up a workspace and always use fully specified import paths instead of relative ones.

diff --git a/client/client.go b/client/client.go
index 145ebe4..129a336 100644
--- a/client/client.go
+++ b/client/client.go
@@ -6,7 +6,7 @@ import (
    "crypto/tls"
    "os"

-   "./pb"
+   "github.com/targodan/caddyGrpcTest/client/pb"
    "google.golang.org/grpc"
    "google.golang.org/grpc/credentials"
 )
diff --git a/client/client_test.go b/client/client_test.go
index 6cd1215..15c4dbc 100644
--- a/client/client_test.go
+++ b/client/client_test.go
@@ -8,7 +8,7 @@ import (
    "strings"
    "testing"

-   "./pb"
+   "github.com/targodan/caddyGrpcTest/client/pb"
 )

 var connHosts []string
diff --git a/server/main.go b/server/main.go
index d5640ce..d369c9f 100644
--- a/server/main.go
+++ b/server/main.go
@@ -2,7 +2,7 @@
 //go:generate protoc -I "../proto/" "../proto/service.proto" --go_out=plugins=grpc:server/pb
 package main

-import "./server"
+import "github.com/targodan/caddyGrpcTest/server/server"
 import "os"
 import "fmt"

diff --git a/server/server/server.go b/server/server/server.go
index d2e2974..bd92f5c 100644
--- a/server/server/server.go
+++ b/server/server/server.go
@@ -7,7 +7,7 @@ import (
    "net"
    "os"

-   "./pb"
+   "github.com/targodan/caddyGrpcTest/server/server/pb"

    "golang.org/x/net/context"

• Compiled caddy

git pull --all
git checkout fix_1502
cd caddy
./build.bash

• Compiled caddyGrpcTest

cd client
go generate
cd ../server
go generate

• Start caddy

sudo ./caddy -conf Caddyfile -host localhost -port 443 -log=stdout

• Start the server (in terminal tab 1)

cd server
go run main.go ":4242"

• Run the client tests directly (in terminal tab 2)

cd client
TEST_HOSTS="127.0.0.1:4242" go test

Results in:

PASS
ok      github.com/targodan/caddyGrpcTest/client    0.034s

• Run the client tests over caddy (in terminal tab 2)

TEST_HOSTS="127.0.0.1:443" go test

Results in:

PASS
ok      github.com/targodan/caddyGrpcTest/client    0.033s

---

Did I do something wrong here?

[targodan]

Sorry, I made the mistake. 🙈

Thank you @lhecker for your work and the detailed information on how you tested it.

I compiled caddy outside of the gopath wich propably caused it to use the not-updated version from my gopath for any imports.

The fix works. 😄

PS: I didn't close the issue yet because I don't know if you guys keep issues open until the release is out or not. As far as I am concerned it can be closed.