Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

No grpc reponse from Javascript client request #9452

Closed
DaveO-Home opened this issue Nov 1, 2024 · 33 comments · Fixed by #9505
Closed

No grpc reponse from Javascript client request #9452

DaveO-Home opened this issue Nov 1, 2024 · 33 comments · Fixed by #9505
Assignees
Labels

Comments

@DaveO-Home
Copy link

The Helidon gRPC correctly accepts the Javascript gRPC request. However, there is no or just null response from the server.

Environment Details

build.date 2023-08-03 16:19:35 UTC
build.version 3.0.6
build.revision 0c0d6790
project.version 1.0.0
project.helidon.version 4.1.2
project.flavor MP
latest.helidon.version 4.1.3
default.helidon.version 4.1.3
Java(TM) SE Runtime Environment Oracle GraalVM 21.0.2+13.1 (build 21.0.2+13-LTS-jvmci-23.1-b30)
Java HotSpot(TM) 64-Bit Server VM Oracle GraalVM 21.0.2+13.1 (build 21.0.2+13-LTS-jvmci-23.1-b30, mixed mode, sharing)


Sample Code:


import com.google.protobuf.Descriptors;
import golf.handicap.Golfer;
import handicap.grpc.HandicapData;
import handicap.grpc.HandicapProto;
import handicap.grpc.HandicapSetup;
import io.grpc.stub.StreamObserver;
import io.helidon.grpc.core.ResponseHelper;
import io.helidon.webserver.grpc.GrpcService;
import jakarta.json.Json;
import jakarta.json.JsonObject;
import jakarta.json.bind.JsonbBuilder;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class HandicapService implements GrpcService {
    private static final Logger logger = LogManager.getLogger(HandicapService.class.getName());

    public HandicapService() {
    }

    public void getGolfer(HandicapSetup request, StreamObserver<HandicapData> observer) {
        logger.info("Doing GetGolfer***********************: {}", request);
        JsonObject requestJson = Json.createObjectBuilder().add("data", request.getJson()).build();
        Golfer currentGolfer = JsonbBuilder.create().fromJson(requestJson.getString("data"), Golfer.class);
        /*
            Call logic with (currentGolfer) not implemented - sending back requested data
        */
        logger.info("Returning Data: {}", requestJson.getJsonString("data").getString());
        HandicapData handicapData = HandicapData.newBuilder()
          .setMessage("No Golfer Found")
          .setCmd(request.getCmd())
          .setJson(requestJson.getJsonString("data").getString())
          .build();
        ResponseHelper.complete(observer, handicapData);
    }

    @Override
    public Descriptors.FileDescriptor proto() {
        return HandicapProto.getDescriptor();
    }

    @Override
    public void update(Routing routing) {
        routing.unary(
          "GetGolfer", this::getGolfer
        );
    }
}

The proto:

// import "google/protobuf/struct.proto";

option java_multiple_files = true;
option java_package = "handicap.grpc";
option java_outer_classname = "HandicapProto";

package handicap.grpc;

service HandicapService {
  rpc ListCourses(Command) returns (ListCoursesResponse) {}
  rpc AddRating(Command) returns (HandicapData) {}
  rpc AddScore(Command) returns (HandicapData) {}
  rpc RemoveScore(Command) returns (HandicapData) {}
  rpc GolferScores(Command) returns (HandicapData) {}
  rpc GetGolfer (HandicapSetup) returns (HandicapData) {}
  rpc ListGolfers (Command) returns (ListPublicGolfers) {}
}

message HandicapSetup {
  int32 cmd = 1;
  string json = 2;
  string message = 3;
}

message HandicapData {
  int32 cmd = 1;
  string json = 2;
  string message = 3;
}

message Rating {
  int32 tee = 1;
  string rating = 2;
  int32 slope = 3;
  int32 par = 4;
  string color = 5;
  int32 seq = 6;
}
message Course {
  int32 id = 1;
  string name = 2;
  repeated Rating ratings = 3;
}

message ListCoursesResponse {
  repeated Course courses = 1;
}

message Golfer {
  string name = 1;
}

message ListPublicGolfers {
  repeated Golfer golfer = 1;
}

message Command {
  int32 cmd = 1;
  string key = 2;
  string json = 3;
}

The data the Helidon server accepts:

2024-10-31 17:09:11 (HandicapService:25) - INFO Doing GetGolfer***********************: cmd: 3
json: "{\"pin\":\"xx1234\",\"firstName\":\"\",\"lastName\":\"\",\"country\":\"US\",\"state\":\"AL\",\"overlap\":false,\"public\":false,\"status\":0,\"lastLogin\":\"1730419751853\",\"course\":\"\",\"tee\":\"2\",\"teeDate\":\"1730419751853\"}"
message: "Golfer Data"  #105  

Data the Server responses with:

2024-10-31 17:09:11 (HandicapService:29) - INFO Returning Data: 2024-10-31 17:35:23 (HandicapService:36) - INFO Returning Data:
 cmd: 3
json: "{\"pin\":\"xx1234\",\"firstName\":\"\",\"lastName\":\"\",\"country\":\"US\",\"state\":\"AL\",\"overlap\":false,\"public\":false,\"status\":0,\"lastLogin\":\"1730421323634\",\"course\":\"\",\"tee\":\"2\",\"teeDate\":\"1730421323634\"}"
message: "No Golfer Found" #105

Note: There is an Envoy proxy between the client/server. Does CORS and HTTP: 2

@DaveO-Home
Copy link
Author

"Is your Javascript client assuming dynamic resolution of the proto file?"
The client only posts the application data, it might be passing meta data under the covers.
I don't see that the poxy is an issue because the grpcurl query works.

