grpc-ecosystem / grpc-spring

Spring Boot starter module for gRPC framework.
https://grpc-ecosystem.github.io/grpc-spring/
Apache License 2.0
3.48k stars 817 forks source link

How to define a client interceptor ? #510

Closed ghevge closed 3 years ago

ghevge commented 3 years ago

I have a spring-boot app and I'm trying to define a client interceptor for my grpc service, so that I can set some custom headers in the response (which will be transcoded to html)

My interceptor definition looks like this:

import io.grpc.CallOptions;
import io.grpc.Channel;
import io.grpc.ClientCall;
import io.grpc.ClientInterceptor;
import io.grpc.ForwardingClientCall.SimpleForwardingClientCall;
import io.grpc.ForwardingClientCallListener.SimpleForwardingClientCallListener;
import io.grpc.Metadata;
import io.grpc.MethodDescriptor;
import net.devh.boot.grpc.client.interceptor.GrpcGlobalClientInterceptor;

@GrpcGlobalClientInterceptor
public class HeaderClientInterceptor implements ClientInterceptor {

  static final Metadata.Key<String> CUSTOM_HEADER_KEY =
      Metadata.Key.of("custom_client_header_key", Metadata.ASCII_STRING_MARSHALLER);

  @Override
  public <ReqT, RespT> ClientCall<ReqT, RespT> interceptCall(MethodDescriptor<ReqT, RespT> method,
      CallOptions callOptions, Channel next) {
    System.out.println("====log====================");
    return new SimpleForwardingClientCall<ReqT, RespT>(next.newCall(method, callOptions)) {
        @Override
        public void sendMessage(ReqT message) {
            System.out.println("====log send====================");
            super.sendMessage(message);
        }
        @Override
        public void start(Listener<RespT> responseListener, Metadata headers) {
            headers.put(CUSTOM_HEADER_KEY, "customRequestValue");
            super.start(new SimpleForwardingClientCallListener<RespT>(responseListener) {
                @Override
                public void onHeaders(Metadata headers) {
                    System.out.println("====head===================="+headers);
                    super.onHeaders(headers);
                }
            }, headers);
        }
    };
  }
}

No matter what I've tried, the response doesn't want o go through that code. Just note that I also have a ServerInterceptor define in my code, and that logic works fine.

My .proto api definition looks like:

rpc DownloadBuild(DownloadBuildRequest) returns (stream google.api.HttpBody) {
    option (google.api.http) = {
      get : "/v4/projects/{projectId}/types/{buildType}/builds/{buildVersion}/.download"
    };
    option (grpc.gateway.protoc_gen_swagger.options.openapiv2_operation) = {
      description: "Download build.";
      summary: "Download build.";
      tags: "Builds";
      responses: {
        key: "200"
        value: {
          description: "Download build";
        }
      }
      responses: {
        key: "401"
        value: {
          description: "Request could not be authorized";
        }
      }
      responses: {
        key: "404"
        value: {
          description: "Build not found";
        }
      }
      responses: {
        key: "500"
        value: {
          description: "Internal server error";
        }
      }
    };
  }

while my grpc implementation looks like this:

