ServerCallHandler: OperationCanceledException/IOException as Log Level "Information"

[lindeberg]

Is your feature request related to a problem? Please describe.

Our logs are spammed with this. Guessing it happens when users of the mobile app that is initiating the requests close the app at a specific timing. They all are logged for the same request:

Level: Error
MessageTemplate: Call failed with gRPC error status. Status code: '{StatusCode}', Message: '{StatusMessage}'.
SourceContext: Grpc.Net.Client.Internal.GrpcCall
Exception: System.OperationCanceledException: The operation was canceled.

and

Level: Error
MessageTemplate: Error reading message.
SourceContext: Grpc.AspNetCore.Server.ServerCallHandler
Exception: System.IO.IOException: The client reset the request stream.
   at Grpc.AspNetCore.Server.Internal.PipeExtensions.ReadSingleMessageAsync[T](PipeReader input, HttpContextServerCallContext serverCallContext, Func`2 deserializer)

and

Level: Error
MessageTemplate: Error when executing service method '{ServiceMethod}'.
SourceContext: Grpc.AspNetCore.Server.ServerCallHandler
Exception: System.IO.IOException: The client reset the request stream.
   at Grpc.AspNetCore.Server.Internal.PipeExtensions.ReadSingleMessageAsync[T](PipeReader input, HttpContextServerCallContext serverCallContext, Func`2 deserializer)
   at Grpc.AspNetCore.Server.Internal.CallHandlers.UnaryServerCallHandler`3.HandleCallAsyncCore(HttpContext httpContext, HttpContextServerCallContext serverCallContext)
   at Grpc.AspNetCore.Server.Internal.CallHandlers.ServerCallHandlerBase`3.<HandleCallAsync>g__AwaitHandleCall|8_0(HttpContextServerCallContext serverCallContext, Method`2 method, Task handleCall)

Describe the solution you'd like

IMO: These should not be logged with log level error, but rather with Information.

https://github.com/grpc/grpc-dotnet/blob/master/src/Grpc.AspNetCore.Server/Internal/HttpContextServerCallContext.cs#L196

Describe alternatives you've considered

• Not logging it at all?
• Letting package users decide on log level for this specific case

Additional context

Add any other context about the feature request here.

[tleed5]

Just ran into this issue, specifically the System.IO.IOException logging when a client disconnects from the stream which even though we handle the exception it still gets logged at an information level because of this catch statement

Alternative solution could be to not log in the instances where the exception is going to bubble up anyway which will likely mean ASP will log it anyway.

In the meantime for a work around i'm looking at adding a log filter that filters out logs that come from Grpc.AspNetCore.Server.ServerCallHandler source context which isn't ideal but having noisy logs isn't great either.

[gao-artur]

@JamesNK this is still reported as an error (in addition to information) here
https://github.com/grpc/grpc-dotnet/blob/master/src/Grpc.AspNetCore.Server/Internal/PipeExtensions.cs#L278-L283

This catch doesn't handle the IOException

System.IO.IOException: The client reset the request stream.
at Grpc.AspNetCore.Server.Internal.PipeExtensions.ReadSingleMessageAsync[T](PipeReader input, HttpContextServerCallContext serverCallContext, Func`2 deserializer)