grpcurl -plaintext -d '{"cmd":3,"json":"{\"pin\":\"do1234\"}","message":"get golfer"}'
 -vv -proto src/main/proto/handicap.proto localhost:8071 handicap.grpc.HandicapService/GetGolfer

port 8071 is the proxy. The query also works via port 8061 the helidon webserver port since grpcurl works with http2. But again the proto file is required.

@spericas
Copy link
Member

spericas commented Nov 1, 2024

@DaveO-Home Could provide more info about the JS client part? The library and the JS client code that gets a null response?

@DaveO-Home
Copy link
Author

DaveO-Home commented Nov 1, 2024

You can find the code at:
https://github.com/DaveO-Home/dodex-quarkus/tree/master/src/grpc/client
This is a Quarkus framework that has the same code. The only difference is that in the handiap.proto file the Service was changed for HandicapIndex to HandicapService.
Files of interest:
proto bash script that generates the code in ./js/handicap, the gRPC javascript client. The proto is in ./protos/handicap/
This same setup on Quarkus works without the -proto parameter.

@spericas
Copy link
Member

spericas commented Nov 1, 2024

Related to issue #9454

@DaveO-Home
Copy link
Author

Thanks, - Question, why does the request work and the response fails. Doesn't the request require reflection?

@barchetta barchetta moved this from Triage to Normal priority in Backlog Nov 4, 2024
@DaveO-Home
Copy link
Author

I added a health Check and it's response seems to work:

public class HandicapServiceHealthCheck implements HealthCheck {
    private static final Logger logger = LogManager.getLogger(HandicapServiceHealthCheck.class.getName());
    private final WebClient webClient;
    private CountDownLatch latch;
    private volatile boolean readiness = true;

    public HandicapServiceHealthCheck(Config config) {
        // set up client to access gRPC service
        Tls clientTls = Tls.builder().enabled(false).build();

        this.webClient = WebClient.builder()
          .tls(clientTls)
          .baseUri("http://localhost:" + 8061) // serverPort)
          .build();
        logger.info("Starting Health Check!");
    }

    @Override
    public String name() {
        return HandicapService.class.getSimpleName();
    }

    @Override
    public HealthCheckType type() {
        return HealthCheckType.READINESS;
    }

    @Override
    public HealthCheckResponse call() {
        if (latch == null) {
            latch = new CountDownLatch(1);
            Scheduling.fixedRate()          // task to check for readiness
              .delay(1)
              .initialDelay(0)
              .timeUnit(TimeUnit.MINUTES)
              .task(i -> checkReadiness())
              .build();
        }
        try {
            boolean check = latch.await(5, TimeUnit.SECONDS);
            return HealthCheckResponse.builder()
              .status(check && readiness)
              .get();
        } catch (Exception e) {
            logger.info("Response status: {}", e.getMessage());
            return HealthCheckResponse.builder()
              .status(false)
              .get();
        }
    }

    /**
     * Self-invocation to verify gRPC endpoint is available and ready.
     */
    private void checkReadiness() {
        try {
            GrpcClient grpcClient = webClient.client(GrpcClient.PROTOCOL);
            HandicapServiceGrpc.HandicapServiceBlockingStub service =
              HandicapServiceGrpc.newBlockingStub(grpcClient.channel());
            HandicapData res = service.getGolfer(
              HandicapSetup.newBuilder().setMessage("Get Golfer").setCmd(3).setJson("{\"pin\":\"XX1234\"}").build());
            readiness = res.getMessage().equals("No Golfer Found");
            logger.info("Response: {} -- {}", readiness, res);
        } catch (Exception e) {
            readiness = false;
            logger.info("CheckReadiness: {}", e.getMessage());
        } finally {
            latch.countDown();
        }
    }
}

Executed http://localhost:8061/health and got:

json: "{\"pin\":\"XX1234\"}"
message: "Get Golfer"
 #110  
2024-11-04 11:53:57 (HandicapService:36) - INFO Returning Data: cmd: 3
json: "{\"pin\":\"XX1234\"}"
message: "No Golfer Found"
 #110  
2024-11-04 11:53:57 (HandicapServiceHealthCheck:90) - INFO Response: true -- cmd: 3
json: "{\"pin\":\"XX1234\"}"
message: "No Golfer Found"
 #105

The reponse data was set in the HandicapService. The response works here.

@DaveO-Home
Copy link
Author

I was also able to run the Health Check from a remote Java gRPC web client using a main class.


package my.jsc.scripts;
import java.io.File;
import java.util.logging.*;
import com.google.protobuf.*;

import io.helidon.config.Config;
import io.helidon.common.tls.Tls;
import io.helidon.webclient.api.WebClient;
import io.helidon.webclient.grpc.GrpcClient;
import handicap.grpc.*;

import java.io.*;
import java.util.*;
import java.lang.*;
import jin.shell.Shell;
import jin.shell.factory.JScript;
import jin.shell.GetParameters;

public class TestIt extends Shell implements JScript {
public TestIt() { super(); }
        String _argv_[] = null;
public static void main(String[] argv) throws Exception
{
        new TestIt().program(GetParameters.getParameters(argv));
}
   private WebClient webClient;
   private Boolean readiness;

   public void program(Hashtable h) throws Exception {

        Config config = Config.empty();
        Config.global(config);

        Tls clientTls = Tls.builder().enabled(false).build();

        this.webClient = WebClient.builder()
          .tls(clientTls)
          .baseUri("http://localhost:" + 8061)  // http/2 only 
          .build();
        System.out.println("Starting Health Check!");
        checkReadiness();

   }

