remove behavior and handler base exception logging

loresoft · May 10, 2024 · 9e576c3 · 9e576c3
1 parent 6316477
commit 9e576c3
Show file tree

Hide file tree

Showing 9 changed files with 55 additions and 44 deletions.
diff --git a/src/MediatR.CommandQuery.Audit/MediatR.CommandQuery.Audit.csproj b/src/MediatR.CommandQuery.Audit/MediatR.CommandQuery.Audit.csproj
@@ -7,7 +7,7 @@
   </PropertyGroup>
 
   <ItemGroup>
-    <PackageReference Include="EntityChange" Version="5.3.0" />
+    <PackageReference Include="EntityChange" Version="5.3.1" />
     <PackageReference Include="Microsoft.Extensions.DependencyInjection.Abstractions" Version="8.0.1" />
   </ItemGroup>
 

diff --git a/src/MediatR.CommandQuery.Cosmos/MediatR.CommandQuery.Cosmos.csproj b/src/MediatR.CommandQuery.Cosmos/MediatR.CommandQuery.Cosmos.csproj
@@ -8,7 +8,7 @@
 
   <ItemGroup>
     <PackageReference Include="AutoMapper" Version="13.0.1" />
-    <PackageReference Include="Cosmos.Abstracts" Version="6.1.0" />
+    <PackageReference Include="Cosmos.Abstracts" Version="6.2.0" />
   </ItemGroup>
 
   <ItemGroup>

diff --git a/src/MediatR.CommandQuery.Hangfire/MediatorDispatcher.cs b/src/MediatR.CommandQuery.Hangfire/MediatorDispatcher.cs
@@ -2,6 +2,8 @@
 
 using Hangfire;
 
+using MediatR.CommandQuery.Services;
+
 using Microsoft.Extensions.Logging;
 
 namespace MediatR.CommandQuery.Hangfire;
@@ -24,6 +26,7 @@ public async Task Send<TRequest>(TRequest request, CancellationToken cancellatio
         if (request is null)
             throw new ArgumentNullException(nameof(request));
 
+        var startTime = ActivityTimer.GetTimestamp();
         try
         {
             LogStart(_logger, request);
@@ -39,14 +42,20 @@ public async Task Send<TRequest>(TRequest request, CancellationToken cancellatio
             LogError(_logger, request, ex.Message, ex);
             throw;
         }
+        finally
+        {
+            var elaspsed = ActivityTimer.GetElapsedTime(startTime);
+            LogFinish(_logger, request, elaspsed.TotalMilliseconds);
+        }
+
     }
 
     [LoggerMessage(1, LogLevel.Trace, "Dispatching request '{request}' ...")]
     static partial void LogStart(ILogger logger, IBaseRequest request);
 
     [LoggerMessage(2, LogLevel.Trace, "Dispatched request '{request}': {elapsed} ms")]
-    static partial void LogFinish(ILogger logger, IBaseRequest request, long elapsed);
+    static partial void LogFinish(ILogger logger, IBaseRequest request, double elapsed);
 
-    [LoggerMessage(3, LogLevel.Trace, "Error Dispatching request '{request}': {errorMessage}")]
+    [LoggerMessage(3, LogLevel.Error, "Error Dispatching request '{request}': {errorMessage}")]
     static partial void LogError(ILogger logger, IBaseRequest request, string errorMessage, Exception? exception);
 }
diff --git a/src/MediatR.CommandQuery.Mvc/JsonExceptionMiddleware.cs b/src/MediatR.CommandQuery.Mvc/JsonExceptionMiddleware.cs
@@ -1,4 +1,5 @@
 using System.Diagnostics;
+using System.Net;
 using System.Text.Json;
 
 using FluentValidation;
@@ -36,6 +37,13 @@ public async Task Invoke(HttpContext context)
         {
             await _next(context).ConfigureAwait(false);
         }
+        catch (OperationCanceledException)
+        {
+            context.Response.StatusCode = 499; // Client Closed Request
+            context.Response.OnStarting(_clearCacheHeadersDelegate, context.Response);
+
+            return;
+        }
         catch (Exception middlewareError)
         {
             _logger.LogError(middlewareError, "An unhandled exception has occurred while executing the request.");

diff --git a/src/MediatR.CommandQuery/Behaviors/PipelineBehaviorBase.cs b/src/MediatR.CommandQuery/Behaviors/PipelineBehaviorBase.cs
@@ -1,5 +1,7 @@
 using System.Diagnostics;
 
+using MediatR.CommandQuery.Services;
+
 using Microsoft.Extensions.Logging;
 
 namespace MediatR.CommandQuery.Behaviors;
@@ -35,26 +37,16 @@ protected PipelineBehaviorBase(ILoggerFactory loggerFactory)
         if (next is null)
             throw new ArgumentNullException(nameof(next));
 
+        var startTime = ActivityTimer.GetTimestamp();
         try
         {
             LogStart(Logger, _name, request);
-            var watch = Stopwatch.StartNew();
-
-            var response = await Process(request, next, cancellationToken).ConfigureAwait(false);
-
-            watch.Stop();
-            LogFinish(Logger, _name, request, watch.ElapsedMilliseconds);
-
-            return response;
+            return await Process(request, next, cancellationToken).ConfigureAwait(false);
         }
-        catch (DomainException)
+        finally
         {
-            throw;
-        }
-        catch (Exception ex)
-        {
-            LogError(Logger, _name, request, ex.Message, ex);
-            throw new DomainException(ex.Message, ex);
+            var elaspsed = ActivityTimer.GetElapsedTime(startTime);
+            LogFinish(Logger, _name, request, elaspsed.TotalMilliseconds);
         }
     }
 
