Challenges

We are on microservice so multiple hops are involved, with hops there comes a delay, so we were looking for a solution for reducing latency as some time out packet size was quite heavy, so even the server was able to respond but the client was getting a timeout.

With research, Protocol Buffers came for the rescue and as we already have Protocol Buffers in our system and gRPC has by default support for proto, So We went for gRPC.

Just like every new implementation we got a lot of roadblocks. Access log was one of those as we are relying on an access log to plot our latency in Grafana. It was the only way for us to benchmark the system and to justify what we are getting out of our gRPC implementation.

Problem

GRPC having a limited set of developer docs as it’s quite young so not much information was available over the internet. After landing into the gRPC binary and doing some reverse engineering through class files we found GRPC has an interceptor. That gives us some hope.

Solution

Below are the steps we followed to achieved access logging in GRPC implementation

  1. Create an interceptor that extends ServerInterceptor.
  2. Annotated with @GRpcGlobalInterceptor.
  3. Override interceptCall and implement and format your log in the required format.
  4. Add a reference to your custom logger.


import com.mmt.engine.service.MetricAspect;
import io.grpc.*;
import org.lognet.springboot.grpc.GRpcGlobalInterceptor;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Component;

@GRpcGlobalInterceptor
@Component
public class GrpcLogIntercepter implements ServerInterceptor {

@Autowired
private MetricAspect metricAspect;

private static final Logger LOGGER = LoggerFactory.getLogger("access-log");

@Override
public <ReqT, RespT> ServerCall.Listener<ReqT> interceptCall(ServerCall<ReqT, RespT> serverCall, Metadata metadata, ServerCallHandler<ReqT, RespT> serverCallHandler) {

LOGGER.info(
String.format(
"method=[%s], remote=%s",
serverCall.getMethodDescriptor().getFullMethodName(),
serverCall.getAttributes().get(Grpc.TRANSPORT_ATTR_REMOTE_ADDR)
)
);


return serverCallHandler.startCall(serverCall, metadata);
}
}

5. And finally give a reference on your stub controller

@GRpcService(interceptors = {GrpcLogIntercepter.class})
public class GrpcEngineController extends ServiceGrpc.ServiceImplBase {
...
...
...
}

woohoo, we did it!

Final Note

We heavily relied on class files of gRPC but once we got the direction we found some resources as well.