Improve CorrelationId to use a static AsyncLocal string.

src/application/PlantBasedPizza.Api/Program.cs

@@ -42,37 +42,33 @@
     var correlationId = string.Empty;
 
     if (context.Request.Headers.ContainsKey("X-Amzn-Trace-Id"))
-    {
-        observability.Info(string.Empty, "Trace id found");
-
+    {   
         correlationId = context.Request.Headers["X-Amzn-Trace-Id"].ToString();
 
-        context.Request.Headers.Add("CorrelationId", correlationId);
+        context.Request.Headers.Add(CorrelationContext.DefaultRequestHeaderName, correlationId);
     }
-    else if (context.Request.Headers.ContainsKey("CorrelationId"))
+    else if (context.Request.Headers.ContainsKey(CorrelationContext.DefaultRequestHeaderName))
     {
-        observability.Info(string.Empty, "Header correlation id found");
-
-        correlationId = context.Request.Headers["CorrelationId"].ToString();
+        correlationId = context.Request.Headers[CorrelationContext.DefaultRequestHeaderName].ToString();
     }
     else
     {
-        observability.Info(string.Empty, "Generating new correlation id");
-
         correlationId = Guid.NewGuid().ToString();
 
-        context.Request.Headers.Add("CorrelationId", correlationId);
+        context.Request.Headers.Add(CorrelationContext.DefaultRequestHeaderName, correlationId);
     }
 
     var timer = new System.Timers.Timer();
 
     timer.Start();
 
-    observability.Info(correlationId, $"Request received to {context.Request.Path.Value}");
+    CorrelationContext.SetCorrelationId(correlationId);
+
+    observability.Info($"Request received to {context.Request.Path.Value}");
 
-    observability.StartTraceSegment(context.Request.Path.Value, correlationId);
+    observability.StartTraceSegment(context.Request.Path.Value);
 
-    context.Response.Headers.Add("CorrelationId", correlationId);
+    context.Response.Headers.Add(CorrelationContext.DefaultRequestHeaderName, correlationId);
 
     // Do work that doesn't write to the Response.
     await next.Invoke();

src/modules/deliver/PlantBasedPizza.Deliver.Core/Handlers/OrderReadyForDeliveryEventHandler.cs

@@ -31,7 +31,7 @@ public async Task Handle(OrderReadyForDeliveryEvent evt)
 
             if (existingDeliveryRequestForOrder != null)
             {
-                this._logger.Info(evt.CorrelationId, "Delivery request for order received, skipping");
+                this._logger.Info("Delivery request for order received, skipping");
                 return;
             }
 

src/modules/deliver/PlantBasedPizza.Deliver.Infrastructure/Controllers/DeliveryRequestController.cs

@@ -29,8 +29,7 @@ public DeliveryRequestController(IDeliveryRequestRepository deliveryRequestRepos
         [HttpGet("delivery/awaiting-collection")]
         public async Task<List<DeliveryRequest>> GetAwaitingCollection()
         {
-            this._logger.Info(this.Request.Headers["CorrelationId"],
-                "Received request to get orders awaiting collection");
+            this._logger.Info("Received request to get orders awaiting collection");
 
             return await this._deliveryRequestRepository.GetAwaitingDriver();
         }

src/modules/kitchen/PlantBasedPizza.Kitchen.Core/Handlers/OrderSubmittedEventHandler.cs

@@ -30,24 +30,24 @@ public async Task Handle(OrderSubmittedEvent evt)
         {
             Guard.AgainstNull(evt, nameof(evt));
 
-            this._logger.Info(evt.CorrelationId, "[KITCHEN] Logging order submitted event");
+            this._logger.Info("[KITCHEN] Logging order submitted event");
 
             var recipes = new List<RecipeAdapter>();
 
             var order = await this._orderManagerService.GetOrderDetails(evt.OrderIdentifier);
 
-            this._logger.Info(evt.CorrelationId, $"[KITCHEN] Order has {order.Items.Count} item(s)");
+            this._logger.Info($"[KITCHEN] Order has {order.Items.Count} item(s)");
 
             foreach (var recipe in order.Items)
             {
-                this._logger.Info(evt.CorrelationId, $"[KITCHEN] Addig item {recipe.ItemName}");
+                this._logger.Info($"[KITCHEN] Addig item {recipe.ItemName}");
 
                 recipes.Add(await this._recipeService.GetRecipe(recipe.RecipeIdentifier));
             }
 
             var kitchenRequest = new KitchenRequest(evt.OrderIdentifier, recipes);
 
-            this._logger.Info(evt.CorrelationId, "[KITCHEN] Storing kitchen request");
+            this._logger.Info("[KITCHEN] Storing kitchen request");
 
             await this._kitchenRequestRepository.AddNew(kitchenRequest);
         }

src/modules/order-manager/PlantBasedPizza.OrderManager.Core/Entites/Order.cs

@@ -5,6 +5,8 @@
 using PlantBasedPizza.Events;
 using PlantBasedPizza.Shared.Events;
 using PlantBasedPizza.Shared.Guards;
+using PlantBasedPizza.Shared.Logging;
+using Serilog;
 
 namespace PlantBasedPizza.OrderManager.Core.Entites
 {
@@ -37,6 +39,8 @@ public static Order Create(string orderIdentifier, OrderType type, string custom
                 throw new ArgumentException("If order type is delivery a delivery address must be specified",
                     nameof(deliveryDetails));
             }
+
+            ApplicationLogger.Info($"Creating a new order with type {type}");
 
             var order = new Order()
             {
@@ -85,6 +89,7 @@ public void AddOrderItem(string recipeIdentifier, string itemName, int quantity,
         {
             if (this.OrderSubmittedOn.HasValue)
             {
+                ApplicationLogger.Warn("Attempting to add an order item to an order that has already been submitted, skipping");
                 return;
             }
 

src/shared/PlantBasedPizza.Shared/Events/DomainEvents.cs

@@ -36,12 +36,18 @@ public async static Task Raise<T>(T evt) where T : IDomainEvent
             if (Container != null)
             {
                 var observability = Container.GetService<IObservabilityService>();
-                observability.Info(evt.CorrelationId, $"[EVENT MANAGER] Raising event {evt.EventName}");
+
+                observability.Info($"[EVENT MANAGER] Raising event {evt.EventName}");
 
                 foreach (var handler in Container.GetServices<Handles<T>>())
                 {
-                    observability.Info(evt.CorrelationId, $"[EVENT MANAGER] Handling event with handler {handler.GetType().Name}");
+                    observability.StartTraceSubsegment(handler.GetType().Name);
+
+                    observability.Info($"[EVENT MANAGER] Handling event with handler {handler.GetType().Name}");
+
                     await handler.Handle(evt);
+
+                    observability.EndTraceSubsegment();
                 }
             }
 

src/shared/PlantBasedPizza.Shared/Logging/ApplicationLogger.cs

@@ -2,6 +2,7 @@
 using Serilog;
 using Serilog.Context;
 using Serilog.Core;
+using Serilog.Events;
 using Serilog.Formatting.Compact;
 using Serilog.Formatting.Json;
 
@@ -14,26 +15,35 @@ public static class ApplicationLogger
         public static void Init()
         {
             _logger = new LoggerConfiguration()
-                .WriteTo.Console(new JsonFormatter())
+                .MinimumLevel.Debug()
+                .MinimumLevel.Override("Microsoft", LogEventLevel.Error)
+                .Enrich.FromLogContext()
+                .WriteTo.Console()
                 .WriteTo.File(new JsonFormatter(), "logs/myapp-{Date}.json")
                 .CreateLogger();
         }
 
-        public static void Info(string correlationId, string message)
+        public static void Info(string message)
         {
-            using (LogContext.PushProperty("CorrelationId", correlationId))
+            using (LogContext.PushProperty("CorrelationId", CorrelationContext.GetCorrelationId()))
                 _logger.Information(message);
         }
 
-        public static void Warn(string correlationId, Exception ex, string message)
+        public static void Warn(Exception ex, string message)
         {
-            using (LogContext.PushProperty("CorrelationId", correlationId))
+            using (LogContext.PushProperty("CorrelationId", CorrelationContext.GetCorrelationId()))
                 _logger.Warning(ex, message);
         }
 
-        public static void Error(string correlationId, Exception ex, string message)
+        public static void Warn(string message)
         {
-            using (LogContext.PushProperty("CorrelationId", correlationId))
+            using (LogContext.PushProperty("CorrelationId", CorrelationContext.GetCorrelationId()))
+                _logger.Warning(message);
+        }
+
+        public static void Error(Exception ex, string message)
+        {
+            using (LogContext.PushProperty("CorrelationId", CorrelationContext.GetCorrelationId()))
                 _logger.Error(ex, message);
         }
     }

src/shared/PlantBasedPizza.Shared/Logging/CorrelationContext.cs

@@ -0,0 +1,28 @@
+namespace PlantBasedPizza.Shared.Logging;
+
+public static class CorrelationContext
+{
+    private static readonly AsyncLocal<string> _correlationId = new AsyncLocal<string>();
+
+    public static string DefaultRequestHeaderName = "X-Correlation-ID";
+
+    public static void SetCorrelationId(string correlationId)
+    {
+        if (string.IsNullOrWhiteSpace(correlationId))
+        {
+            throw new ArgumentException("Correlation Id cannot be null or empty", nameof(correlationId));
+        }
+
+        if (!string.IsNullOrWhiteSpace(_correlationId.Value))
+        {
+            throw new InvalidOperationException("Correlation Id is already set for the context");
+        }
+
+        _correlationId.Value = correlationId;
+    }
+
+    public static string GetCorrelationId()
+    {
+        return _correlationId.Value;
+    }
+}

src/shared/PlantBasedPizza.Shared/Logging/IObservabilityService.cs

@@ -5,7 +5,7 @@ namespace PlantBasedPizza.Shared.Logging
 {
     public interface IObservabilityService
     {
-        void StartTraceSegment(string segmentName, string correlationId = "");
+        void StartTraceSegment(string segmentName);
 
         void EndTraceSegment();
 
@@ -23,10 +23,10 @@ public interface IObservabilityService
 
         Task<TResult> TraceMethodAsync<TResult>(string methodName, Func<Task<TResult>> method);
 
-        void Info(string correlationId, string message);
+        void Info(string message);
 
-        void Warn(string correlationId, Exception ex, string message);
+        void Warn(Exception ex, string message);
 
-        void Error(string correlationId, Exception ex, string message);
+        void Error(Exception ex, string message);
     }
 }

src/shared/PlantBasedPizza.Shared/Logging/ObservabiityService.cs

@@ -18,11 +18,11 @@ public ObservabiityService(AmazonCloudWatchClient cloudWatchClient)
             this._cloudWatchClient = cloudWatchClient;
         }
 
-        public void StartTraceSegment(string segmentName, string correlationId = "")
+        public void StartTraceSegment(string segmentName)
         {
             AWSXRayRecorder.Instance.BeginSegment(segmentName);
 
-            AWSXRayRecorder.Instance.AddAnnotation("CorrelationId", correlationId);
+            AWSXRayRecorder.Instance.AddAnnotation("CorrelationId", CorrelationContext.GetCorrelationId());
         }
 
         public void EndTraceSegment()
@@ -71,10 +71,6 @@ await this._cloudWatchClient.PutMetricDataAsync(new PutMetricDataRequest()
             {
             }
         }
-
-        public void AddCorrelationId(string correlationId)
-        {
-        }
 
         public TResult TraceMethod<TResult>(string methodName, Func<TResult> method)
         {
@@ -102,21 +98,19 @@ public async Task<TResult> TraceMethodAsync<TResult>(string methodName, Func<Tas
             return await AWSXRayRecorder.Instance.TraceMethodAsync<TResult>(methodName, method);
         }
 
-        public void Info(string correlationId, string message)
+        public void Info(string message)
         {
-            using (LogContext.PushProperty("CorrelationId", correlationId))
-                Log.Information(message);
+            ApplicationLogger.Info(message);
         }
 
-        public void Warn(string correlationId, Exception ex, string message)
+        public void Warn(Exception ex, string message)
         {
-            using (LogContext.PushProperty("CorrelationId", correlationId))
-                Log.Warning(ex, message);
+            ApplicationLogger.Warn(ex, message);
         }
 
-        public void Error(string correlationId, Exception ex, string message)
+        public void Error(Exception ex, string message)
         {
-            Log.Error(correlationId, ex, message);
+            ApplicationLogger.Error(ex, message);
         }
     }
 }

src/shared/PlantBasedPizza.Shared/Setup.cs

@@ -8,6 +8,7 @@
 using Microsoft.Extensions.DependencyInjection;
 using PlantBasedPizza.Shared.Logging;
 using Serilog;
+using Serilog.Events;
 using Serilog.Formatting.Json;
 
 namespace PlantBasedPizza.Shared
@@ -33,6 +34,8 @@ public static IServiceCollection AddSharedInfrastructure(this IServiceCollection
         public static WebApplicationBuilder AddSharedInfrastructure(this WebApplicationBuilder builder)
         {
             builder.Host.UseSerilog((ctx, lc) => lc
+                .MinimumLevel.Debug()
+                .MinimumLevel.Override("Microsoft", LogEventLevel.Error)
                 .Enrich.FromLogContext()
                 .WriteTo.Console()
                 .WriteTo.File(new JsonFormatter(), "logs/myapp-{Date}.json"));