From f52e2195cf79d3bf82c77ed321de573d5b6ac231 Mon Sep 17 00:00:00 2001
From: Mads Magnus Due <xmadu@energinet.dk>
Date: Tue, 10 Dec 2024 12:38:57 +0100
Subject: [PATCH] chore: log incoming message execution time (#1414)

---
 .../IncomingMessageReceiver.cs                |  5 +++++
 .../UseCases/ReceiveIncomingMarketMessage.cs  | 19 +++++++++++++++++++
 2 files changed, 24 insertions(+)

diff --git a/source/B2BApi/IncomingMessages/IncomingMessageReceiver.cs b/source/B2BApi/IncomingMessages/IncomingMessageReceiver.cs
index 87ffc8477..77361ee5e 100644
--- a/source/B2BApi/IncomingMessages/IncomingMessageReceiver.cs
+++ b/source/B2BApi/IncomingMessages/IncomingMessageReceiver.cs
@@ -12,6 +12,7 @@
 // See the License for the specific language governing permissions and
 // limitations under the License.
 
+using System.Diagnostics;
 using System.Net;
 using System.Text;
 using Energinet.DataHub.EDI.AuditLog.AuditLogger;
@@ -55,6 +56,7 @@ public async Task<HttpResponseData> RunAsync(
         CancellationToken hostCancellationToken)
     {
         ArgumentNullException.ThrowIfNull(request);
+        var stopwatch = Stopwatch.StartNew();
         var cancellationToken = request.GetCancellationToken(hostCancellationToken);
 
         if (!await _featureFlagManager.ReceiveMeteredDataForMeasurementPointsAsync().ConfigureAwait(false))
@@ -113,6 +115,9 @@ public async Task<HttpResponseData> RunAsync(
         var httpResponseData = await CreateResponseAsync(request, httpStatusCode, documentFormat, responseMessage)
             .ConfigureAwait(false);
 
+        stopwatch.Stop();
+        _logger.LogInformation($"IncomingMessage Execution time: {stopwatch.ElapsedMilliseconds} ms");
+
         return httpResponseData;
     }
 
diff --git a/source/IncomingMessages.Application/UseCases/ReceiveIncomingMarketMessage.cs b/source/IncomingMessages.Application/UseCases/ReceiveIncomingMarketMessage.cs
index bcfe9b900..ca5070ed6 100644
--- a/source/IncomingMessages.Application/UseCases/ReceiveIncomingMarketMessage.cs
+++ b/source/IncomingMessages.Application/UseCases/ReceiveIncomingMarketMessage.cs
@@ -12,6 +12,7 @@
 // See the License for the specific language governing permissions and
 // limitations under the License.
 
+using System.Diagnostics;
 using Energinet.DataHub.EDI.ArchivedMessages.Interfaces;
 using Energinet.DataHub.EDI.ArchivedMessages.Interfaces.Models;
 using Energinet.DataHub.EDI.BuildingBlocks.Domain.Authentication;
@@ -78,12 +79,18 @@ public async Task<ResponseMessage> ReceiveIncomingMarketMessageAsync(
     {
         ArgumentNullException.ThrowIfNull(documentType);
         ArgumentNullException.ThrowIfNull(incomingMarketMessageStream);
+        var stopwatch = Stopwatch.StartNew();
+
         var incomingMarketMessageParserResult = await ParseIncomingMessageAsync(
                 incomingMarketMessageStream,
                 incomingDocumentFormat,
                 documentType,
                 cancellationToken)
             .ConfigureAwait(false);
+
+        stopwatch.Stop();
+        _logger.LogInformation($"IncomingMessage Parsing execution time: {stopwatch.ElapsedMilliseconds} ms");
+
         if (incomingMarketMessageParserResult.Errors.Count != 0
             || incomingMarketMessageParserResult.IncomingMessage == null)
         {
@@ -99,21 +106,30 @@ public async Task<ResponseMessage> ReceiveIncomingMarketMessageAsync(
 
         if (ShouldArchive(documentType))
         {
+            stopwatch.Restart();
             await ArchiveIncomingMessageAsync(
                     incomingMarketMessageStream,
                     incomingMarketMessageParserResult.IncomingMessage,
                     documentType,
                     cancellationToken)
                 .ConfigureAwait(false);
+            stopwatch.Stop();
+            _logger.LogInformation($"IncomingMessage Archiving execution time: {stopwatch.ElapsedMilliseconds} ms");
         }
 
+        stopwatch.Restart();
         await _delegateIncomingMessage
             .DelegateAsync(incomingMarketMessageParserResult.IncomingMessage, documentType, cancellationToken)
             .ConfigureAwait(false);
+        stopwatch.Stop();
+        _logger.LogInformation($"IncomingMessage Delegation execution time: {stopwatch.ElapsedMilliseconds} ms");
 
+        stopwatch.Restart();
         var validationResult = await _validateIncomingMessage
             .ValidateAsync(incomingMarketMessageParserResult.IncomingMessage, incomingDocumentFormat, cancellationToken)
             .ConfigureAwait(false);
+        stopwatch.Stop();
+        _logger.LogInformation($"IncomingMessage Validation execution time: {stopwatch.ElapsedMilliseconds} ms");
 
         if (!validationResult.Success)
         {
@@ -124,11 +140,14 @@ await _delegateIncomingMessage
             return _responseFactory.From(validationResult, responseDocumentFormat);
         }
 
+        stopwatch.Restart();
         var result = await _incomingMessageReceiver
             .ReceiveAsync(
                 incomingMarketMessageParserResult.IncomingMessage,
                 cancellationToken)
             .ConfigureAwait(false);
+        stopwatch.Stop();
+        _logger.LogInformation($"IncomingMessage Receiving execution time: {stopwatch.ElapsedMilliseconds} ms");
 
         if (result.Success)
         {