[java] Logging result of every call on server

[John Hume]

We have a ServerInterceptor for logging every call our grpc-java server receives. It wraps the ServerCall passed on to next::startCall with a SimpleForwardingServerCall that overrides close(Status,Metadata) for logging the status of the call and tracking total time elapsed between interceptCall and close. We expected this to result in logging status and tracking elapsed time for every call received.

We've found one case in production where our interceptor logged in the body of interceptCall, and then an inner interceptor did some logging in its interceptCall, but we never saw any more logging for the request. Other context suggests that there were connection issues between the client and server at the time.

Should ServerCall::close(Status,Metadata) be called for every call, regardless of client or connection misbehavior? If not, is there some other callback that we may have missed that would indicate that a call has died?

[Carl Mastrangelo]

You should always call close, except if it has already been closed.  You can tell if a downstream interceptor has called close because you will get back an onCancel or onComplete callback from the ServerCall.Listener you get back from ServerCallHandler.startCall.

[John Hume]

My wording was ambiguous, but what I meant to ask was whether the framework guarantees that ServerCall::close will be called on the possibly-wrapped-by-interceptors ServerCall passed on to the next handler. Our logs suggest that it does not.

Our logging interceptor wasn't logging in the returned ServerCall.Listener's onCancel and onCompleted callbacks, so I suspect that in some cases of connection issues, there's an onCancel callback and no call to the interceptor-supplied ServerCall::close. We'll add logging there are see what we see.

[Eric Anderson]

This was also discussed at https://stackoverflow.com/a/47025228/4690866 . Yes, ServerCall.close() is not guaranteed. The only guarantee is you'll get one of onCancel or onComplete. onComplete should only happen after a call to ServerCall.close().

--
You received this message because you are subscribed to the Google Groups "grpc.io" group.
To unsubscribe from this group and stop receiving emails from it, send an email to grpc-io+unsubscribe@googlegroups.com.
To post to this group, send email to grp...@googlegroups.com.
Visit this group at https://groups.google.com/group/grpc-io.
To view this discussion on the web visit https://groups.google.com/d/msgid/grpc-io/1e19c923-d825-4019-9361-eb0e8f099d58%40googlegroups.com.

For more options, visit https://groups.google.com/d/optout.