Merge pull request #562 from TransactionProcessing/task/#550_projection_trace_threshold

Added trace threshold for projection

Author: StuartFerguson

TransactionProcessor.ProjectionEngine.Tests/ProjectionHandlerTests.cs

@@ -1,15 +1,23 @@
 namespace TransactionProcessor.ProjectionEngine.Tests;
 
 using Dispatchers;
+using Microsoft.Extensions.Configuration;
 using Moq;
 using Projections;
 using Repository;
 using Shared.DomainDrivenDesign.EventSourcing;
+using Shared.General;
 using Shouldly;
 using State;
 
 public class ProjectionHandlerTests{
 
+    public ProjectionHandlerTests(){
+        Shared.Logger.Logger.Initialise(Shared.Logger.NullLogger.Instance);
+        IConfigurationRoot configurationRoot = new ConfigurationBuilder().AddInMemoryCollection(TestData.DefaultAppSettings).Build();
+        ConfigurationReader.Initialise(configurationRoot);
+    }
+
     [Fact]
     public async Task ProjectionHandler_Handle_NullEvent_EventHandled(){
         Mock<IProjectionStateRepository<MerchantBalanceState>> repo = new Mock<IProjectionStateRepository<MerchantBalanceState>>();
@@ -57,8 +65,6 @@ public async Task ProjectionHandler_Handle_StateNotFoundInRepository_EventHandle
     [Fact]
     public async Task ProjectionHandler_Handle_StateFoundInRepository_NoChanges_EventHandled()
     {
-        Shared.Logger.Logger.Initialise(Shared.Logger.NullLogger.Instance);
-
         Mock<IProjectionStateRepository<MerchantBalanceState>> repo = new Mock<IProjectionStateRepository<MerchantBalanceState>>();
         Mock<IProjection<MerchantBalanceState>> projection = new Mock<IProjection<MerchantBalanceState>>();
         Mock<IStateDispatcher<MerchantBalanceState>> stateDispatcher = new Mock<IStateDispatcher<MerchantBalanceState>>();
@@ -80,8 +86,6 @@ public async Task ProjectionHandler_Handle_StateFoundInRepository_NoChanges_Even
     [Fact]
     public async Task ProjectionHandler_Handle_StateFoundInRepository_ChangesMade_EventHandled()
     {
-        Shared.Logger.Logger.Initialise(Shared.Logger.NullLogger.Instance);
-
         Mock<IProjectionStateRepository<MerchantBalanceState>> repo = new Mock<IProjectionStateRepository<MerchantBalanceState>>();
         Mock<IProjection<MerchantBalanceState>> projection = new Mock<IProjection<MerchantBalanceState>>();
         Mock<IStateDispatcher<MerchantBalanceState>> stateDispatcher = new Mock<IStateDispatcher<MerchantBalanceState>>();

TransactionProcessor.ProjectionEngine.Tests/TestData.cs

@@ -167,6 +167,7 @@ public static TransactionHasStartedEvent GetTransactionHasStartedEvent(Decimal?
         public static IReadOnlyDictionary<String, String> DefaultAppSettings =>
             new Dictionary<String, String>
             {
+                ["AppSettings:ProjectionTraceThresholdInSeconds"] = "1",
                 ["AppSettings:ClientId"] = "clientId",
                 ["AppSettings:ClientSecret"] = "clientSecret",
                 ["AppSettings:UseConnectionStringConfig"] = "false",

TransactionProcessor.ProjectionEngine/ProjectionHandler/ProjectionHandler.cs

@@ -7,6 +7,7 @@
 using Projections;
 using Repository;
 using Shared.DomainDrivenDesign.EventSourcing;
+using Shared.General;
 using Shared.Logger;
 using State;
 
@@ -25,12 +26,10 @@ public ProjectionHandler(IProjectionStateRepository<TState> projectionStateRepos
         this.StateDispatcher = stateDispatcher;
     }
 
-    public async Task Handle(IDomainEvent @event, CancellationToken cancellationToken)
-    {
+    public async Task Handle(IDomainEvent @event, CancellationToken cancellationToken){
         if (@event == null) return;
-        
-        if (this.Projection.ShouldIHandleEvent(@event) == false)
-        {
+
+        if (this.Projection.ShouldIHandleEvent(@event) == false){
             return;
         }
 
@@ -40,8 +39,7 @@ public async Task Handle(IDomainEvent @event, CancellationToken cancellationToke
         //Load the state from persistence
         TState state = await this.ProjectionStateRepository.Load(@event, cancellationToken);
 
-        if (state == null)
-        {
+        if (state == null){
             return;
         }
 
@@ -50,41 +48,40 @@ public async Task Handle(IDomainEvent @event, CancellationToken cancellationToke
         builder.Append($"{stopwatch.ElapsedMilliseconds}ms Handling {@event.EventType} Id [{@event.EventId}] for state {state.GetType().Name}|");
 
         TState newState = await this.Projection.Handle(state, @event, cancellationToken);
-        
+
         builder.Append($"{stopwatch.ElapsedMilliseconds}ms After Handle|");
 
-        if (newState != state)
-        {
-            newState = newState with
-                       {
-                           ChangesApplied = true
-                       };
-            
+        if (newState != state){
+            newState = newState with{
+                                        ChangesApplied = true
+                                    };
+
             // save state
             newState = await this.ProjectionStateRepository.Save(newState, @event, cancellationToken);
 
             //Repo might have detected a duplicate event
             builder.Append($"{stopwatch.ElapsedMilliseconds}ms After Save|");
 
-            if (this.StateDispatcher != null)
-            {
+            if (this.StateDispatcher != null){
                 // Send to anyone else interested
                 await this.StateDispatcher.Dispatch(newState, @event, cancellationToken);
 
                 builder.Append($"{stopwatch.ElapsedMilliseconds}ms After Dispatch|");
             }
-            
+
         }
-        else
-        {
+        else{
             builder.Append($"{stopwatch.ElapsedMilliseconds}ms No Save required|");
         }
 
         stopwatch.Stop();
 
         builder.Insert(0, $"Total time: {stopwatch.ElapsedMilliseconds}ms|");
-        Logger.LogWarning(builder.ToString());
-        Logger.LogInformation($"Event Type {@event.EventType} Id [{@event.EventId}] for state {state.GetType().Name} took {stopwatch.ElapsedMilliseconds}ms to process");
 
+        Int32 projectionTraceThresholdInSeconds = Int32.Parse(ConfigurationReader.GetValue("AppSettings", "ProjectionTraceThresholdInSeconds"));
+        if (stopwatch.Elapsed.Seconds > projectionTraceThresholdInSeconds){
+            Logger.LogWarning(builder.ToString());
+            Logger.LogInformation($"Event Type {@event.EventType} Id [{@event.EventId}] for state {state.GetType().Name} took {stopwatch.ElapsedMilliseconds}ms to process");
+        }
     }
 }

TransactionProcessor/appsettings.json

@@ -3,6 +3,7 @@
     "ClientId": "serviceClient",
     "ClientSecret": "d192cbc46d834d0da90e8a9d50ded543",
     //"SecurityService": "https://127.0.0.1:5001",
+    "ProjectionTraceThresholdInSeconds": 1,
     "EventHandlerConfiguration": {
       "TransactionHasBeenCompletedEvent": [
         "TransactionProcessor.BusinessLogic.EventHandling.TransactionDomainEventHandler,TransactionProcessor.BusinessLogic"
@@ -105,7 +106,7 @@
         }
       ]
     }
-    },
+  },
   "ConnectionStrings": {
     // SQL Server
     "TransactionProcessorReadModel": "server=192.168.1.167;user id=sa;password=Sc0tland;database=TransactionProcessorReadModel;Encrypt=false"