Merged PR 693228: Forward rocksdb logs to Kusto

This is a manual rollback of [this rollback](https://dev.azure.com/mseng/Domino/_git/BuildXL.Internal/pullrequest/689216).
microsoft · Dec 14, 2022 · e1e04f9 · e1e04f9
1 parent 7bc194b
commit e1e04f9
Show file tree

Hide file tree

Showing 8 changed files with 133 additions and 26 deletions.
diff --git a/Public/Src/Cache/ContentStore/Distributed/MetadataService/RocksDbContentMetadataDatabase.cs b/Public/Src/Cache/ContentStore/Distributed/MetadataService/RocksDbContentMetadataDatabase.cs
@@ -4,9 +4,6 @@
 using System;
 using System.Collections.Generic;
 using System.Diagnostics.CodeAnalysis;
-using System.Diagnostics.ContractsLight;
-using System.Diagnostics.SymbolStore;
-using System.Globalization;
 using System.IO;
 using System.Linq;
 using System.Runtime.CompilerServices;
@@ -17,7 +14,6 @@
 using BuildXL.Cache.ContentStore.Distributed.NuCache;
 using BuildXL.Cache.ContentStore.FileSystem;
 using BuildXL.Cache.ContentStore.Hashing;
-using BuildXL.Cache.ContentStore.Interfaces.Extensions;
 using BuildXL.Cache.ContentStore.Interfaces.FileSystem;
 using BuildXL.Cache.ContentStore.Interfaces.Results;
 using BuildXL.Cache.ContentStore.Interfaces.Synchronization;
@@ -32,18 +28,16 @@
 using BuildXL.Native.IO;
 using BuildXL.Utilities;
 using BuildXL.Utilities.Collections;
-using BuildXL.Utilities.Serialization;
 using BuildXL.Utilities.Tasks;
 using RocksDbSharp;
+using static BuildXL.Cache.ContentStore.Distributed.MetadataService.RocksDbOperations;
 using static BuildXL.Engine.Cache.KeyValueStores.RocksDbStore;
 using AbsolutePath = BuildXL.Cache.ContentStore.Interfaces.FileSystem.AbsolutePath;
 
 #nullable enable
 
 namespace BuildXL.Cache.ContentStore.Distributed.MetadataService
 {
-    using static RocksDbOperations;
-
     public class RocksDbContentMetadataDatabaseConfiguration : RocksDbContentLocationDatabaseConfiguration
     {
         public RocksDbContentMetadataDatabaseConfiguration(AbsolutePath storeLocation)
@@ -60,7 +54,7 @@ public RocksDbContentMetadataDatabaseConfiguration(AbsolutePath storeLocation)
     }
 
     /// <summary>
-    /// RocksDb-based version of <see cref="ContentLocationDatabase"/>.
+    /// RocksDb-based version of <see cref="ContentLocationDatabase"/> used by the global location store.
     /// </summary>
     public class RocksDbContentMetadataDatabase : ContentLocationDatabase
     {
@@ -289,23 +283,27 @@ private BoolResult Load(OperationContext context, StoreSlot activeSlot, bool cle
                 var dbAlreadyExists = Directory.Exists(storeLocation);
                 Directory.CreateDirectory(storeLocation);
 
-                Tracer.Info(context, $"Creating RocksDb store at '{storeLocation}'. Clean={clean}, Configured Epoch='{_configuration.Epoch}'");
+                var settings = new RocksDbStoreConfiguration(storeLocation)
+                               {
+                                   AdditionalColumns = ColumnNames.SelectMany(n => n),
+                                   RotateLogsMaxFileSizeBytes = 0L,
+                                   RotateLogsNumFiles = 60,
+                                   RotateLogsMaxAge = TimeSpan.FromHours(12),
+                                   EnableStatistics = true,
+                                   FastOpen = true,
+                                   LeveledCompactionDynamicLevelTargetSizes = true,
+                                   Compression = Compression.Zstd,
+                                   UseReadOptionsWithSetTotalOrderSeekInDbEnumeration = true,
+                                   UseReadOptionsWithSetTotalOrderSeekInGarbageCollection = true,
+                                   MergeOperators = GetMergeOperators()
+                               };
+
+                RocksDbUtilities.ConfigureRocksDbTracingIfNeeded(context, _configuration, settings, Tracer, componentName: nameof(RocksDbContentMetadataDatabase));
+
+                Tracer.Info(context, $"Creating RocksDb store at '{storeLocation}'. Clean={clean}, Configured Epoch='{_configuration.Epoch}', TracingLevel={_configuration.RocksDbTracingLevel}");
 
                 var possibleStore = KeyValueStoreAccessor.Open(
-                    new RocksDbStoreConfiguration(storeLocation)
-                    {
-                        AdditionalColumns = ColumnNames.SelectMany(n => n),
-                        RotateLogsMaxFileSizeBytes = 0L,
-                        RotateLogsNumFiles = 60,
-                        RotateLogsMaxAge = TimeSpan.FromHours(12),
-                        EnableStatistics = true,
-                        FastOpen = true,
-                        LeveledCompactionDynamicLevelTargetSizes = true,
-                        Compression = Compression.Zstd,
-                        UseReadOptionsWithSetTotalOrderSeekInDbEnumeration = true,
-                        UseReadOptionsWithSetTotalOrderSeekInGarbageCollection = true,
-                        MergeOperators = GetMergeOperators()
-                    },
+                    settings,
                     // When an exception is caught from within methods using the database, this handler is called to
                     // decide whether the exception should be rethrown in user code, and the database invalidated. Our
                     // policy is to only invalidate if it is an exception coming from RocksDb, but not from our code.

diff --git a/Public/Src/Cache/ContentStore/Distributed/NuCache/ContentLocationDatabaseConfiguration.cs b/Public/Src/Cache/ContentStore/Distributed/NuCache/ContentLocationDatabaseConfiguration.cs
@@ -5,6 +5,7 @@
 using BuildXL.Cache.ContentStore.Distributed.NuCache.InMemory;
 using BuildXL.Cache.ContentStore.Interfaces.FileSystem;
 using BuildXL.Cache.Host.Configuration;
+using RocksDbSharp;
 using static BuildXL.Utilities.ConfigurationHelper;
 
 #nullable enable
@@ -60,6 +61,12 @@ public abstract class ContentLocationDatabaseConfiguration
         /// </summary>
         public bool TraceOperations { get; set; } = true;
 
+        /// <summary>
+        /// Ges or sets log level from RocksDb emitted to Kusto.
+        /// Null - the tracing is off.
+        /// </summary>
+        public LogLevel? RocksDbTracingLevel { get; set; }
+
         /// <summary>
         /// Specifies whether to trace touches or not.
         /// Tracing touches is expensive in terms of the amount of traffic to Kusto and in terms of memory traffic.
@@ -221,6 +228,7 @@ public static RocksDbContentLocationDatabaseConfiguration FromDistributedContent
 
             configuration.RocksDbPerformanceSettings = settings.RocksDbPerformanceSettings;
 
+            ApplyIfNotNull(settings.ContentLocationDatabaseRocksDbTracingLevel, v => configuration.RocksDbTracingLevel = (LogLevel)v);
             ApplyIfNotNull(settings.TraceStateChangeDatabaseOperations, v => configuration.TraceOperations = v);
             ApplyIfNotNull(settings.TraceNoStateChangeDatabaseOperations, v => configuration.TraceNoStateChangeOperations = v);
 
@@ -229,7 +237,7 @@ public static RocksDbContentLocationDatabaseConfiguration FromDistributedContent
             ApplyIfNotNull(settings.ContentLocationDatabaseMetadataGarbageCollectionMaximumSizeMb, v => configuration.MetadataGarbageCollectionMaximumSizeMb = v);
             ApplyIfNotNull(settings.ContentLocationDatabaseMetadataGarbageCollectionLogEnabled, v => configuration.MetadataGarbageCollectionLogEnabled = v);
 
-            ApplyIfNotNull(settings.ContentLocationDatabaseOpenReadOnly, v => configuration.OpenReadOnly = v && !settings.IsMasterEligible);
+            ApplyIfNotNull(settings.ContentLocationDatabaseOpenReadOnly, v => configuration.OpenReadOnly = (v && !settings.IsMasterEligible));
             ApplyIfNotNull(settings.UseMergeOperatorForContentLocations, v => configuration.UseMergeOperatorForContentLocations = v);
             ApplyIfNotNull(settings.SortMergeableContentLocations, v => configuration.SortMergeableContentLocations = v);
 

diff --git a/Public/Src/Cache/ContentStore/Distributed/NuCache/RocksDbContentLocationDatabase.cs b/Public/Src/Cache/ContentStore/Distributed/NuCache/RocksDbContentLocationDatabase.cs
@@ -9,6 +9,8 @@
 using System.Linq;
 using System.Threading;
 using System.Threading.Tasks;
+using BuildXL.Cache.ContentStore.Distributed.MetadataService;
+using BuildXL.Cache.ContentStore.FileSystem;
 using BuildXL.Cache.ContentStore.Hashing;
 using BuildXL.Cache.ContentStore.Interfaces.Results;
 using BuildXL.Cache.ContentStore.Interfaces.Synchronization;
@@ -210,7 +212,7 @@ private BoolResult Load(OperationContext context, StoreSlot activeSlot, bool cle
                 bool dbAlreadyExists = Directory.Exists(storeLocation);
                 Directory.CreateDirectory(storeLocation);
 
-                Tracer.Info(context, $"Creating RocksDb store at '{storeLocation}'. Clean={clean}, UseMergeOperators={_configuration.UseMergeOperatorForContentLocations}, Configured Epoch='{_configuration.Epoch}'");
+                Tracer.Info(context, $"Creating RocksDb store at '{storeLocation}'. Clean={clean}, UseMergeOperators={_configuration.UseMergeOperatorForContentLocations}, Configured Epoch='{_configuration.Epoch}', TracingLevel={_configuration.RocksDbTracingLevel}");
 
                 var settings = new RocksDbStoreConfiguration(storeLocation)
                 {
@@ -240,6 +242,8 @@ private BoolResult Load(OperationContext context, StoreSlot activeSlot, bool cle
                     UseReadOptionsWithSetTotalOrderSeekInGarbageCollection = _configuration.UseReadOptionsWithSetTotalOrderSeekInGarbageCollection,
                 };
 
+                RocksDbUtilities.ConfigureRocksDbTracingIfNeeded(context, _configuration, settings, Tracer, componentName: nameof(RocksDbContentLocationDatabase));
+
                 if (_configuration.UseMergeOperatorForContentLocations)
                 {
                     var mergeContext = context.CreateNested(nameof(RocksDbContentLocationDatabase), caller: "MergeContentLocationEntries");

diff --git a/Public/Src/Cache/ContentStore/Distributed/RocksDbUtilities.cs b/Public/Src/Cache/ContentStore/Distributed/RocksDbUtilities.cs
@@ -0,0 +1,55 @@
+// Copyright (c) Microsoft Corporation.
+// Licensed under the MIT License.
+
+using System;
+using BuildXL.Cache.ContentStore.Distributed.NuCache;
+using BuildXL.Cache.ContentStore.Tracing;
+using BuildXL.Cache.ContentStore.Tracing.Internal;
+using BuildXL.Engine.Cache.KeyValueStores;
+using RocksDbSharp;
+
+namespace BuildXL.Cache.ContentStore.Distributed.MetadataService
+{
+    internal static class RocksDbUtilities
+    {
+        public static void ConfigureRocksDbTracingIfNeeded(
+            OperationContext context,
+            RocksDbContentLocationDatabaseConfiguration configuration,
+            RocksDbStoreConfiguration settings,
+            Tracer tracer,
+            string componentName)
+        {
+            if (!configuration.OpenReadOnly && configuration.RocksDbTracingLevel is { } tracingLevel)
+            {
+                // Tracing operations only for non-readonly database.
+                // We don't know if the current instance will be on a master machine, but the configuration is happening
+                // before such decision is made.
+                var traceLineHandler = CreateLogLineCallback(context, tracer, componentName: componentName);
+                settings.LogLevel = tracingLevel;
+                settings.HandleLogMessage = traceLineHandler;
+            }
+        }
+
+        public static LogLineCallback CreateLogLineCallback(OperationContext context, Tracer tracer, string componentName)
+        {
+            const string operation = "RocksDbTrace";
+            var rocksDbContext = context.CreateNested(componentName, caller: operation).TracingContext;
+            return (logLevel, message) =>
+                                        {
+                                            Action<string> targetMethod = logLevel switch
+                                            {
+                                                LogLevel.Debug => (string msg) => tracer.Debug(rocksDbContext, msg, operation: operation),
+                                                LogLevel.Info => (string msg) => tracer.Info(rocksDbContext, msg, operation: operation),
+                                                LogLevel.Warn => (string msg) => tracer.Warning(rocksDbContext, msg, operation: operation),
+                                                LogLevel.Error => (string msg) => tracer.Error(rocksDbContext, msg, operation: operation),
+                                                LogLevel.Fatal => (string msg) => tracer.Error(rocksDbContext, msg, operation: operation),
+                                                LogLevel.Header => (string msg) => tracer.Info(rocksDbContext, msg, operation: operation),
+                                                // Do nothing in case of an error
+                                                _ => (string msg) => { }
+                                            };
+
+                                            targetMethod(message);
+                                        };
+        }
+    }
+}
diff --git a/Public/Src/Cache/ContentStore/Distributed/Services/DistributedContentStoreServices.cs b/Public/Src/Cache/ContentStore/Distributed/Services/DistributedContentStoreServices.cs
@@ -218,6 +218,7 @@ private RocksDbContentMetadataStore CreateRocksDbContentMetadataStore()
                 MetadataSizeRotationThreshold = DistributedContentSettings.GlobalCacheMetadataSizeRotationThreshold,
             };
 
+            ApplyIfNotNull(DistributedContentSettings.ContentMetadataDatabaseRocksDbTracingLevel, v => dbConfig.RocksDbTracingLevel = (RocksDbSharp.LogLevel)v);
             ApplyIfNotNull(DistributedContentSettings.LocationEntryExpiryMinutes, v => dbConfig.ContentRotationInterval = TimeSpan.FromMinutes(v));
             dbConfig.MetadataRotationInterval = DistributedContentSettings.ContentMetadataServerMetadataRotationInterval;
 

diff --git a/Public/Src/Cache/DistributedCache.Host/Configuration/DistributedContentSettings.cs b/Public/Src/Cache/DistributedCache.Host/Configuration/DistributedContentSettings.cs
@@ -220,6 +220,21 @@ public void DisableRedis()
         [DataMember]
         public bool? TraceStateChangeDatabaseOperations { get; set; }
 
+        /// <summary>
+        /// Defines a tracing level used by RocksDb logging adapter.
+        /// </summary>
+        /// <remarks>
+        /// See RocksDbSharp.LogLevel. The levels are:
+        /// 0 - Debug,
+        /// 1 - Info,
+        /// 2 - Warn,
+        /// 3 - Error,
+        /// 4 - Fatal,
+        /// 5 - Header
+        /// </remarks>
+        [DataMember]
+        public int? ContentLocationDatabaseRocksDbTracingLevel { get; set; } = 1;
+
         [DataMember]
         public bool TraceTouches { get; set; } = true;
 
@@ -961,6 +976,10 @@ public void DisableRedis()
         [DataMember]
         public bool ContentMetadataUseMergeWrites { get; set; }
 
+        /// <inheritdoc cref="ContentLocationDatabaseRocksDbTracingLevel"/>
+        [DataMember]
+        public int? ContentMetadataDatabaseRocksDbTracingLevel { get; set; }
+
         [DataMember]
         public string ContentMetadataBlobSecretName { get; set; }
 

diff --git a/Public/Src/Utilities/KeyValueStore/RocksDb/RocksDbStore.cs b/Public/Src/Utilities/KeyValueStore/RocksDb/RocksDbStore.cs
@@ -113,6 +113,8 @@ private record struct ColumnFamilyInfo
 
         private readonly RocksDbStoreConfiguration? m_options;
 
+        private readonly RocksDbLoggingAdapter? m_loggingAdapter;
+
         /// <summary>
         /// Encapsulates <see cref="RocksDb"/> options that should be set.
         /// </summary>
@@ -154,6 +156,12 @@ public RocksDbStore(RocksDbStoreConfiguration configuration)
                 // }
                 .IncreaseParallelism(performanceConfiguration.GetBackgroundCompactionActualThreadCount());
 
+            if (configuration.HandleLogMessage != null)
+            {
+                m_loggingAdapter = new RocksDbLoggingAdapter(configuration.HandleLogMessage);
+                m_defaults.DbOptions = m_defaults.DbOptions.SetInfoLog(m_loggingAdapter);
+            }
+
             if (performanceConfiguration.DbWriteBufferSize is { } dbWriteBufferSize)
             {
                 m_defaults.DbOptions.SetDbWriteBufferSize(dbWriteBufferSize);
@@ -236,6 +244,11 @@ public RocksDbStore(RocksDbStoreConfiguration configuration)
                     .SetPrefixExtractor(SliceTransform.CreateNoOp())
                     .SetLevelCompactionDynamicLevelBytes(configuration.LeveledCompactionDynamicLevelTargetSizes);
 
+                if (configuration.HandleLogMessage != null)
+                {
+                    options = options.SetInfoLogLevel((int)configuration.LogLevel);
+                }
+
                 ColumnFamilyPerformanceConfiguration? perfConfiguration = null;
                 if (name != null)
                 {
@@ -952,7 +965,9 @@ public void Dispose()
                     }
                 }
 
+                // Disabling the log to avoid execution engine exceptions by calling deleted delegates
                 m_store.Dispose();
+                m_loggingAdapter?.Dispose();
             }
             else
             {

diff --git a/Public/Src/Utilities/KeyValueStore/RocksDb/RocksDbStoreConfiguration.cs b/Public/Src/Utilities/KeyValueStore/RocksDb/RocksDbStoreConfiguration.cs
@@ -4,7 +4,6 @@
 using System;
 using System.Collections.Generic;
 using System.Text;
-using BuildXL.Utilities.Collections;
 using RocksDbSharp;
 
 namespace BuildXL.Engine.Cache.KeyValueStores
@@ -161,6 +160,14 @@ public record RocksDbStoreConfiguration(string StoreDirectory)
         /// </remarks>
         public bool UseReadOptionsWithSetTotalOrderSeekInGarbageCollection { get; init; } = true;
 
+        /// <summary>
+        /// Log handler that will be called once rocksdb traces a message.
+        /// </summary>
+        public LogLineCallback? HandleLogMessage { get; set; }
+
+        /// <nodoc />
+        public LogLevel LogLevel { get; set; } = LogLevel.Info;
+
         /// <nodoc />
         public RocksDbPerformanceConfiguration PerformanceConfiguration { get; set; } = new RocksDbPerformanceConfiguration();
     }