@@ -68,8 +60,5 @@ protected PipelineBehaviorBase(ILoggerFactory loggerFactory)
     static partial void LogStart(ILogger logger, string behavior, IRequest<TResponse> request);
 
     [LoggerMessage(2, LogLevel.Trace, "Processed behavior '{Behavior}' for request '{Request}': {Elapsed} ms")]
-    static partial void LogFinish(ILogger logger, string behavior, IRequest<TResponse> request, long elapsed);
-
-    [LoggerMessage(3, LogLevel.Error, "Error processing behavior '{Behavior}' for request '{Request}': {ErrorMessage}")]
-    static partial void LogError(ILogger logger, string behavior, IRequest<TResponse> request, string errorMessage, Exception? exception);
+    static partial void LogFinish(ILogger logger, string behavior, IRequest<TResponse> request, double elapsed);
 }
diff --git a/src/MediatR.CommandQuery/Handlers/RequestHandlerBase.cs b/src/MediatR.CommandQuery/Handlers/RequestHandlerBase.cs
@@ -1,5 +1,7 @@
 using System.Diagnostics;
 
+using MediatR.CommandQuery.Services;
+
 using Microsoft.Extensions.Logging;
 
 namespace MediatR.CommandQuery.Handlers;
@@ -27,26 +29,16 @@ public virtual async Task<TResponse> Handle(TRequest request, CancellationToken
         if (request is null)
             throw new ArgumentNullException(nameof(request));
 
+        var startTime = ActivityTimer.GetTimestamp();
         try
         {
             LogStart(Logger, _name, request);
-            var watch = Stopwatch.StartNew();
-
-            var response = await Process(request, cancellationToken).ConfigureAwait(false);
-
-            watch.Stop();
-            LogFinish(Logger, _name, request, watch.ElapsedMilliseconds);
-
-            return response;
+            return await Process(request, cancellationToken).ConfigureAwait(false);
         }
-        catch (DomainException)
+        finally
         {
-            throw;
-        }
-        catch (Exception ex)
-        {
-            LogError(Logger, _name, request, ex.Message, ex);
-            throw new DomainException(ex.Message, ex);
+            var elaspsed = ActivityTimer.GetElapsedTime(startTime);
+            LogFinish(Logger, _name, request, elaspsed.TotalMilliseconds);
         }
     }
 
@@ -57,8 +49,5 @@ public virtual async Task<TResponse> Handle(TRequest request, CancellationToken
     static partial void LogStart(ILogger logger, string handler, IRequest<TResponse> request);
 
     [LoggerMessage(2, LogLevel.Trace, "Processed handler '{Handler}' for request '{Request}': {Elapsed} ms")]
-    static partial void LogFinish(ILogger logger, string handler, IRequest<TResponse> request, long elapsed);
-
-    [LoggerMessage(3, LogLevel.Error, "Error processing handler '{Handler}' for request '{Request}': {ErrorMessage}")]
-    static partial void LogError(ILogger logger, string handler, IRequest<TResponse> request, string errorMessage, Exception? exception);
+    static partial void LogFinish(ILogger logger, string handler, IRequest<TResponse> request, double elapsed);
 }
diff --git a/src/MediatR.CommandQuery/MediatR.CommandQuery.csproj b/src/MediatR.CommandQuery/MediatR.CommandQuery.csproj
@@ -11,7 +11,7 @@
     <PackageReference Include="MediatR" Version="12.2.0" />
     <PackageReference Include="Microsoft.Extensions.Caching.Abstractions" Version="8.0.0" />
     <PackageReference Include="Microsoft.Extensions.Logging.Abstractions" Version="8.0.1" />
-    <PackageReference Include="System.Linq.Dynamic.Core" Version="1.3.13" />
+    <PackageReference Include="System.Linq.Dynamic.Core" Version="1.3.14" />
     <PackageReference Include="System.Text.Json" Version="8.0.3" />
     <PackageReference Include="SystemTextJsonPatch" Version="3.1.0" />
   </ItemGroup>

diff --git a/src/MediatR.CommandQuery/Services/ActivityTimer.cs b/src/MediatR.CommandQuery/Services/ActivityTimer.cs
@@ -0,0 +1,16 @@
+using System.Diagnostics;
+
+namespace MediatR.CommandQuery.Services;
+
+public static class ActivityTimer
+{
+    private static readonly double _tickFrequency = (double)TimeSpan.TicksPerSecond / Stopwatch.Frequency;
+
+    public static long GetTimestamp() => Stopwatch.GetTimestamp();
+
+    public static TimeSpan GetElapsedTime(long startingTimestamp)
+        => GetElapsedTime(startingTimestamp, GetTimestamp());
+
+    public static TimeSpan GetElapsedTime(long startingTimestamp, long endingTimestamp)
+        => new((long)((endingTimestamp - startingTimestamp) * _tickFrequency));
+}
diff --git a/test/Directory.Build.props b/test/Directory.Build.props
@@ -33,7 +33,7 @@
     <PackageReference Include="FluentAssertions" Version="6.12.0" />
     <PackageReference Include="Injectio" Version="3.1.0" PrivateAssets="All" />
     <PackageReference Include="MinVer" Version="5.0.0" PrivateAssets="All" />
-    <PackageReference Include="XUnit.Hosting" Version="1.5.0" />
+    <PackageReference Include="XUnit.Hosting" Version="1.6.0" />
   </ItemGroup>
 
   <ItemGroup>