...
@GrpcService
public class GrpcAPIService extends MixAPIGrpc.MixAPIImplBase {
...
 @Override
    public void downloadBuild(DownloadBuildRequest request, StreamObserver<com.google.api.HttpBody> responseObserver) {
        handleDownloadGrpcCall("downloadBuild", mwProxy::downloadBuild, request, responseObserver);
    }
...
 private <T, R> void handleDownloadGrpcCall(String grpcMethodName, Function<T, byte[]> serviceMethod, T request,
            StreamObserver<com.google.api.HttpBody> streamObserver) {
        log.debug("{}: >>>, request:[{}]", grpcMethodName, request);
        try {
            Instant start = Instant.now();
            byte[] bytes = serviceMethod.apply(request);
            BufferedInputStream stream = new BufferedInputStream(new ByteArrayInputStream(bytes));

            int bufferSize = 1 * 1024;// 1KB
            byte[] buffer = new byte[bufferSize];
            int length;
            boolean addExtension = true;
            while ((length = stream.read(buffer, 0, bufferSize)) != -1) {
                streamObserver.onNext(com.google.api.HttpBody.newBuilder()
                        .setData(ByteString.copyFrom(buffer, 0, length))
                        .setContentType("application/octet-stream")
                        .build());
            }
            stream.close();
            streamObserver.onCompleted();
            Instant end = Instant.now();
            timingService.logMethodExecution(grpcMethodName, start, end, request);
        } catch (Exception e) {
            handleException(e, streamObserver, request, grpcMethodName);
        }
        log.debug("{}: <<<<", grpcMethodName);
    }
...

Any idea what could be wrong ?

ST-DDT commented 3 years ago

I pasted your interceptor into the local-grpc-client example project and got the following log output:

> Task :examples:local-grpc-client:bootRun

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.3.8.RELEASE)

2021-03-15 23:27:56.929  INFO 15136 --- [           main] n.d.b.g.e.l.c.LocalGrpcClientApplication : Starting LocalGrpcClientApplication 
2021-03-15 23:27:56.931  INFO 15136 --- [           main] n.d.b.g.e.l.c.LocalGrpcClientApplication : No active profile set, falling back to default profiles: default
2021-03-15 23:27:57.675  INFO 15136 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2021-03-15 23:27:57.684  INFO 15136 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2021-03-15 23:27:57.684  INFO 15136 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.41]
2021-03-15 23:27:57.753  INFO 15136 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2021-03-15 23:27:57.753  INFO 15136 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 779 ms
2021-03-15 23:27:57.830  INFO 15136 --- [           main] n.d.b.g.c.a.GrpcClientAutoConfiguration  : Detected grpc-netty-shaded: Creating ShadedNettyChannelFactory + InProcessChannelFactory
2021-03-15 23:27:58.030  INFO 15136 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2021-03-15 23:27:58.142  INFO 15136 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2021-03-15 23:27:58.149  INFO 15136 --- [           main] n.d.b.g.e.l.c.LocalGrpcClientApplication : Started LocalGrpcClientApplication in 1.55 seconds (JVM running for 1.857)
2021-03-15 23:28:01.146  INFO 15136 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2021-03-15 23:28:01.147  INFO 15136 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2021-03-15 23:28:01.151  INFO 15136 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 4 ms
====log====================
2021-03-15 23:28:01.194  INFO 15136 --- [nio-8080-exec-1] n.d.b.g.e.l.client.LogGrpcInterceptor    : Simple/SayHello
====log send====================
====head====================Metadata(content-type=application/grpc,grpc-encoding=identity,grpc-accept-encoding=gzip)

So I assume it is working as intended there.

Have you checked whether the bean is created "early enough"? Add a debug output/breakpoint to your constructor and net.devh.boot.grpc.client.interceptor.GlobalClientInterceptorRegistry.getClientInterceptors() return and check whether they are executed in this order.

ghevge commented 3 years ago

Thanks for the reply!

From what I see the client interceptor bean gets created (added some logs in the constructor) but I'm not catching anything in debug mode in the GlobalClientInterceptorRegistry methods, during the grpc calls.

ghevge commented 3 years ago

During the app startup, I only catch a call to GlobalClientInterceptorRegistry constructor:

 public GlobalClientInterceptorRegistry(final ApplicationContext applicationContext) {
        this.applicationContext = requireNonNull(applicationContext, "applicationContext");
    }

then a call to config class :

@Order(Ordered.LOWEST_PRECEDENCE)
@Configuration(proxyBeanMethods = false)
public class GlobalClientInterceptorConfiguration {

    @GrpcGlobalClientInterceptor
    ClientInterceptor hClientInterceptor() {
        System.out.println("====log=c===================");
        return new HeaderClientInterceptor();
    }

}

Then nothing else related to client interceptors.

For serverInterceptor that I have defined in the same app, I can see the call going through GlobalServerInterceptorRegistry.getServerInterceptors(). So there is definitely something wrong with the client interceptor setup. Not clear what exactly.

