perf: use logging methods and pass cancellation token (#395)

Author: ikesnowy

src/Cnblogs.Architecture.Ddd.Cqrs.Abstractions/InvalidCacheRequestHandler.cs

@@ -7,7 +7,7 @@ namespace Cnblogs.Architecture.Ddd.Cqrs.Abstractions;
 /// <summary>
 ///     The default handler for <see cref="InvalidCacheRequest"/>.
 /// </summary>
-public class InvalidCacheRequestHandler : IRequestHandler<InvalidCacheRequest>
+public partial class InvalidCacheRequestHandler : IRequestHandler<InvalidCacheRequest>
 {
     private readonly ICacheProvider _cacheProvider;
     private readonly ILogger<InvalidCacheRequestHandler> _logger;
@@ -41,15 +41,14 @@ public async Task Handle(InvalidCacheRequest request, CancellationToken cancella
         }
         catch (Exception e)
         {
-            _logger.LogError(
-                "----- Invalid Cache Failed, Type: {TypeName}, Request: {RequestBody}, Message: {Message}",
-                request.GetType().Name,
-                request,
-                e.Message);
+            LogInvalidCacheFailed(request.GetType().Name, request, e.Message);
             if (request.ThrowIfFailed == true)
             {
                 throw;
             }
         }
     }
+
+    [LoggerMessage(LogLevel.Error, "----- Invalid Cache Failed, Type: {TypeName}, Request: {RequestBody}, Message: {Message}")]
+    partial void LogInvalidCacheFailed(string typeName, InvalidCacheRequest requestBody, string message);
 }

src/Cnblogs.Architecture.Ddd.Cqrs.Abstractions/LockableRequestBehavior.cs

@@ -1,7 +1,5 @@
 using Cnblogs.Architecture.Ddd.Infrastructure.Abstractions;
-
 using MediatR;
-
 using Microsoft.Extensions.Logging;
 
 namespace Cnblogs.Architecture.Ddd.Cqrs.Abstractions;
@@ -11,7 +9,7 @@ namespace Cnblogs.Architecture.Ddd.Cqrs.Abstractions;
 /// </summary>
 /// <typeparam name="TRequest">The type of request.</typeparam>
 /// <typeparam name="TResponse">The type of response.</typeparam>
-public class LockableRequestBehavior<TRequest, TResponse> : IPipelineBehavior<TRequest, TResponse>
+public partial class LockableRequestBehavior<TRequest, TResponse> : IPipelineBehavior<TRequest, TResponse>
     where TRequest : ILockableRequest, IRequest<TResponse>
     where TResponse : ILockableResponse, new()
 {
@@ -45,19 +43,21 @@ public async Task<TResponse> Handle(
                 : null;
             var response = await _distributedLockProvider.ExecuteWithLockAsync(
                 request.GetLockKey(),
-                async () => await next(),
+                async () => await next(cancellationToken),
                 expiresIn);
             response.LockAcquired = true;
             return response;
         }
         catch (AcquireDistributionLockFailedException e)
         {
-            _logger.LogError(
-                e,
-                "Acquire Distribution Lock Failed, Request: {@Request}, LockKey: {@LockLey}",
-                request,
-                e.LockKey);
+            LogAcquireDistributionLockFailed(request, e.LockKey, e);
             return new TResponse { IsConcurrentError = true, LockAcquired = false };
         }
     }
-}
+
+    [LoggerMessage(LogLevel.Error, "Acquire Distribution Lock Failed, Request: {@request}, LockKey: {@lockLey}")]
+    partial void LogAcquireDistributionLockFailed(
+        TRequest request,
+        string lockLey,
+        AcquireDistributionLockFailedException acquireDistributionLockFailedException);
+}

src/Cnblogs.Architecture.Ddd.Cqrs.Abstractions/LoggingBehavior.cs

@@ -9,7 +9,7 @@ namespace Cnblogs.Architecture.Ddd.Cqrs.Abstractions;
 /// </summary>
 /// <typeparam name="TRequest">The type of request.</typeparam>
 /// <typeparam name="TResponse">The type of response.</typeparam>
-public class LoggingBehavior<TRequest, TResponse> : IPipelineBehavior<TRequest, TResponse>
+public partial class LoggingBehavior<TRequest, TResponse> : IPipelineBehavior<TRequest, TResponse>
     where TRequest : IRequest<TResponse>
 {
     private readonly ILogger<LoggingBehavior<TRequest, TResponse>> _logger;
@@ -29,9 +29,15 @@ public async Task<TResponse> Handle(
         RequestHandlerDelegate<TResponse> next,
         CancellationToken cancellationToken)
     {
-        _logger.LogDebug("Handling {@Request}", request);
-        var result = await next();
-        _logger.LogDebug("Handled {@Request}", request);
+        LogHandlingRequest(request);
+        var result = await next(cancellationToken);
+        LogHandledRequest(request);
         return result;
     }
+
+    [LoggerMessage(LogLevel.Debug, "Handling {request}")]
+    partial void LogHandlingRequest(TRequest request);
+
+    [LoggerMessage(LogLevel.Debug, "Handled {Request}")]
+    partial void LogHandledRequest(TRequest request);
 }

