When deadlines are set for a call, there is an inherent race condition in which party first sees the deadline was exceeded - it can be either the client or the server (they see the same deadline for a call so the client side part of the call will expire at almost the same time as the server-side of the call).
I suspect in your case, the client-side of the call realizes the call has timed out first (and resets the HTTP2 stream to the server). Right after that, the server sees the timeout as well and tries to send the "Cancelled" status to the client - but the connection has just been reset by the client and it results in an error. As said, this race is inherent and it is quite natural that it happens. On the other hand, we shouldn't really print a somewhat misleading error when that happens (= i.e. the problem is with too verbose logging in this situation, not with the RPC handling logic itself). Specifically for your applications, if you have that many (>20%) or requests timing out, you should probably increase the call deadline. On Wednesday, December 20, 2017 at 8:50:10 PM UTC+1, [email protected] wrote: > > > Hi gRPC experts, > > I have a Client Streaming gRPC (C# client, C# server) set up, and I ran > into an issue where about 20% of requests would fail to complete. On the > client, the error was DEADLINE_EXCEEDED, but on the server, our injected > gRPC logger was seeing the following warnings. The server was successfully > fulfilling the request - it just couldn't send a reply back to the client. > > [gRPC Warning] Exception while handling RPC. > System.InvalidOperationException: Operation is not valid due to the current > state of the object. at > Grpc.Core.Internal.AsyncCallServer`2.SendStatusFromServerAsync(Status > status, Metadata trailers, Tuple`2 optionalWrite) at > Grpc.Core.Internal.ClientStreamingServerCallHandler`2.<HandleCall>d__4.MoveNext() > > --- End of stack trace from previous location where exception was thrown > --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at > System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task > > task) at Grpc.Core.Server.<HandleCallAsync>d__39.MoveNext() > > I re-deployed the app with more logging, but lost the repro. I was going > to start with capturing traces as noted in this SO question > <https://stackoverflow.com/questions/37125975/how-to-debug-grpc-call>; is > there anything else I can do? > > I'm wondering if you have any pointers on what might be happening? > > Thanks! > Scott > -- 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 [email protected]. To post to this group, send email to [email protected]. 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/2d4afa8a-aece-49bc-9cab-ef4644f026d7%40googlegroups.com. For more options, visit https://groups.google.com/d/optout.