ghevge commented 3 years ago

These are my app startup logs:

mix-api_1        | 2021-03-16T14:10:55.982Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [com.n.mix.api.Application] Starting Application using Java 15.0.2 on cfb47259348d with PID 1 (/mix-api-component-exec.jar started by root in /) 
mix-api_1        | 2021-03-16T14:10:56.006Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [com.n.mix.api.Application] The following profiles are active: production 
mix-api_1        | 2021-03-16T14:11:07.071Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.s.b.w.e.tomcat.TomcatWebServer] Tomcat initialized with port(s): 8080 (http) 
mix-api_1        | 2021-03-16T14:11:07.203Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.a.coyote.http11.Http11NioProtocol] Initializing ProtocolHandler ["http-nio-8080"] 
mix-api_1        | 2021-03-16T14:11:07.204Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.a.catalina.core.StandardService] Starting service [Tomcat] 
mix-api_1        | 2021-03-16T14:11:07.204Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.a.catalina.core.StandardEngine] Starting Servlet engine: [Apache Tomcat/9.0.39] 
mix-api_1        | 2021-03-16T14:11:07.504Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.a.c.c.C.[Tomcat].[localhost].[/]] Initializing Spring embedded WebApplicationContext 
mix-api_1        | 2021-03-16T14:11:07.505Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.s.b.w.s.c.ServletWebServerApplicationContext] Root WebApplicationContext: initialization completed in 10969 ms 
mix-api_1        | 2021-03-16T14:11:07.910Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [c.s.e.o.g.GracefulShutdownHealthCheck] Gracefulshutdown healthcheck up 
mix-api_1        | 2021-03-16T14:11:08.121Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [n.d.b.g.c.a.GrpcClientAutoConfiguration] Detected grpc-netty-shaded: Creating ShadedNettyChannelFactory + InProcessChannelFactory 
mix-api_1        | 2021-03-16T14:11:11.983Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [c.n.m.a.l.LaunchdarklyService] Enabling feature flags 
mix-api_1        | 2021-03-16T14:11:12.662Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [c.launchdarkly.sdk.server.LDClient] Starting LaunchDarkly client in offline mode 
mix-api_1        | 2021-03-16T14:11:13.339Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [i.o.c.s.w.s.ServerTracingAutoConfiguration] Creating FilterRegistrationBean bean with TracingFilter mapped to [], skip pattern is "/api-docs.*|/swagger.*|.*\.png|.*\.css|.*\.js|.*\.html|/favicon.ico|/hystrix.stream|/actuator/(prometheus|prometheus/.*|beans|beans/.*|caches|caches/.*|health|health/.*|info|info/.*|conditions|conditions/.*|configprops|configprops/.*|env|env/.*|loggers|loggers/.*|heapdump|heapdump/.*|threaddump|threaddump/.*|metrics|metrics/.*|scheduledtasks|scheduledtasks/.*|mappings|mappings/.*)" 
mix-api_1        | ====log=c===================
mix-api_1        | 2021-03-16T14:11:14.042Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [i.o.c.s.w.s.ServerTracingAutoConfiguration] Creating WebMvcConfigurer bean with class io.opentracing.contrib.spring.web.interceptor.TracingHandlerInterceptor 
mix-api_1        | 2021-03-16T14:11:14.322Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.s.s.c.ThreadPoolTaskExecutor] Initializing ExecutorService 'applicationTaskExecutor' 
mix-api_1        | 2021-03-16T14:11:15.266Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [n.d.b.g.s.a.GrpcServerFactoryAutoConfiguration] Detected grpc-netty-shaded: Creating ShadedNettyGrpcServerFactory 
mix-api_1        | 2021-03-16T14:11:16.018Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.a.coyote.http11.Http11NioProtocol] Starting ProtocolHandler ["http-nio-8080"] 
mix-api_1        | 2021-03-16T14:11:16.096Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.s.b.w.e.tomcat.TomcatWebServer] Tomcat started on port(s): 8080 (http) with context path '' 
mix-api_1        | 2021-03-16T14:11:16.609Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.s.b.w.e.tomcat.TomcatWebServer] Tomcat initialized with port(s): 9099 (http) 
mix-api_1        | 2021-03-16T14:11:16.614Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.a.coyote.http11.Http11NioProtocol] Initializing ProtocolHandler ["http-nio-9099"] 
mix-api_1        | 2021-03-16T14:11:16.617Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.a.catalina.core.StandardService] Starting service [Tomcat] 
mix-api_1        | 2021-03-16T14:11:16.618Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.a.catalina.core.StandardEngine] Starting Servlet engine: [Apache Tomcat/9.0.39] 
mix-api_1        | 2021-03-16T14:11:16.684Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.a.c.c.C.[.[localhost].[/]] Initializing Spring embedded WebApplicationContext 
mix-api_1        | 2021-03-16T14:11:16.701Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.s.b.w.s.c.ServletWebServerApplicationContext] Root WebApplicationContext: initialization completed in 535 ms 
mix-api_1        | 2021-03-16T14:11:16.785Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.s.b.a.e.web.EndpointLinksResolver] Exposing 14 endpoint(s) beneath base path '/actuator' 
mix-api_1        | 2021-03-16T14:11:17.071Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.a.coyote.http11.Http11NioProtocol] Starting ProtocolHandler ["http-nio-9099"] 
mix-api_1        | 2021-03-16T14:11:17.084Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [o.s.b.w.e.tomcat.TomcatWebServer] Tomcat started on port(s): 9099 (http) with context path '' 
mix-api_1        | 2021-03-16T14:11:18.240Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [n.d.b.g.s.s.AbstractGrpcServerFactory] Registered gRPC service: mix.api.MixAPI, bean: grpcAPIService, class: com.n.mix.api.impl.grpc.GrpcAPIService 
mix-api_1        | 2021-03-16T14:11:19.499Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [n.d.b.g.s.s.GrpcServerLifecycle] gRPC Server started, listening on address: 0.0.0.0, port: 9090 
mix-api_1        | 2021-03-16T14:11:19.556Z <> {session=,trace=,span=,user=,client=,thread=main} INFO: [com.n.mix.api.Application] Started Application in 27.547 seconds (JVM running for 30.08) 
ghevge commented 3 years ago