src/Cnblogs.Architecture.Ddd.Cqrs.Abstractions/ValidationBehavior.cs

@@ -9,7 +9,7 @@ namespace Cnblogs.Architecture.Ddd.Cqrs.Abstractions;
 /// </summary>
 /// <typeparam name="TRequest">The type of request.</typeparam>
 /// <typeparam name="TResponse">The type of response.</typeparam>
-public class ValidationBehavior<TRequest, TResponse> : IPipelineBehavior<TRequest, TResponse>
+public partial class ValidationBehavior<TRequest, TResponse> : IPipelineBehavior<TRequest, TResponse>
     where TRequest : IValidatable, IRequest<TResponse>
     where TResponse : IValidationResponse, new()
 {
@@ -30,19 +30,15 @@ public async Task<TResponse> Handle(
         RequestHandlerDelegate<TResponse> next,
         CancellationToken cancellationToken)
     {
-        _logger.LogInformation("----- Validating request {RequestType}", request.GetType().Name);
+        LogValidating(request.GetType().Name);
         var errors = new ValidationErrors();
         request.Validate(errors);
         if (errors.Count == 0)
         {
-            return await next();
+            return await next(cancellationToken);
         }
 
-        _logger.LogWarning(
-            "----- Validation failed with error, type: {RequestType}, Request: {Request}, Message: {Message}",
-            request.GetType().Name,
-            request,
-            errors.First().Message);
+        LogValidationFailedWithError(request.GetType().Name, request, errors.First().Message);
 
         return new TResponse
         {
@@ -51,4 +47,10 @@ public async Task<TResponse> Handle(
             ValidationErrors = errors
         };
     }
-}
+
+    [LoggerMessage(LogLevel.Information, "----- Validating request {RequestType}")]
+    partial void LogValidating(string requestType);
+
+    [LoggerMessage(LogLevel.Warning, "----- Validation failed with error, type: {RequestType}, Request: {Request}, Message: {Message}")]
+    partial void LogValidationFailedWithError(string requestType, TRequest request, string message);
+}

src/Cnblogs.Architecture.Ddd.EventBus.Abstractions/DefaultEventBus.cs

@@ -6,7 +6,7 @@ namespace Cnblogs.Architecture.Ddd.EventBus.Abstractions;
 /// <summary>
 ///     Default implementation for <see cref="IEventBus"/>
 /// </summary>
-public class DefaultEventBus : IEventBus
+public partial class DefaultEventBus : IEventBus
 {
     private readonly IEventBuffer _eventBuffer;
     private readonly IMediator _mediator;
@@ -59,7 +59,7 @@ public async Task<bool> TryPublishAsync<TEvent>(string eventName, TEvent @event)
         }
         catch (Exception e)
         {
-            _logger.LogError(e, "Publish IntegrationEvent({Name}) failed, {Event}", eventName, @event);
+            LogPublishIntegrationEvent(eventName, @event, e);
             return false;
         }
     }
@@ -69,15 +69,17 @@ public Task ReceiveAsync<TEvent>(TEvent receivedEvent)
         where TEvent : IntegrationEvent
     {
         var traceId = receivedEvent.TraceId ?? receivedEvent.Id;
-        _logger.LogInformation(
-            "Received integration event, Name: {EventName}, Event: {Event}, TraceId: {TraceId}",
-            typeof(TEvent).Name,
-            receivedEvent,
-            traceId);
+        LogReceivedIntegrationEventName(typeof(TEvent).Name, receivedEvent, traceId);
         TraceId = traceId;
         return _mediator.Publish(receivedEvent);
     }
 
     /// <inheritdoc />
     public Guid? TraceId { get; set; }
+
+    [LoggerMessage(LogLevel.Error, "Publish IntegrationEvent({Name}) failed, {Event}")]
+    partial void LogPublishIntegrationEvent(string name, object @event, Exception exception);
+
+    [LoggerMessage(LogLevel.Information, "Received integration event, Name: {EventName}, Event: {Event}, TraceId: {TraceId}")]
+    partial void LogReceivedIntegrationEventName(string eventName, object @event, Guid traceId);
 }

src/Cnblogs.Architecture.Ddd.EventBus.Dapr/DaprEventBusProvider.cs

@@ -8,7 +8,7 @@ namespace Cnblogs.Architecture.Ddd.EventBus.Dapr;
 /// <summary>
 ///     Implementations for <see cref="IEventBusProvider"/> using Dapr.
 /// </summary>
