Merged PR 684246: Add an option to save metrics asynchronously for pe…

…rformance reasons

Add an option to save metrics asynchronously for performance reasons.

Here is an azure trace that shows how expensive the tracing is right now.
![image.png](https://dev.azure.com/mseng/9ed2c125-1cd5-4a17-886b-9d267f3a5fab/_apis/git/repositories/50d331c7-ea65-45eb-833f-0303c6c2387e/pullRequests/684246/attachments/image.png)

Public/Src/Cache/ContentStore/Distributed/NuCache/ContentLocationDatabase.cs

@@ -27,6 +27,7 @@
 using BuildXL.Engine.Cache.KeyValueStores;
 using BuildXL.Utilities;
 using BuildXL.Utilities.Collections;
+using BuildXL.Utilities.ParallelAlgorithms;
 using BuildXL.Utilities.Serialization;
 using BuildXL.Utilities.Tasks;
 using BuildXL.Utilities.Tracing;

Public/Src/Cache/ContentStore/Distributed/NuCache/EventStreaming/ContentLocationEventStore.cs

@@ -20,6 +20,7 @@
 using BuildXL.Cache.ContentStore.Utils;
 using BuildXL.Utilities;
 using BuildXL.Utilities.Collections;
+using BuildXL.Utilities.ParallelAlgorithms;
 using BuildXL.Utilities.Tracing;
 using static BuildXL.Cache.ContentStore.Distributed.Tracing.TracingStructuredExtensions;
 using static BuildXL.Cache.ContentStore.Distributed.NuCache.EventStreaming.ContentLocationEventStoreCounters;

Public/Src/Cache/DistributedCache.Host/Configuration/LoggingSettings.cs

@@ -32,6 +32,12 @@ public class LoggingSettings
         [DataMember]
         public string? MdmAccountName { get; set; }
 
+        /// <summary>
+        /// If true, then the metrics saved asynchronously using a queue.
+        /// </summary>
+        [DataMember]
+        public bool SaveMetricsAsynchronously { get; set; }
+
         public LoggingSettings()
         {
         }

Public/Src/Cache/DistributedCache.Host/Service/LoggerFactory.cs

@@ -83,7 +83,7 @@ public static (ILogger Logger, IDisposable? DisposableToken) ReplaceLogger(Logge
                 else if (!string.IsNullOrEmpty(loggingSettings.MdmAccountName))
                 {
                     Tracer.Debug(context, "Creating MetricsLogger with an in-proc MdmOperationLogger.");
-                    operationLogger = MdmOperationLogger.Create(context, loggingSettings.MdmAccountName, GetDefaultDimensions(arguments));
+                    operationLogger = MdmOperationLogger.Create(context, loggingSettings.MdmAccountName, GetDefaultDimensions(arguments), loggingSettings.SaveMetricsAsynchronously);
                     replacementLogger = new MetricsAdapter(nLogAdapter, operationLogger);
                 }
 

Public/Src/Cache/Logging/Library/BuildXL.Cache.Logging.Library.dsc

@@ -10,7 +10,9 @@ namespace Library {
     export const dll = BuildXLSdk.library({
         assemblyName: "BuildXL.Cache.Logging",
         sources: globR(d`.`,"*.cs"),
+        nullable: true,
         references: [
+            BuildXLSdk.asyncInterfacesPackage,
             importFrom("WindowsAzure.Storage").pkg,
             importFrom("NLog").pkg,
             importFrom("BuildXL.Cache.ContentStore").Hashing.dll,

Public/Src/Cache/Logging/Library/External/NLogAdapter.cs

@@ -2,14 +2,15 @@
 // Licensed under the MIT License.
 
 using System;
-using System.Collections.Generic;
 using System.Diagnostics.ContractsLight;
 using System.Threading;
 using System.Threading.Tasks;
 using BuildXL.Cache.ContentStore.Interfaces.Logging;
 using NLog;
 using ILogger = BuildXL.Cache.ContentStore.Interfaces.Logging.ILogger;
 
+#nullable enable
+
 namespace BuildXL.Cache.Logging.External
 {
     /// <summary>
@@ -303,19 +304,19 @@ public void Dispose()
             }
         }
 
-        private void CurrentDomain_ProcessExit(object sender, EventArgs e)
+        private void CurrentDomain_ProcessExit(object? sender, EventArgs e)
         {
             Dispose();
         }
 
-        private void CurrentDomain_DomainUnload(object sender, EventArgs e)
+        private void CurrentDomain_DomainUnload(object? sender, EventArgs e)
         {
             Dispose();
         }
 
-        private void CurrentDomain_UnhandledException(object sender, UnhandledExceptionEventArgs args)
+        private void CurrentDomain_UnhandledException(object? sender, UnhandledExceptionEventArgs args)
         {
-            var exception = args.ExceptionObject as Exception;
+            var exception = (Exception)args.ExceptionObject;
 
             string exitString = args.IsTerminating
                                     ? "Process will exit"
@@ -334,7 +335,7 @@ private void CurrentDomain_UnhandledException(object sender, UnhandledExceptionE
             }
         }
 
-        private void TaskScheduler_UnobservedTaskException(object sender, UnobservedTaskExceptionEventArgs args)
+        private void TaskScheduler_UnobservedTaskException(object? sender, UnobservedTaskExceptionEventArgs args)
         {
             var exception = args.Exception;
             var exceptionObserver = new TaskExceptionObserver();
@@ -367,7 +368,7 @@ private void TaskScheduler_UnobservedTaskException(object sender, UnobservedTask
             }
         }
 
-        private void HandleConfigurationReload(object sender, NLog.Config.LoggingConfigurationReloadedEventArgs e)
+        private void HandleConfigurationReload(object? sender, NLog.Config.LoggingConfigurationReloadedEventArgs e)
         {
             if (e.Succeeded)
             {
@@ -381,7 +382,7 @@ private void HandleConfigurationReload(object sender, NLog.Config.LoggingConfigu
             CurrentSeverity = ComputeCurrentSeverity();
         }
 
-        private void HandleConfigurationChange(object sender, NLog.Config.LoggingConfigurationChangedEventArgs e)
+        private void HandleConfigurationChange(object? sender, NLog.Config.LoggingConfigurationChangedEventArgs e)
         {
             _host.Info("NLog configuration has changed");
 

Public/Src/Cache/Logging/Library/Metrics/FailingLogger.cs

@@ -12,7 +12,7 @@ namespace BuildXL.Cache.Logging
     public abstract class FailingLogger : ILogger
     {
         /// <inheritdoc />
-        public void Dispose()
+        public virtual void Dispose()
         {
             // Throw is the only exception and should not throw.
         }

Public/Src/Cache/Logging/Library/Metrics/MdmOperationLogger.cs

@@ -7,7 +7,6 @@
 using System.Diagnostics.ContractsLight;
 using BuildXL.Cache.ContentStore.Interfaces.Logging;
 using BuildXL.Cache.ContentStore.Interfaces.Tracing;
-using BuildXL.Cache.ContentStore.Tracing.Internal;
 
 #nullable enable
 
@@ -51,7 +50,11 @@ private MdmOperationLogger(Context context, string? monitoringAccount, MetricLog
         /// <remarks>
         /// The mdm metrics are off if <paramref name="monitoringAccount"/> is null or empty.
         /// </remarks>
-        public static MdmOperationLogger Create(Context context, string? monitoringAccount, List<DefaultDimension> defaultDimensions)
+        public static MdmOperationLogger Create(
+            Context context,
+            string? monitoringAccount,
+            List<DefaultDimension> defaultDimensions,
+            bool saveMetricsAsynchronously)
         {
             // Setting the default dimensions once instead of passing them all the time explicitly.
             MetricLogger.InitializeMdmDefaultDimensions(context, defaultDimensions);
@@ -63,30 +66,39 @@ public static MdmOperationLogger Create(Context context, string? monitoringAccou
                 logicalNameSpace: ServiceName,
                 metricName: "OperationDurationMs",
                 addDefaultDimensions: true,
-                dimensions: OperationDurationDimensions);
+                dimensions: OperationDurationDimensions,
+                saveMetricsAsynchronously);
 
             var metricLogger = MetricLogger.CreateLogger(
                 context,
                 monitoringAccount,
                 logicalNameSpace: ServiceName,
                 metricName: "Metric",
                 addDefaultDimensions: true,
-                dimensions: MetricDimensions);
+                dimensions: MetricDimensions,
+                saveMetricsAsynchronously);
 
             return new MdmOperationLogger(context, monitoringAccount, operationFinishedMetricLogger, metricLogger);
         }
 
+        /// <inheritdoc />
+        public override void Dispose()
+        {
+            _metricLogger.Dispose();
+        }
+
         /// <inheritdoc />
         public void OperationFinished(in OperationResult result)
         {
             _operationFinishedMetricLogger.Log(
+                new OperationFinishedMetric(
                 (long)result.Duration.TotalMilliseconds,
                 result.OperationName,
                 result.OperationKind.ToStringNoAlloc(),
                 result.Status == OperationStatus.Success ? "Succeeded" : "Failed",
                 result.Status.ToStringNoAlloc(),
                 result.TracerName,
-                result.Exception?.GetType().ToString() ?? "NA");
+                    result.Exception?.GetType().ToString() ?? "NA"));
         }
 
         /// <inheritdoc />
@@ -113,7 +125,8 @@ MetricLogger getOrCreateMetricLogger(string statisticName)
                         logicalNameSpace: ServiceName,
                         metricName: statisticName,
                         addDefaultDimensions: true,
-                        dimensions: Array.Empty<Dimension>());
+                        dimensions: Array.Empty<Dimension>(),
+                        saveMetricsAsynchronously: false); // we should not have too many stats metrics, so its fine to save them synchronously all the time.
 
                     _statisticLoggers[statisticName] = metricLogger;
                 }

Public/Src/Cache/Logging/Library/Metrics/MetricLogger.cs

@@ -1,17 +1,30 @@
 // Copyright (c) Microsoft Corporation.
 // Licensed under the MIT License.
 
+using System;
 using System.Collections.Generic;
 using BuildXL.Cache.ContentStore.Interfaces.Tracing;
 
 #nullable enable
 
 namespace BuildXL.Cache.Logging
 {
+    /// <summary>
+    /// Represents a metric emitted when an operation is finished.
+    /// </summary>
+    public record struct OperationFinishedMetric(
+        long DurationMs,
+        string OperationName,
+        string OperationKind,
+        string SuccessOrFailure,
+        string Status,
+        string Component,
+        string ExceptionType);
+
     /// <summary>
     /// A base type for logging metrics.
     /// </summary>
-    public abstract class MetricLogger
+    public abstract class MetricLogger : IDisposable
     {
         /// <summary>
         /// Logs metric value with the given dimensions.
@@ -20,11 +33,21 @@ public abstract class MetricLogger
         /// <param name="dimensionValues">Dimension values.</param>
         public abstract void Log(long metricValue, params string?[] dimensionValues);
 
+        /// <summary>
+        /// Logs a metric of a finished operation.
+        /// </summary>
+        public abstract void Log(in OperationFinishedMetric metric);
+
         /// <summary>
         /// Logs metric value with the given dimensions.
         /// </summary>
         public abstract void Log(long metricValue, string dimension1, string dimension2);
 
+        /// <summary>
+        /// Dispose remaining logging resources or flush the logs.
+        /// </summary>
+        public virtual void Dispose() { }
+
         /// <summary>
         /// Geneva / MDM is not tolerant of null or empty dimension values. Replace them with actual strings to prevent errors.
         /// </summary>
@@ -68,10 +91,11 @@ public static MetricLogger CreateLogger(
             string logicalNameSpace,
             string metricName,
             bool addDefaultDimensions,
-            IEnumerable<Dimension> dimensions)
+            IEnumerable<Dimension> dimensions,
+            bool saveMetricsAsynchronously)
         {
 #if MICROSOFT_INTERNAL
-            return WindowsMetricLogger.Create(context, monitoringAccount, logicalNameSpace, metricName, addDefaultDimensions, dimensions);
+            return WindowsMetricLogger.Create(context, monitoringAccount, logicalNameSpace, metricName, addDefaultDimensions, dimensions, saveMetricsAsynchronously);
 #else
             return NoOpMetricLogger.Instance;
 #endif

Public/Src/Cache/Logging/Library/Metrics/NoOpMetricLogger.cs

@@ -18,6 +18,10 @@ internal sealed class NoOpMetricLogger : MetricLogger
         /// <inheritdoc />
         public override void Log(long metricValue, params string?[] dimensionValues) { }
 
+        /// <inheritdoc />
         public override void Log(long metricValue, string dimension1, string dimension2) { }
+
+        /// <inheritdoc />
+        public override void Log(in OperationFinishedMetric metric) { }
     }
 }