   private void checkReadiness() {
        try {
            GrpcClient grpcClient = webClient.client(GrpcClient.PROTOCOL);
            HandicapServiceGrpc.HandicapServiceBlockingStub service =
            HandicapServiceGrpc.newBlockingStub(grpcClient.channel());

            System.out.println("Channel: "+ grpcClient.channel().authority());

            System.out.println("Sending...");
            int cmd = 3;
            String message = "Get Golfer";
            String json = "{\"pin\":\"XX1234\"}";
            System.out.println("Data: " + cmd + " -- " + message + " -- " + json);

            HandicapData res = service.getGolfer(
            HandicapSetup.newBuilder().setMessage(message).setCmd(cmd).setJson(json).build());
            readiness = res.getMessage().equals("No Golfer Found");

            System.out.println("\nMessage Correct? + Response: " + readiness + " -- " + res);

        } catch (Exception e) {
            readiness = false;
            System.out.println("CheckReadiness: " + e.getMessage());
        } finally {
             System.out.println("gRPC call finished");
        }
   }

}

Results: No proto file required.....Too bad I can't run this is a browser.

Starting Health Check!
Channel: localhost:8061
Sending...
Data: 3 -- Get Golfer -- {"pin":"XX1234"}

Message Correct? + Response: true -- cmd: 3
json: "{\"pin\":\"XX1234\"}"
message: "No Golfer Found"

gRPC call finished
                               2,1           Top

@spericas spericas moved this from Normal priority to In Progress in Backlog Nov 7, 2024
@spericas spericas moved this from In Progress to Sprint Scope in Backlog Nov 7, 2024
@spericas
Copy link
Member

spericas commented Nov 8, 2024

@DaveO-Home Finally found some time to look at this. I've set up an env to test this e2e with Envoy etc. The behavior I'm seeing is a bit different than yours: I see an HTTP2 problem when Envoy connects to the Helidon endpoint. I'm currently investigating, but Envoy is basically reporting an "HTTP violation.

How did you configure your Envoy yaml file for the upstream Helidon endpoint? This requires setting up TLS

@DaveO-Home
Copy link
Author

DaveO-Home commented Nov 8, 2024

@spericas From what I understand Envoy does the upgrade to http/2 automatically - here's my config:

admin:
 access_log_path: /tmp/admin_access.log
 address:
   socket_address:
     address: 0.0.0.0
     port_value: 9901
static_resources:
  listeners:
    - name: listener_01
      address:
        socket_address: { address: 0.0.0.0, port_value: 8071 }
      filter_chains:
        - filters:
          - name: envoy.filters.network.http_connection_manager
            typed_config:
              "@type": type.googleapis.com/envoy.extensions.filters.network.http_connection_manager.v3.HttpConnectionManager
              codec_type: auto
              stat_prefix: ingress_http
              route_config:
                name: local_route
                virtual_hosts:
                  - name: local_service
                    domains: ["*"]
                    routes:
                      - match: { prefix: "/handicap" }
                        route:
                          cluster: handicap_service
                          max_stream_duration:
                            grpc_timeout_header_max: 0s
                    cors:
                      allow_origin_string_match:
                        - prefix: "*"
                      allow_methods: GET, PUT, DELETE, POST, OPTIONS
                      allow_headers: keep-alive,user-agent,cache-control,content-type,content-transfer-encoding,custom-header-1,x-accept-content-transfer-encoding,x-accept-response-streaming,x-user-agent,x-grpc-web,grpc-timeout
                      max_age: "1728000"
                      expose_headers: custom-header-1,grpc-status,grpc-message
              http_filters:
                - name: envoy.filters.http.grpc_web
                  typed_config:
                    "@type": type.googleapis.com/envoy.extensions.filters.http.grpc_web.v3.GrpcWeb
                - name: envoy.filters.http.cors
                  typed_config:
                    "@type": type.googleapis.com/envoy.extensions.filters.http.cors.v3.Cors
                - name: envoy.filters.http.router
                  typed_config:
                    "@type": type.googleapis.com/envoy.extensions.filters.http.router.v3.Router
  clusters:
    - name: handicap_service
      connect_timeout: 0.25s
      type: logical_dns
      http2_protocol_options: {}
      lb_policy: round_robin
      load_assignment:
        cluster_name: cluster_0
        endpoints:
          - lb_endpoints:
            - endpoint:
                address:
                  socket_address:
                    address: 0.0.0.0
                    port_value: 8061

The query gets to the helidon server but the response gets lost. ??

Here's my Helidon Server Code: Notice, the main application uses Helidon MP and gRPC uses Helidon SE. I couldn't get gRPC to work with MP.

package dmo.fs.server;

import dmo.fs.routes.HandicapService;
import dmo.fs.routes.HandicapServiceHealthCheck;
import dmo.fs.util.ColorUtilConstants;
import dmo.fs.util.DodexUtil;
import io.helidon.config.Config;
import io.helidon.logging.common.HelidonMdc;
import io.helidon.microprofile.server.Server;
import io.helidon.webserver.WebServer;
import io.helidon.webserver.grpc.GrpcRouting;
import io.helidon.webserver.observe.ObserveFeature;
import io.helidon.webserver.observe.health.HealthObserver;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.eclipse.microprofile.config.ConfigProvider;

import java.io.File;
import java.io.IOException;
import java.sql.SQLException;

public final class DodexMain {
    private static final Logger LOGGER = LogManager.getLogger(DodexMain.class.getName());
    public static org.eclipse.microprofile.config.Config config = ConfigProvider.getConfig();

    private DodexMain() {
    }

    public static void main(final String[] args) throws IOException, SQLException, InterruptedException {
        Config config = Config.empty(); // .create();
        Config.global(config);
        Config serverConfig = config.get("server");

        Server server = startServer();
        WebServer webServer = startServer(serverConfig);
        HelidonMdc.set("name", "Nima");
        checkInstallation();
    }
    /* gRPC Server */
    static WebServer startServer(Config serverConfig) {
        ObserveFeature observe = ObserveFeature.builder()
          .addObserver(HealthObserver.builder()
            .config(serverConfig.get("server.features.observe")) // .get("features.observe.observers.health"))
            .addCheck(new HandicapServiceHealthCheck(serverConfig))
            .build())
          .build();

              return WebServer.builder()
                .host("0.0.0.0")
                .port(8061)
                .addRouting(GrpcRouting.builder().service(new HandicapService()))
                .addFeature(observe)
                .build()
                .start();
    }

