Log duration of export request

Signed-off-by: Victor Chang <[email protected]>

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);

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>();
 

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);