-public class DaprEventBusProvider : IEventBusProvider
+public partial class DaprEventBusProvider : IEventBusProvider
 {
     private readonly DaprClient _daprClient;
     private readonly DaprOptions _daprOptions;
@@ -33,17 +33,14 @@ public DaprEventBusProvider(
     /// <inheritdoc />
     public async Task PublishAsync(string eventName, IntegrationEvent @event)
     {
-        _logger.LogInformation(
-            "Publishing IntegrationEvent, PubSub: {PubSubName}, TopicName: {TopicName}, Name: {EventName}, Body: {Event}, TraceId: {TraceId}",
-            DaprOptions.PubSubName,
-            DaprUtils.GetDaprTopicName(_daprOptions.AppName, eventName),
-            eventName,
-            @event,
-            @event.TraceId ?? @event.Id);
+        LogPublishingIntegrationEvent(DaprOptions.PubSubName, DaprUtils.GetDaprTopicName(_daprOptions.AppName, eventName), eventName, @event, @event.TraceId ?? @event.Id);
         object data = @event; // do not provide type information to serializer since it's base class.
         await _daprClient.PublishEventAsync(
             DaprOptions.PubSubName,
             DaprUtils.GetDaprTopicName(_daprOptions.AppName, eventName),
             data);
     }
+
+    [LoggerMessage(LogLevel.Information, "Publishing IntegrationEvent, PubSub: {PubSubName}, TopicName: {TopicName}, Name: {EventName}, Body: {Event}, TraceId: {TraceId}")]
+    partial void LogPublishingIntegrationEvent(string pubSubName, string topicName, string eventName, IntegrationEvent @event, Guid traceId);
 }

test/Cnblogs.Architecture.IntegrationTestProject/EventHandlers/TestIntegrationEventHandler.cs

@@ -4,27 +4,24 @@
 
 namespace Cnblogs.Architecture.IntegrationTestProject.EventHandlers;
 
-public class TestIntegrationEventHandler : IIntegrationEventHandler<TestIntegrationEvent>,
-    IIntegrationEventHandler<BlogPostCreatedIntegrationEvent>
+public partial class TestIntegrationEventHandler(ILogger<TestIntegrationEventHandler> logger)
+    : IIntegrationEventHandler<TestIntegrationEvent>,
+        IIntegrationEventHandler<BlogPostCreatedIntegrationEvent>
 {
-    private readonly ILogger _logger;
-
-    public TestIntegrationEventHandler(ILogger<TestIntegrationEventHandler> logger)
-    {
-        _logger = logger;
-    }
+    private readonly ILogger _logger = logger;
 
     public Task Handle(TestIntegrationEvent notification, CancellationToken cancellationToken)
     {
-        _logger.LogInformation(LogTemplates.HandledIntegratonEvent, notification);
-
+        LogHandledIntegrationEventEvent(notification);
         return Task.CompletedTask;
     }
 
     public Task Handle(BlogPostCreatedIntegrationEvent notification, CancellationToken cancellationToken)
     {
-        _logger.LogInformation(LogTemplates.HandledIntegratonEvent, notification);
-
+        LogHandledIntegrationEventEvent(notification);
         return Task.CompletedTask;
     }
-}
+
+    [LoggerMessage(LogLevel.Information, LogTemplates.HandledIntegratonEvent)]
+    partial void LogHandledIntegrationEventEvent(object @event);
+}

test/Cnblogs.Architecture.UnitTests/Cqrs/Behaviors/LoggerBehaviorTests.cs

@@ -29,27 +29,21 @@ public async Task LoggerBehavior_ShouldLogDebugAsync()
             Arg.Any<Func<object, Exception?, string>>());
     }
 
-    private class TestLogger<T> : ILogger<T>
+    private class TestLogger<T>(ILogger<T> logger) : ILogger<T>
     {
-        private readonly ILogger<T> _logger;
-
         // ReSharper disable once ContextualLoggerProblem
-        public TestLogger(ILogger<T> logger)
-        {
-            _logger = logger;
-        }
 
         /// <inheritdoc />
         public IDisposable? BeginScope<TState>(TState state)
             where TState : notnull
         {
-            return _logger.BeginScope(state);
+            return logger.BeginScope(state);
         }
 
         /// <inheritdoc />
         public virtual bool IsEnabled(LogLevel logLevel)
         {
-            return _logger.IsEnabled(logLevel);
+            return true;
         }
 
         /// <inheritdoc />
@@ -60,7 +54,7 @@ public virtual void Log<TState>(
             Exception? exception,
             Func<TState, Exception?, string> formatter)
         {
-            _logger.Log<object>(logLevel, eventId, state!, exception, (_, _) => string.Empty);
+            logger.Log<object>(logLevel, eventId, state!, exception, (_, _) => string.Empty);
         }
     }
 }