    static Server startServer() {
        LOGGER.info("Starting Http Server");

        return Server.create().start();
    }

    static void checkInstallation() {
        String fileDir = "./src/main/resources/WEB/static/node_modules/";
        File checkDir = new File(fileDir);
        String mode = DodexUtil.getMode();
        if("dev".equals(mode)) {
            if (!checkDir.exists()) {
                LOGGER.warn("{}{}{}", ColorUtilConstants.CYAN_BOLD_BRIGHT,
                  "To install Dodex, execute 'npm install' in 'src/main/resources/WEB/static/'"
                  , ColorUtilConstants.RESET);
            }
        }
        fileDir = "./src/grpc/client/node_modules/";
        checkDir = new File(fileDir);
        mode = DodexUtil.getMode();
        if("dev".equals(mode)) {
            if (!checkDir.exists()) {
                LOGGER.warn("{}{}{}", ColorUtilConstants.CYAN_BOLD_BRIGHT,
                  "To install gRPC, execute 'npm install' in 'src/grpc/client/' and 'npm run esbuild:prod' or 'npm run webpack:prod'"
                  , ColorUtilConstants.RESET);
            }
        }
    }
}

@spericas
Copy link
Member

spericas commented Nov 8, 2024

@DaveO-Home I am seeing a problem in the Envoy log, but in my case, it is happening early in the request process so the gRPC endpoint is never called. Details below.

Is there any chance you can turn on logging for Envoy to see what it reports in your environment? I'm running it outside of Docker, so if you are using Docker, you'd need to update the corresponding Dockerfile:

envoy -l debug -c net/grpc/gateway/examples/echo/envoy.yaml

Here are the details of the error that I'm seeing:

[2024-11-08 15:38:25.724][294921][debug][pool] [source/common/conn_pool/conn_pool_base.cc:182] [Tags: "ConnectionId":"1"] creating stream
[2024-11-08 15:38:25.724][294921][debug][router] [source/common/router/upstream_request.cc:593] [Tags: "ConnectionId":"0","StreamId":"9651045886242334412"] pool ready
[2024-11-08 15:38:25.724][294921][debug][client] [source/common/http/codec_client.cc:142] [Tags: "ConnectionId":"1"] encode complete
[2024-11-08 15:38:25.774][294921][debug][http2] [source/common/http/http2/codec_impl.cc:1323] [Tags: "ConnectionId":"1"] invalid frame: Violation in HTTP messaging rule on stream 1
[2024-11-08 15:38:25.774][294921][debug][client] [source/common/http/codec_client.cc:171] [Tags: "ConnectionId":"1"] Error dispatching received data: The user callback function failed
[2024-11-08 15:38:25.774][294921][debug][connection] [source/common/network/connection_impl.cc:150] [Tags: "ConnectionId":"1"] closing data_to_write=0 type=1
[2024-11-08 15:38:25.774][294921][debug][connection] [source/common/network/connection_impl.cc:276] [Tags: "ConnectionId":"1"] closing socket: 1
[2024-11-08 15:38:25.774][294921][debug][client] [source/common/http/codec_client.cc:107] [Tags: "ConnectionId":"1"] disconnect. resetting 1 pending requests
[2024-11-08 15:38:25.774][294921][debug][client] [source/common/http/codec_client.cc:159] [Tags: "ConnectionId":"1"] request reset

Issue seems to be "Violation in HTTP messaging".

@DaveO-Home
Copy link
Author

The section where I call the server using the javascript client:

2024-11-08 12:52:54.687][21209][debug] [external/envoy/source/server/active_tcp_listener.cc:328] [C0] new connection
[2024-11-08 12:52:54.689][21209][debug] [external/envoy/source/common/http/conn_manager_impl.cc:261] [C0] new stream
[2024-11-08 12:52:54.690][21209][debug] [external/envoy/source/common/http/conn_manager_impl.cc:882] [C0][S9326661871979922665] request headers complete (end_stream=true):
':authority', 'localhost:8071'
':path', '/handicap.grpc.HandicapService/GetGolfer'
':method', 'OPTIONS'
'user-agent', 'Mozilla/5.0 (X11; Linux x86_64; rv:132.0) Gecko/20100101 Firefox/132.0'
'accept', '*/*'
'accept-language', 'en-US,en;q=0.5'
'accept-encoding', 'gzip, deflate, br, zstd'
'access-control-request-method', 'POST'
'access-control-request-headers', 'content-type,x-grpc-web,x-user-agent'
'referer', 'http://localhost:8060/'
'origin', 'http://localhost:8060'
'connection', 'keep-alive'
'sec-fetch-dest', 'empty'
'sec-fetch-mode', 'cors'
'sec-fetch-site', 'same-site'
'priority', 'u=4'
'pragma', 'no-cache'
'cache-control', 'no-cache'

