caddy: Reverse proxying GRPC calls does not work

@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?

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.

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.

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?