Unchecked exceptions can't be captured from a ServerInterceptor

[zackangelo]

I'm attempting to add instrumentation to our gRPC service implementations using a ServerInterceptor, namely failure rates on a per-method basis. To do this, I'm using a SimpleForwardingServerCall, overriding the close method and then checking the status to see if the call succeeded.

When an unchecked exception is thrown from a service implementation:

@Override
    public void sayHello(HelloRequest req, StreamObserver<HelloReply> responseObserver) {
       throw new RuntimeException("BOOM!");
    }

and given an interceptCall method that looks something like this:

@Override
  public <ReqT, RespT> ServerCall.Listener<ReqT> interceptCall(
      MethodDescriptor<ReqT, RespT> method,
      ServerCall<RespT> call,
      final Metadata requestHeaders,
      ServerCallHandler<ReqT, RespT> next) {

    return next.startCall(method, new SimpleForwardingServerCall<RespT>(call) {
      @Override
      public void close(Status status, Metadata trailers) {
        logger.info("ERROR ENCOUNTERED"); // <-- never see this
        super.close(status, trailers);
      }
    }, requestHeaders);
  }

the close method is never called, so there isn't an opportunity to log the failure.

The exception seems to bubble up to the Executor instead:

Mar 15, 2016 12:26:59 PM io.grpc.internal.SerializingExecutor$TaskRunner run
SEVERE: Exception while executing runnable io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$2@3e694e4a
java.lang.RuntimeException: BOOM!
    at io.grpc.examples.helloworld.HelloWorldServer$GreeterImpl.sayHello(HelloWorldServer.java:98)
    at io.grpc.examples.helloworld.GreeterGrpc$MethodHandlers.invoke(GreeterGrpc.java:161)
    at io.grpc.stub.ServerCalls$1$1.onHalfClose(ServerCalls.java:147)
    at io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.halfClosed(ServerCallImpl.java:255)
    at io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$2.runInContext(ServerImpl.java:458)
    at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:54)
    at io.grpc.internal.SerializingExecutor$TaskRunner.run(SerializingExecutor.java:154)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745) 

I've also tried returning a ForwardingServerCallListener from interceptCall and the onComplete callback is invoked, but it doesn't have enough information for me to determine if the call was a failure.

Is there another API I can take a look at that will allow me to capture these failures?

[ejona86]

FYI, failure rate statistics are going to be a native feature.

Yes, close() is not called, because 1) it is impossible to call from a threading standpoint and 2) it would have to be a feature of the stub which means if an interceptor threw an exception close() still wouldn't be called.

Your best option is to override onHalfClose (and preferably the other listener methods, too) to catch and notice the exception. Note that startCall would throw instead in the case of client-streaming and bidi calls. Basically you should catch exceptions from all the listener methods and startCall.

[zackangelo]

Thanks Eric!

The option you suggested in the meantime seems to work great.

[zackangelo]

@ejona86 hate to resurrect an old issue... we're trying to similarly capture exceptions, but now we'd like to add a header or trailer with the error details in the Throwable.

It's straightforward if the error occurs asynchronously, but if it's in the calling thread the error is thrown in onHalfClose, by which point it seems too late to modify the Metadata in the response?

[ejona86]

@zackangelo, I don't follow, onHalfClose is called before ServerCall.close() has been called. You want to send headers instead?

[zackangelo]

@ejona86 Maybe I'm missing something, but if I modify the Metadata from onHalfClose, those trailers don't seem to be making it in the response.

[ejona86]

"the Metadata" Where did you get that instance? It might be useful to see a small code snippet (or pseudo code)

[zackangelo]

It's the Metadata instance that's being passed into interceptCall.

[ejona86]

The Metadata passed to interceptCall() is incoming from the client. Changing it will never impact the response. Instead, you need to deal with the Metadata passed in sendHeaders() or 'close()`.

[zackangelo]

@ejona86 apologies, we've been grasping at straws a bit trying to get it to work, this was one of our more desperate iterations :)

sendHeaders doesn't appear to be called at all, is there anything additional I need to do to make the interceptor aware that I want to send headers? Also, would sendHeaders be invoked after the exception occurs in the method call? Thanks for your help.

[ejona86]

Try something like this. Note that it assumes when an exception occurs that the application will not use ServerCall any more (since the object is not thread-safe). For many applications that's a reasonable assumption.

@Override
public <ReqT, RespT> ServerCall.Listener<ReqT> interceptCall(
    MethodDescriptor<ReqT, RespT> method,
    final ServerCall<RespT> call,
    final Metadata requestHeaders,
    ServerCallHandler<ReqT, RespT> next) {
  ServerCall.Listener<ReqT> listener;
  try {
    listener = next.startCall(method, call, requestHeaders);
  } catch (RuntimeException ex) {
    handleException(call, ex);
    throw ex;
  }
  return new SimpleForwardingServerCallListener<ReqT>(listener) {
    // No point in overriding onCancel and onComplete; it's already too late
    @Override public void onHalfClose() {
      try {
        super.onHalfClose();
      } catch (RuntimeException ex) {
        handleException(call, ex);
        throw ex;
      }
    }
    @Override public void onReady() {
      try {
        super.onReady();
      } catch (RuntimeException ex) {
        handleException(call, ex);
        throw ex;
      }
    }
  };
  private void handleThrowable(ServerCall<RespT> call, Throwable t) {
    call.close(Status.fromThrowable(ex), yourCustomLogic(ex));
  }
}

[zackangelo]

Some additional clarification after I ran some more tests, it looks like sendHeaders isn't invoked at all if the method results in a failure in any way (async or in calling thread).

[zackangelo]

@ejona86 closing the call in the exception handlers seems to be working!

Am I altering the call flow in any meaningful way that I should be aware of? Why isn't .close(...) called by default when an exception occurs in .onHalfClose()?

[ejona86]

Why isn't .close(...) called by default when an exception occurs in .onHalfClose()?

Because close() is "outside" of the runtime; it can only be called from the application, and threading prevents us from calling it as part of the stub. And even then it wouldn't change what happens when an interceptor throws an exception.

close() is called within the grpc library, but that doesn't invoke any interceptors because it happens within the Channel itself. Normally the exception is just logged and onCancelled() called.