[2024-11-08 12:52:54.690][21209][debug] [external/envoy/source/common/http/filter_manager.cc:779] [C0][S9326661871979922665] request end stream
[2024-11-08 12:52:54.690][21209][debug] [external/envoy/source/common/http/conn_manager_impl.cc:1455] [C0][S9326661871979922665] encoding headers via codec (end_stream=true):
':status', '200'
'access-control-allow-origin', 'http://localhost:8060'
'access-control-allow-methods', 'GET, PUT, DELETE, POST, OPTIONS'
'access-control-allow-headers', 'keep-alive,user-agent,cache-control,content-type,content-transfer-encoding,custom-header-1,x-accept-content-transfer-encoding,x-accept-response-streaming,x-user-agent,x-grpc-web,grpc-timeout'
'access-control-max-age', '1728000'
'access-control-expose-headers', 'custom-header-1,grpc-status,grpc-message'
'date', 'Fri, 08 Nov 2024 20:52:54 GMT'
'server', 'envoy'
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/http/conn_manager_impl.cc:882] [C0][S1205770673130837713] request headers complete (end_stream=false):
':authority', 'localhost:8071'
':path', '/handicap.grpc.HandicapService/GetGolfer'
':method', 'POST'
'user-agent', 'Mozilla/5.0 (X11; Linux x86_64; rv:132.0) Gecko/20100101 Firefox/132.0'
'accept', 'application/grpc-web-text'
'accept-language', 'en-US,en;q=0.5'
'accept-encoding', 'gzip, deflate, br, zstd'
'content-type', 'application/grpc-web-text'
'x-user-agent', 'grpc-web-javascript/0.1'
'x-grpc-web', '1'
'content-length', '288'
'origin', 'http://localhost:8060'
'connection', 'keep-alive'
'referer', 'http://localhost:8060/'
'sec-fetch-dest', 'empty'
'sec-fetch-mode', 'cors'
'sec-fetch-site', 'same-site'
'priority', 'u=0'
'pragma', 'no-cache'
'cache-control', 'no-cache'

[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/router/router.cc:445] [C0][S1205770673130837713] cluster 'handicap_service' match for URL '/handicap.grpc.HandicapService/GetGolfer'
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/router/router.cc:631] [C0][S1205770673130837713] router decoding headers:
':authority', 'localhost:8071'
':path', '/handicap.grpc.HandicapService/GetGolfer'
':method', 'POST'
':scheme', 'http'
'user-agent', 'Mozilla/5.0 (X11; Linux x86_64; rv:132.0) Gecko/20100101 Firefox/132.0'
'accept', 'application/grpc-web-text'
'access-control-max-age', '1728000'
'access-control-expose-headers', 'custom-header-1,grpc-status,grpc-message'
'date', 'Fri, 08 Nov 2024 20:52:54 GMT'
'server', 'envoy'

[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/http/conn_manager_impl.cc:261] [C0] new stream
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/http/conn_manager_impl.cc:882] [C0][S1205770673130837713] request headers complete (end_stream=false):
':authority', 'localhost:8071'
':path', '/handicap.grpc.HandicapService/GetGolfer'
':method', 'POST'
'user-agent', 'Mozilla/5.0 (X11; Linux x86_64; rv:132.0) Gecko/20100101 Firefox/132.0'
'accept', 'application/grpc-web-text'
'accept-language', 'en-US,en;q=0.5'
'accept-encoding', 'gzip, deflate, br, zstd'
'content-type', 'application/grpc-web-text'
'x-user-agent', 'grpc-web-javascript/0.1'
'x-grpc-web', '1'
'content-length', '288'
'origin', 'http://localhost:8060'
'connection', 'keep-alive'
'referer', 'http://localhost:8060/'
'sec-fetch-dest', 'empty'
'sec-fetch-mode', 'cors'
'sec-fetch-site', 'same-site'
'priority', 'u=0'
'pragma', 'no-cache'
'cache-control', 'no-cache'

[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/router/router.cc:445] [C0][S1205770673130837713] cluster 'handicap_service' match for URL '/handicap.grpc.HandicapService/GetGolfer'
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/router/router.cc:631] [C0][S1205770673130837713] router decoding headers:
':authority', 'localhost:8071'
':path', '/handicap.grpc.HandicapService/GetGolfer'
':method', 'POST'
':scheme', 'http'
'user-agent', 'Mozilla/5.0 (X11; Linux x86_64; rv:132.0) Gecko/20100101 Firefox/132.0'
'accept', 'application/grpc-web-text'
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/http/conn_pool_base.cc:74] queueing stream due to no available connections
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/conn_pool/conn_pool_base.cc:241] trying to create new connection
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/conn_pool/conn_pool_base.cc:143] creating a new connection
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/http/codec_client.cc:43] [C1] connecting
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/network/connection_impl.cc:860] [C1] connecting to 0.0.0.0:8061
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/network/connection_impl.cc:876] [C1] connection in progress
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/http/http2/codec_impl.cc:1222] [C1] updating connection-level initial window size to 268435456
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/http/filter_manager.cc:779] [C0][S1205770673130837713] request end stream
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/network/connection_impl.cc:665] [C1] connected
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/http/codec_client.cc:82] [C1] connected
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/conn_pool/conn_pool_base.cc:275] [C1] attaching to next stream
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/conn_pool/conn_pool_base.cc:171] [C1] creating stream
[2024-11-08 12:52:54.691][21209][debug] [external/envoy/source/common/router/upstream_request.cc:371] [C0][S1205770673130837713] pool ready
[2024-11-08 12:52:54.732][21209][debug] [external/envoy/source/common/router/router.cc:1244] [C0][S1205770673130837713] upstream headers complete: end_stream=false
[2024-11-08 12:52:54.732][21209][debug] [external/envoy/source/common/http/conn_manager_impl.cc:1455] [C0][S1205770673130837713] encoding headers via codec (end_stream=false):
':status', '200'
'content-type', 'application/grpc-web-text+proto'
'grpc-encoding', 'identity'
'x-envoy-upstream-service-time', '40'
'access-control-allow-origin', 'http://localhost:8060'
'access-control-expose-headers', 'custom-header-1,grpc-status,grpc-message'
'date', 'Fri, 08 Nov 2024 20:52:54 GMT'
'server', 'envoy'

