From 468155f0bc9a2b745aac0118013af7d8333c5d33 Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Fri, 6 Sep 2024 11:11:48 +0800 Subject: [PATCH 1/2] Log server cancellation errors at info level --- src/Grpc.AspNetCore.Server/Internal/GrpcServerLog.cs | 10 +++++++++- .../Internal/HttpContextServerCallContext.cs | 11 ++++++++++- test/FunctionalTests/Client/StreamingTests.cs | 2 +- 3 files changed, 20 insertions(+), 3 deletions(-) diff --git a/src/Grpc.AspNetCore.Server/Internal/GrpcServerLog.cs b/src/Grpc.AspNetCore.Server/Internal/GrpcServerLog.cs index b93fde101..884a6021d 100644 --- a/src/Grpc.AspNetCore.Server/Internal/GrpcServerLog.cs +++ b/src/Grpc.AspNetCore.Server/Internal/GrpcServerLog.cs @@ -1,4 +1,4 @@ -#region Copyright notice and license +#region Copyright notice and license // Copyright 2019 The gRPC Authors // @@ -104,6 +104,9 @@ internal static class GrpcServerLog private static readonly Action _deadlineStopped = LoggerMessage.Define(LogLevel.Trace, new EventId(27, "DeadlineStopped"), "Request deadline stopped."); + private static readonly Action _serviceMethodCanceled = + LoggerMessage.Define(LogLevel.Information, new EventId(28, "ServiceMethodCanceled"), "Service method '{ServiceMethod}' canceled."); + internal static void DeadlineStopped(ILogger logger) { _deadlineStopped(logger, null); @@ -238,4 +241,9 @@ public static void DeadlineTimerRescheduled(ILogger logger, TimeSpan remaining) { _deadlineTimerRescheduled(logger, remaining, null); } + + public static void ServiceMethodCanceled(ILogger logger, string serviceMethod, Exception ex) + { + _serviceMethodCanceled(logger, serviceMethod, ex); + } } diff --git a/src/Grpc.AspNetCore.Server/Internal/HttpContextServerCallContext.cs b/src/Grpc.AspNetCore.Server/Internal/HttpContextServerCallContext.cs index 5e1d51fa2..deef29887 100644 --- a/src/Grpc.AspNetCore.Server/Internal/HttpContextServerCallContext.cs +++ b/src/Grpc.AspNetCore.Server/Internal/HttpContextServerCallContext.cs @@ -193,7 +193,16 @@ private void ProcessHandlerError(Exception ex, string method) } else { - GrpcServerLog.ErrorExecutingServiceMethod(Logger, method, ex); + if (ex is OperationCanceledException or IOException && CancellationTokenCore.IsCancellationRequested) + { + // Request cancellation can causes OCE and IO errors. + // When the request has been canceled log these error types at the info-level to avoid creating error-level noise. + GrpcServerLog.ServiceMethodCanceled(Logger, method, ex); + } + else + { + GrpcServerLog.ErrorExecutingServiceMethod(Logger, method, ex); + } var message = ErrorMessageHelper.BuildErrorMessage("Exception was thrown by handler.", ex, Options.EnableDetailedErrors); diff --git a/test/FunctionalTests/Client/StreamingTests.cs b/test/FunctionalTests/Client/StreamingTests.cs index da1668fe0..8aa9ec7e1 100644 --- a/test/FunctionalTests/Client/StreamingTests.cs +++ b/test/FunctionalTests/Client/StreamingTests.cs @@ -429,7 +429,7 @@ async Task ClientStreamedData(IAsyncStreamReader requ AssertHasLog(LogLevel.Information, "GrpcStatusError", "Call failed with gRPC error status. Status code: 'Cancelled', Message: ''."); await TestHelpers.AssertIsTrueRetryAsync( - () => HasLog(LogLevel.Error, "ErrorExecutingServiceMethod", "Error when executing service method 'ClientStreamedDataTimeout'."), + () => HasLog(LogLevel.Information, "ServiceMethodCanceled", "Service method 'ClientStreamedDataTimeout' canceled."), "Wait for server error so it doesn't impact other tests.").DefaultTimeout(); } From acf256c57943fd9370f429669d95a02737de4945 Mon Sep 17 00:00:00 2001 From: James Newton-King Date: Fri, 6 Sep 2024 11:31:30 +0800 Subject: [PATCH 2/2] Update --- .../Internal/HttpContextServerCallContext.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Grpc.AspNetCore.Server/Internal/HttpContextServerCallContext.cs b/src/Grpc.AspNetCore.Server/Internal/HttpContextServerCallContext.cs index deef29887..e799e2aa7 100644 --- a/src/Grpc.AspNetCore.Server/Internal/HttpContextServerCallContext.cs +++ b/src/Grpc.AspNetCore.Server/Internal/HttpContextServerCallContext.cs @@ -195,7 +195,7 @@ private void ProcessHandlerError(Exception ex, string method) { if (ex is OperationCanceledException or IOException && CancellationTokenCore.IsCancellationRequested) { - // Request cancellation can causes OCE and IO errors. + // Request cancellation can cause OCE and IOException. // When the request has been canceled log these error types at the info-level to avoid creating error-level noise. GrpcServerLog.ServiceMethodCanceled(Logger, method, ex); }