@ST-DDT do you have any other suggestions ?

ST-DDT commented 3 years ago

How do you create the client stub? Are you using the @GrpcClient annotation for that?

Please also add a breakpoint to:

Make sure that both are called and especially that at the end of the later one the interceptors contain your interceptor instance.

ghevge commented 3 years ago

@ST-DDT I might be missing something here... I don't have a client stub created on my grpc server. I only define a @GrpcService. What I want to achieve, is to set some extra headers (metadata) on the response that will be sent to the clients. The reason being that in from of my grpc server I have an envoy instance which is doing http transcoding. My understanding is that the ClientInterceptor is supposed to allow me to do just that. As the ServerInterceptor allows me to extract the request headers. Have I miss understood ClientInterceptors ?

ST-DDT commented 3 years ago

What I want to achieve, is to set some extra headers (metadata) on the response that will be sent to the clients.

Then you should use server interceptors for that.

If you don't use the @GrcpClient at all, then you can/should switch from the grpc-spring-boot-starter dependency to the grpc-server-spring-boot-starter dependency.

ghevge commented 3 years ago

@ST-DDT ok but how do I intercept the server responses then with ServerInterceptor? From what I can see, ServerInterceptors only get triggered on incoming requests.

ST-DDT commented 3 years ago

@ST-DDT ok but how do I intercept the server responses then with ServerInterceptor? From what I can see, ServerInterceptors only get triggered on incoming requests.

No, it is possible to intercept the responses as well, you just have to use a slightly different approach, see the metrics interceptor as example:

ghevge commented 3 years ago

@ST-DDT Thanks! I've managed to set it.

ST-DDT commented 3 years ago

Do you have any additional questions?

ghevge commented 3 years ago

No I'm good!