[2024-11-08 12:52:54.732][21209][debug] [external/envoy/source/common/http/codec_client.cc:124] [C1] response complete
[2024-11-08 12:52:54.732][21209][debug] [external/envoy/source/common/conn_pool/conn_pool_base.cc:200] [C1] destroying stream: 0 remaining
[2024-11-08 12:52:54.732][21209][debug] [external/envoy/source/common/http/conn_manager_impl.cc:1471] [C0][S1205770673130837713] encoding trailers via codec:

[2024-11-08 12:52:54.732][21209][debug] [external/envoy/source/common/http/http2/codec_impl.cc:997] [C1] stream closed: 0
[2024-11-08 12:52:55.844][21176][debug] [external/envoy/source/common/upstream/logical_dns_cluster.cc:105] starting async DNS resolution for 0.0.0.0
[2024-11-08 12:52:55.844][21176][debug] [external/envoy/source/common/upstream/logical_dns_cluster.cc:113] async DNS resolution complete for 0.0.0.0
[2024-11-08 12:52:55.844][21176][debug] [external/envoy/source/common/upstream/logical_dns_cluster.cc:159] DNS refresh rate reset for 0.0.0.0, refresh rate 5000 ms
[2024-11-08 12:52:55.848][21176][debug] [external/envoy/source/server/server.cc:209] flushing stats
[2024-11-08 12:53:00.845][21176][debug] [external/envoy/source/common/upstream/logical_dns_cluster.cc:105] starting async DNS resolution for 0.0.0.0
[2024-11-08 12:53:00.845][21176][debug] [external/envoy/source/common/upstream/logical_dns_cluster.cc:113] async DNS resolution complete for 0.0.0.0
                                                                                        1,1           Top

@DaveO-Home
Copy link
Author

@spericas What version of envoy are you using? I'm using:
envoy version: d362e791eb9e4efa8d87f6d878740e72dc8330ac/1.18.2/clean-getenvoy-76c310e-envoy/RELEASE/BoringSSL
I'm using envoy from the terminal.

@DaveO-Home
Copy link
Author

If you already haven't reviewed, here's a link:
https://grpc.io/docs/platforms/web/

@spericas
Copy link
Member

@spericas What version of envoy are you using? I'm using: envoy version: d362e791eb9e4efa8d87f6d878740e72dc8330ac/1.18.2/clean-getenvoy-76c310e-envoy/RELEASE/BoringSSL I'm using envoy from the terminal.

envoy version: e3b4a6e9570da15ac1caffdded17a8bebdc7dfc9/1.32.1/Clean/RELEASE/BoringSSL

@spericas
Copy link
Member

@DaveO-Home There's a clear difference in behavior between these two versions. Looks like the one you're using is from 21. We should work with the latest 1.32.1 to fix any problems.

@spericas
Copy link
Member

@DaveO-Home There's a clear difference in behavior between these two versions. Looks like the one you're using is from 21. We should work with the latest 1.32.1 to fix any problems.

I managed to get past the issue I reported, I'm now seeing the same behavior you describe. There's now a parsing/RPC error reported in the JS code. Using the latest envoy.

@DaveO-Home
Copy link
Author

If you already haven't reviewed, here's a link:
https://grpc.io/docs/platforms/web/

@DaveO-Home
Copy link
Author

DaveO-Home commented Nov 12, 2024

@spericas If you debug the response in the browser(I use firefox) you will see that the response is null.
Could you send me your fixed envoy config? I recently upgraded my linux system and things are broke. So can't do a whole lot at the moment.

@spericas
Copy link
Member

spericas commented Nov 12, 2024

admin:
  access_log_path: /tmp/admin_access.log
  address:
    socket_address: { address: 0.0.0.0, port_value: 9901 }

stats_flush_interval: 299s

static_resources:
  listeners:
    - name: listener_0
      address:
        socket_address: { address: 0.0.0.0, port_value: 8080 }
      filter_chains:
        - filters:
          - name: envoy.filters.network.http_connection_manager
            typed_config:
              "@type": type.googleapis.com/envoy.extensions.filters.network.http_connection_manager.v3.HttpConnectionManager
              codec_type: auto
              stat_prefix: ingress_http
              route_config:
                name: local_route
                virtual_hosts:
                  - name: local_service
                    domains: ["*"]
                    routes:
                      - match: { prefix: "/" }
                        route:
                          cluster: echo_service
                          timeout: 0s
                          max_stream_duration:
                            grpc_timeout_header_max: 0s
                    cors:
                      allow_origin_string_match:
                        - prefix: "*"
                      allow_methods: GET, PUT, DELETE, POST, OPTIONS
                      allow_headers: keep-alive,user-agent,cache-control,content-type,content-transfer-encoding,custom-header-1,x-accept-content-transfer-encoding,x-accept-response-streaming,x-user-agent,x-grpc-web,grpc-timeout
                      max_age: "1728000"
                      expose_headers: custom-header-1,grpc-status,grpc-message
              http_filters:
                - name: envoy.filters.http.grpc_web
                  typed_config:
                    "@type": type.googleapis.com/envoy.extensions.filters.http.grpc_web.v3.GrpcWeb
                - name: envoy.filters.http.cors
                  typed_config:
                    "@type": type.googleapis.com/envoy.extensions.filters.http.cors.v3.Cors
                - name: envoy.filters.http.router
                  typed_config:
                    "@type": type.googleapis.com/envoy.extensions.filters.http.router.v3.Router
  clusters:
    - name: echo_service
      connect_timeout: 10000s
      type: logical_dns
      dns_refresh_rate: 1000000s
      # HTTP/2 support
      typed_extension_protocol_options:
        envoy.extensions.upstreams.http.v3.HttpProtocolOptions:
          "@type": type.googleapis.com/envoy.extensions.upstreams.http.v3.HttpProtocolOptions
          explicit_http_config:
            http2_protocol_options: {}
      lb_policy: round_robin
      #transport_socket:
       # name: envoy.transport_sockets.tls
       # typed_config:
        #  "@type": type.googleapis.com/envoy.extensions.transport_sockets.tls.v3.UpstreamTlsContext
      load_assignment:
        cluster_name: cluster_0
        endpoints:
          - lb_endpoints:
            - endpoint:
                address:
                  socket_address:
                    address: localhost
                    port_value: 9090

