Skip to content

gRPC-JSON Transcoder did not response with 504 when route timeout reached #2275

@arifsetiawan

Description

@arifsetiawan

Issue Template

Title: gRPC-JSON Transcoder did not response with 504 when route timeout reached

Description:

.proto

syntax = "proto3";

package helloworld;
import "annotations.proto";

// The greeting service definition.
service Greeter {
  // Sends a greeting
  rpc SayHello (HelloRequest) returns (HelloReply) {
    option (google.api.http) = {
      post: "/simple/v0.1.0/hello"
      body: "*"
    };
  }
}

// The request message containing the user's name.
message HelloRequest {
  string name = 1;
}

// The response message containing the greetings
message HelloReply {
  string message = 1;
}

Golang server

package main

import (
	"fmt"
	"log"
	"net"
	"time"

	pb "gitlab.com/artoz/grpc-go-simple/helloworld"
	"golang.org/x/net/context"
	"google.golang.org/grpc"
	"google.golang.org/grpc/codes"
	"google.golang.org/grpc/reflection"
	"google.golang.org/grpc/status"
)

const (
	port = ":50051"
)

// server is used to implement helloworld.GreeterServer.
type server struct{}

// SayHello implements helloworld.GreeterServer
func (s *server) SayHello(ctx context.Context, in *pb.HelloRequest) (*pb.HelloReply, error) {
	fmt.Println(time.Now().Format(time.RFC3339), "Incoming request", in)
	if in.Name == "timeout" {
                // sleep for some time because this is long process
		time.Sleep(90 * time.Second)
		fmt.Println(time.Now().Format(time.RFC3339), "Send response", codes.DeadlineExceeded)
		return nil, status.Error(codes.DeadlineExceeded, in.Name)
	}

	if in.Name == "internal" {
		fmt.Println(time.Now().Format(time.RFC3339), "Send response", codes.Internal)
		return nil, status.Error(codes.Internal, in.Name)
	}

	fmt.Println(time.Now().Format(time.RFC3339), "Send response", "Hello "+in.Name)
	return &pb.HelloReply{Message: "Hello " + in.Name}, nil
}

func main() {
	lis, err := net.Listen("tcp", port)
	if err != nil {
		log.Fatalf("failed to listen: %v", err)
	}
	s := grpc.NewServer()
	pb.RegisterGreeterServer(s, &server{})
	// Register reflection service on gRPC server.
	reflection.Register(s)
	if err := s.Serve(lis); err != nil {
		log.Fatalf("failed to serve: %v", err)
	}
}

Envoy version

envoy 0a355de4999ecf3d05c78857137ed5b04cef7f11/Clean/RELEASE live 343 343 0

Envoy config

{
    "listeners": [{
        "address": "tcp://0.0.0.0:80",
        "filters": [{
            "type": "read",
            "name": "http_connection_manager",
            "config": {
                "server_name": "nextapi",
                "codec_type": "auto",
                "stat_prefix": "ingress_http",
                "use_remote_address": true,
                "access_log": [{"path": "/tmp/envoy.access.log"}],
                "route_config": {
                    "virtual_hosts": [{
                        "name": "grpc_service",
                        "domains": ["*"],
                        "routes": [{
                            "prefix": "/",
                            "cluster": "grpc1",
                            "timeout_ms": 5000
                        }]
                    }]
                },
                "filters": [
                    {
                        "type": "both",
                        "name": "grpc_json_transcoder",
                        "config": {
                            "proto_descriptor": "/etc/helloworld.pb",
                            "services": ["helloworld.Greeter"],
                            "print_options": {
                                "add_whitespace": false,
                                "always_print_primitive_fields": false,
                                "always_print_enums_as_ints": false,
                                "preserve_proto_field_names": false
                            }
                        }
                    },    
                    {
                        "type": "decoder",
                        "name": "router",
                        "config": {}
                    },
                    {
                        "name": "cors",
                        "config": {}
                    }
                ]
            }
        }]
    }],
    "admin": {
        "access_log_path": "/tmp/admin_access.log",
        "address": "tcp://0.0.0.0:9901"
    },
    "cluster_manager": {
        "clusters": [{
            "name": "grpc1",
            "connect_timeout_ms": 250,
            "type": "static",
            "lb_type": "random",
            "features": "http2",
            "hosts": [
                {"url": "tcp://192.168.99.100:50051"} 
            ]
        }]
    }
}

If I tried with Node.js grpc client

var PROTO_PATH = __dirname + '/helloworld.proto';
var grpc = require('grpc');
var proto = grpc.load(PROTO_PATH).helloworld;

function main() {
  var client = new proto.Greeter('192.168.99.100:80',grpc.credentials.createInsecure());

  var hrstart = process.hrtime();
  client.sayHello({name: "timeout"},function(err, response) {
    if (err) {
        console.error(err)
    }

    hrend = process.hrtime(hrstart);
    console.info("Execution time (hr): %ds %dms", hrend[0], hrend[1]/1000000);
    console.log(response)
  });
}

main()

I will get following error message after several seconds

{ Error: Received http2 header with status: 504
    at /Users/arifsetiawan/Repository/Artoz/apiserver-envoy/client/node_modules/grpc/src/client.js:554:15 code: 1, metadata: Metadata { _internal_repr: {} } }
Execution time (hr): 7s 916.071999ms

I think is coming from Envoy because of route timeout setting.

If I use curl to access HTTP API, I expect HTTP API should also response with HTTP status 504. I found that I don't get error reply from server and connection keep open

curl -X POST http://192.168.99.100/simple/v0.1.0/hello -d '{"name":"timeout"}' -v
*   Trying 192.168.99.100...
* Connected to 192.168.99.100 (192.168.99.100) port 80 (#0)
> POST /simple/v0.1.0/hello HTTP/1.1
> Host: 192.168.99.100
> User-Agent: curl/7.43.0
> Accept: */*
> Content-Length: 18
> Content-Type: application/x-www-form-urlencoded
> 
* upload completely sent off: 18 out of 18 bytes
``

Metadata

Metadata

Assignees

Labels

questionQuestions that are neither investigations, bugs, nor enhancements

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions