I filed https://github.com/grpc/grpc/issues/13943 the excessive logging.
On Monday, January 8, 2018 at 3:17:42 PM UTC+1, Jan Tattermusch wrote: > > 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/87ff4294-b1ea-43ea-bb24-7fe61f158ca8%40googlegroups.com. For more options, visit https://groups.google.com/d/optout.