@spericas
Copy link
Member

spericas commented Nov 12, 2024

@spericas If you debug the response in the browser(I use firefox) you will see that the response is null. Could you send me your fixed envoy config? I recently upgraded my linux system and things are broke. So can't do a whole lot at the moment.

The response back from Envoy to JS has data chunks:

Screenshot from 2024-11-12 15-18-50

@DaveO-Home
Copy link
Author

I noticed that you are using the Echo endpoint. Grpc Web only supports unary and server side streaming.

@spericas
Copy link
Member

spericas commented Nov 12, 2024

There's a single unary Echo method defined in the service (and I think/hope matches what is used by the JS client that I'm just reusing). Proto file is based on https://github.com/grpc/grpc-web/blob/0.4.0/net/grpc/gateway/examples/echo/echo.proto. grpcurl works great using that proto, so the issue is definitely with Envoy.

Can Envoy pass along the payload without interpreting it? I'm assuming so unless it needs to do some sort of conversion. I can see that the message reply from the service is actually present in the payload, but the JS code fails to parse the message body in my case.

(ubuntu:~/Projects/grpc-web) >> grpcurl -plaintext -d '{"message":"hi"}' -vv -proto ./net/grpc/gateway/examples/echo/echo.proto localhost:9090 grpc.gateway.testing.EchoService/Echo

Resolved method descriptor:
// One request followed by one response
// The server returns the client message as-is.
rpc Echo ( .grpc.gateway.testing.EchoRequest ) returns ( .grpc.gateway.testing.EchoResponse );

Request metadata to send:
(empty)

Response headers received:
content-type: application/grpc

Estimated response size: 10 bytes

Response contents:
{
  "message": "HI",
  "messageCount": 2147483647
}

Response trailers received:
(empty)
Sent 1 request and received 1 response

@DaveO-Home
Copy link
Author

DaveO-Home commented Nov 12, 2024

@spericas Notice that the reponse in java is like this(my handicap example)

HandicapData handicapData = HandicapData.newBuilder()
          .setMessage("No Golfer Found")
          .setCmd(request.getCmd())
          .setJson(requestJson.getJsonString("data").getString())
          .build();

        logger.info("Returning Data: {}", handicapData);
        ResponseHelper.complete(observer, handicapData);

The reponse is a pojo+ generated from protec in my case HandicapData. I don't know what Helidon does with the pojo. I believe it should be marshalled and unmarshalled to grpc/proto specs.

@spericas
Copy link
Member

It finds the protobuf marshaller for that class and calls it. If Helidon did something terrible wrong, it would not work with grpcurl. The issue is with Envoy.

@DaveO-Home
Copy link
Author

DaveO-Home commented Nov 13, 2024

I just got my linux working - I have a node setup that works with envoy. It's different than web but is written in javascript. The pojo is different so I think it does the protobuf stuff under the covers. It uses http/2 and works with or without envoy. I'll put the code together tomorrow. Envoy works with Quarkus/Vert.x frameworks using the same software.

@DaveO-Home
Copy link
Author

@spericas Here's a simple Node remote call to Helidon, I upgraded envoy 1.32.1 and used your yaml config.
This ran via envoy and without envoy since node uses http/2 by default. The Java test I ran(example above) also runs with or without envoy. The problem with the Java test is that a number of jars have to be added to the classpath.


var protoObject = require("./handicap/protos/handicap_pb.js")  // Change to your String app
var PROTO_PATH = __dirname + '/../protos/handicap.proto';      // Change to your String app
var fs = require('fs');
var path = require('path');
var grpc = require('@grpc/grpc-js');
var protoLoader = require('@grpc/proto-loader');

var packageDefinition = protoLoader.loadSync(
  PROTO_PATH,
  {keepCase: true,
    longs: String,
    enums: String,
    defaults: true,
    oneofs: true
  });
var handicap = grpc.loadPackageDefinition(packageDefinition).handicap.grpc;
var client = new handicap.HandicapService('localhost:8071', grpc.credentials.createInsecure());

function runGetGolfer() {
  const golferObject = {pin:"do1234",firstName:"Dave",lastName:"O&#39;Meara",country:"US",state:"AL",overlap:false,public:false,status:0,lastLogin:1731168449906,course:"Toiyabe Golf",tee:2,teeDate:1731168449906};

  let message = JSON.stringify(golferObject);
  /*
      This is different, uses just a javascript object
  */
  var command = {}; // protoObject.HandicapSetup; // new HandicapSetup();
//  command.setJson(message);
//  command.setCmd(3);
//  command.setMessage("Golfer Data");
  /*
      Change to your String app
  */
  command.cmd = 3;
  command.json = message;
  command.message = "Get Golfer";

   var call = client.getGolfer(command, function (err, data) {
    if (err) {
      console.error(err.message)
    } else {
      console.log(data)
      
      // console.log('Found data with "' + data.json + '" and ' +
         // data.cmd + ', ' + data.message);
    }
  });
}

runGetGolfer()

// Note: Sometimes I get: 14 UNAVAILABLE: upstream connect error or disconnect/reset before headers. reset reason: remote refused stream reset

