From ae3e0d011c69933f92e8c477c454f8f32cc907db Mon Sep 17 00:00:00 2001
From: Victor Chang <vicchang@nvidia.com>
Date: Fri, 8 Sep 2023 06:51:22 -0700
Subject: [PATCH] Log duration of export request

Signed-off-by: Victor Chang <vicchang@nvidia.com>
---
 .../Logging/Log.500.ExportService.cs          |  4 +--
 .../Export/ExportRequestEventDetails.cs       | 26 ++++++++++++++++++-
 .../Services/Export/ExportServiceBase.cs      |  5 ++--
 3 files changed, 29 insertions(+), 6 deletions(-)

diff --git a/src/InformaticsGateway/Logging/Log.500.ExportService.cs b/src/InformaticsGateway/Logging/Log.500.ExportService.cs
index 8217940f0..f050aefc6 100644
--- a/src/InformaticsGateway/Logging/Log.500.ExportService.cs
+++ b/src/InformaticsGateway/Logging/Log.500.ExportService.cs
@@ -37,8 +37,8 @@ public static partial class Log
         [LoggerMessage(EventId = 504, Level = LogLevel.Debug, Message = "File {file} ready for export.")]
         public static partial void FileReadyForExport(this ILogger logger, string file);
 
-        [LoggerMessage(EventId = 505, Level = LogLevel.Information, Message = "Export task completed with {failedCount} failures out of {fileCount}.")]
-        public static partial void ExportCompleted(this ILogger logger, int failedCount, int fileCount);
+        [LoggerMessage(EventId = 505, Level = LogLevel.Information, Message = "Export task completed with {failedCount} failures out of {fileCount}. Time to export: {durationMilliseconds}ms.")]
+        public static partial void ExportCompleted(this ILogger logger, int failedCount, int fileCount, int durationMilliseconds);
 
         [LoggerMessage(EventId = 506, Level = LogLevel.Error, Message = "Error downloading payload. Waiting {timeSpan} before next retry. Retry attempt {retryCount}.")]
         public static partial void ErrorDownloadingPayloadWithRetry(this ILogger logger, Exception ex, TimeSpan timeSpan, int retryCount);
diff --git a/src/InformaticsGateway/Services/Export/ExportRequestEventDetails.cs b/src/InformaticsGateway/Services/Export/ExportRequestEventDetails.cs
index 35d83db2a..6b4477f6f 100644
--- a/src/InformaticsGateway/Services/Export/ExportRequestEventDetails.cs
+++ b/src/InformaticsGateway/Services/Export/ExportRequestEventDetails.cs
@@ -37,6 +37,25 @@ public ExportRequestEventDetails(ExportRequestEvent exportRequest)
 
             PluginAssemblies.AddRange(exportRequest.PluginAssemblies);
             ErrorMessages.AddRange(exportRequest.ErrorMessages);
+
+            StartTime = DateTimeOffset.UtcNow;
+        }
+
+        /// <summary>
+        /// Gets the time the export request received.
+        /// </summary>
+        public DateTimeOffset StartTime { get; }
+
+
+        /// <summary>
+        /// Gets time between now and <see cref="StartTime"/>.
+        /// </summary>
+        public TimeSpan Duration
+        {
+            get
+            {
+                return DateTimeOffset.UtcNow.Subtract(StartTime);
+            }
         }
 
         /// <summary>
@@ -53,7 +72,12 @@ public ExportRequestEventDetails(ExportRequestEvent exportRequest)
         /// Gets whether the export task is completed or not based on file count.
         /// </summary>
         public bool IsCompleted
-        { get { return (SucceededFiles + FailedFiles) == Files.Count(); } }
+        {
+            get
+            {
+                return (SucceededFiles + FailedFiles) == Files.Count();
+            }
+        }
 
         public Dictionary<string, FileExportStatus> FileStatuses { get; private set; } = new Dictionary<string, FileExportStatus>();
 
diff --git a/src/InformaticsGateway/Services/Export/ExportServiceBase.cs b/src/InformaticsGateway/Services/Export/ExportServiceBase.cs
index ae51a3650..61507b616 100755
--- a/src/InformaticsGateway/Services/Export/ExportServiceBase.cs
+++ b/src/InformaticsGateway/Services/Export/ExportServiceBase.cs
@@ -283,8 +283,6 @@ private async Task<ExportRequestDataMessage> ExecuteOutputDataEngineCallback(Exp
 
         private void ReportingActionBlock(ExportRequestDataMessage exportRequestData)
         {
-            using var loggerScope = _logger.BeginScope(new Api.LoggingDataDictionary<string, object> { { "ExportTaskId", exportRequestData.ExportTaskId }, { "CorrelationId", exportRequestData.CorrelationId } });
-
             var exportRequest = _exportRequests[exportRequestData.ExportTaskId];
             lock (SyncRoot)
             {
@@ -309,7 +307,8 @@ private void ReportingActionBlock(ExportRequestDataMessage exportRequestData)
                 }
             }
 
-            _logger.ExportCompleted(exportRequest.FailedFiles, exportRequest.Files.Count());
+            using var loggerScope = _logger.BeginScope(new Api.LoggingDataDictionary<string, object> { { "ExportTaskId", exportRequestData.ExportTaskId }, { "CorrelationId", exportRequestData.CorrelationId } });
+            _logger.ExportCompleted(exportRequest.FailedFiles, exportRequest.Files.Count(), exportRequest.Duration.TotalMilliseconds);
 
             var exportCompleteEvent = new ExportCompleteEvent(exportRequest, exportRequest.Status, exportRequest.FileStatuses);