The package.json has more than you need

  "name": "handicap-grpc-client",
  "version": "0.1.0",
  "description": "Manage golf handicap index",
  "main": "client.js",
  "scripts": {
    "webpack:build": "webpack --mode development  --config=config/webpack.config.js",
    "webpack:prod": "webpack --mode production --config=config/webpack.config.js",
    "esbuild:build": "node config/esbuild.config.js false",
    "esbuild:prod": "node config/esbuild.config.js true",
    "group:build": "node config/esbuild.group.config.js false",
    "group:prod": "node config/esbuild.group.config.js true"
  },
  "devDependencies": {
    "@craftamap/esbuild-plugin-html": "^0.8.0",
    "async": "^3.2.5",
    "clean-webpack-plugin": "^4.0.0",
    "copy-webpack-plugin": "^12.0.2",
    "css-loader": "^7.1.2",
    "del": "^7.1.0",
    "esbuild": "^0.24.0",
    "esbuild-copy-static-files": "^0.1.0",
    "html-webpack-plugin": "^5.6.0",
    "lodash": "~4.17.0",
    "mini-css-extract-plugin": "^2.9.0",
    "sass": "^1.77.6",
    "sass-loader": "^16.0.0",
    "terser-webpack-plugin": "^5.3.10",
    "webpack": "^5.92.1",
    "webpack-cli": "^5.1.4",
    "webpack-strip-block": "^0.3.0"
  },
  "dependencies": {
    "@fortawesome/fontawesome-free": "^6.5.2",
    "@grpc/grpc-js": "^1.12.2",
    "@grpc/proto-loader": "^0.7.13",
    "bootstrap": "^5.3.3",
    "bootstrap-table": "1.21.2",
    "date-time-picker-component": "^1.1.10",
    "dodex": "^1.4.1",
    "dodex-input": "^1.4.1",
    "dodex-mess": "^1.3.4",
    "google-protobuf": "^3.21.4",
    "grpc-web": "^1.5.0",
    "jsoneditor": "^10.1.0",
    "protobufjs": "^7.3.2"
  }
}

@DaveO-Home
Copy link
Author

@spericas Here's interesting documentation: https://github.com/grpc/grpc/blob/master/doc/PROTOCOL-WEB.md
The reponse content-type that works with node and Java is application/grpc for grpc-web the content-type is: application/grpc-web-text+proto. Wondering if proto should be json???

@spericas
Copy link
Member

@spericas Here's interesting documentation: https://github.com/grpc/grpc/blob/master/doc/PROTOCOL-WEB.md The reponse content-type that works with node and Java is application/grpc for grpc-web the content-type is: application/grpc-web-text+proto. Wondering if proto should be json???

No, +proto seems fine.

I compared the cases when using Node and Helidon as servers: it appears there's a compressed flag turned on by Envoy when returning the response from Helidon but not Node. I don't know why, but it's odd and possibly/likely wrong. See below:

Screenshot from 2024-11-13 13-09-30

@DaveO-Home
Copy link
Author

Here's the debug for Quarkus that works:

':status', '200'
'access-control-allow-credentials', 'true'
'access-control-allow-origin', 'http://localhost:8089'
'access-control-allow-headers', 'X-Custom'
'access-control-allow-methods', 'GET,PUT,POST,DELETE'
'access-control-expose-headers', 'custom-header-1,grpc-status,grpc-message'
'content-type', 'application/grpc-web-text+proto'
'grpc-accept-encoding', 'gzip'
'x-envoy-upstream-service-time', '151'
'date', 'Wed, 13 Nov 2024 18:33:49 GMT'
'server', 'envoy'

For Helidon:

'content-type', 'application/grpc-web-text+proto'
'grpc-encoding', 'identity'
'x-envoy-upstream-service-time', '14'
'access-control-allow-origin', 'http://localhost:8060'
'access-control-expose-headers', 'custom-header-1,grpc-status,grpc-message,handicap'
'date', 'Wed, 13 Nov 2024 17:38:37 GMT'
'server', 'envoy'

@spericas
Copy link
Member

For Helidon:

'content-type', 'application/grpc-web-text+proto'
'grpc-encoding', 'identity'
'x-envoy-upstream-service-time', '14'
'access-control-allow-origin', 'http://localhost:8060'
'access-control-expose-headers', 'custom-header-1,grpc-status,grpc-message,handicap'
'date', 'Wed, 13 Nov 2024 17:38:37 GMT'
'server', 'envoy'

You seem to be missing :status here, I do see it set to 200.

@DaveO-Home
Copy link
Author

DaveO-Home commented Nov 14, 2024

Yes, I had the 200 status, just screwed up doing the copy. So, can the headers be set before sending the response?

@spericas
Copy link
Member

spericas commented Nov 14, 2024

@DaveO-Home I figured it out, the problem is related to encoding (see the Wireshark screenshot above and grpc-encoding header). Helidon is using the "identity" encoding which isn't really encoding/compressing anything, but it is turning on the encoding bit. The Javascript generated stubs reject all data frames with encoding enabled (likely not supported) and thus the deserialization fails.

This use case is properly supported by grpcurl and other clients. It may be possible to consider the identity as a special encoding (namely no encoding!) and go through the normal path. When you do that, it works just fine. I'm going start working on a PR for Helidon to improve this, but I think this should be handled by the JS stubs eventually.

This was a really really difficult one to find ... it literally was down to one bit

@DaveO-Home
Copy link
Author

DaveO-Home commented Nov 14, 2024

@spericas Glad to have you digging into the bits. Thanks for staying with this, I'll wait for the fix.

@tjquinno tjquinno linked a pull request Nov 18, 2024 that will close this issue
@github-project-automation github-project-automation bot moved this from Sprint Scope to Closed in Backlog Nov 18, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
Archived in project
Development

Successfully merging a pull request may close this issue.

3 participants