Hot Reload for Loggers

src/Cli/ConfigGenerator.cs

@@ -1675,7 +1675,7 @@ public static bool TryStartEngineWithOptions(StartOptions options, FileSystemRun
                 minimumLogLevel = deserializedRuntimeConfig.GetConfiguredLogLevel();
                 HostMode hostModeType = deserializedRuntimeConfig.IsDevelopmentMode() ? HostMode.Development : HostMode.Production;
 
-                _logger.LogInformation("Setting default minimum LogLevel: {minimumLogLevel} for {hostMode} mode.", minimumLogLevel, hostModeType);
+                _logger.LogInformation($"Setting default minimum LogLevel: {minimumLogLevel} for {hostModeType} mode.", minimumLogLevel, hostModeType);
             }
 
             args.Add("--LogLevel");

src/Config/DabConfigEvents.cs

@@ -18,5 +18,5 @@ public static class DabConfigEvents
     public const string GRAPHQL_SCHEMA_REFRESH_ON_CONFIG_CHANGED = "GRAPHQL_SCHEMA_REFRESH_ON_CONFIG_CHANGED";
     public const string GRAPHQL_SCHEMA_EVICTION_ON_CONFIG_CHANGED = "GRAPHQL_SCHEMA_EVICTION_ON_CONFIG_CHANGED";
     public const string GRAPHQL_SCHEMA_CREATOR_ON_CONFIG_CHANGED = "GRAPHQL_SCHEMA_CREATOR_ON_CONFIG_CHANGED";
-
+    public const string LOG_LEVEL_INITIALIZER_ON_CONFIG_CHANGE = "LOG_LEVEL_INITIALIZER_ON_CONFIG_CHANGE";
 }

src/Config/FileSystemRuntimeConfigLoader.cs

@@ -135,7 +135,7 @@ private bool TrySetupConfigFileWatcher()
             return false;
         }
 
-        if (RuntimeConfig is not null && RuntimeConfig.IsDevelopmentMode())
+        if (RuntimeConfig is not null)
         {
             try
             {
@@ -318,6 +318,8 @@ private void HotReloadConfig(bool isDevMode, ILogger? logger = null)
         IsNewConfigDetected = true;
         IsNewConfigValidated = false;
         SignalConfigChanged();
+
+        logger?.LogInformation("Hot-reload process finished.");
     }
 
     /// <summary>

src/Config/HotReloadEventHandler.cs

@@ -33,7 +33,8 @@ public HotReloadEventHandler()
             { AUTHZ_RESOLVER_ON_CONFIG_CHANGED, null },
             { GRAPHQL_SCHEMA_CREATOR_ON_CONFIG_CHANGED, null },
             { GRAPHQL_SCHEMA_REFRESH_ON_CONFIG_CHANGED, null },
-            { GRAPHQL_SCHEMA_EVICTION_ON_CONFIG_CHANGED, null }
+            { GRAPHQL_SCHEMA_EVICTION_ON_CONFIG_CHANGED, null },
+            { LOG_LEVEL_INITIALIZER_ON_CONFIG_CHANGE, null }
         };
     }
 
@@ -49,7 +50,7 @@ public void Subscribe(string eventName, EventHandler<TEventArgs> handler)
     {
         if (_eventHandlers.ContainsKey(eventName))
         {
-            _eventHandlers[eventName] = handler;
+            _eventHandlers[eventName] += handler;
         }
     }
 }

src/Config/RuntimeConfigLoader.cs

@@ -89,22 +89,29 @@ protected void SignalConfigChanged(string message = "")
         // Signal that a change has occurred to all change token listeners.
         RaiseChanged();
 
-        OnConfigChangedEvent(new HotReloadEventArgs(QUERY_MANAGER_FACTORY_ON_CONFIG_CHANGED, message));
-        OnConfigChangedEvent(new HotReloadEventArgs(METADATA_PROVIDER_FACTORY_ON_CONFIG_CHANGED, message));
-        OnConfigChangedEvent(new HotReloadEventArgs(QUERY_ENGINE_FACTORY_ON_CONFIG_CHANGED, message));
-        OnConfigChangedEvent(new HotReloadEventArgs(MUTATION_ENGINE_FACTORY_ON_CONFIG_CHANGED, message));
-        OnConfigChangedEvent(new HotReloadEventArgs(DOCUMENTOR_ON_CONFIG_CHANGED, message));
-
-        // Order of event firing matters: Authorization rules can only be updated after the
-        // MetadataProviderFactory has been updated with latest database object metadata.
-        // RuntimeConfig must already be updated and is implied to have been updated by the time
-        // this function is called.
-        OnConfigChangedEvent(new HotReloadEventArgs(AUTHZ_RESOLVER_ON_CONFIG_CHANGED, message));
-
-        // Order of event firing matters: Eviction must be done before creating a new schema and then updating the schema.
-        OnConfigChangedEvent(new HotReloadEventArgs(GRAPHQL_SCHEMA_EVICTION_ON_CONFIG_CHANGED, message));
-        OnConfigChangedEvent(new HotReloadEventArgs(GRAPHQL_SCHEMA_CREATOR_ON_CONFIG_CHANGED, message));
-        OnConfigChangedEvent(new HotReloadEventArgs(GRAPHQL_SCHEMA_REFRESH_ON_CONFIG_CHANGED, message));
+        // All the data inside of the if statement should only update when DAB is in development mode.
+        if (RuntimeConfig!.IsDevelopmentMode())
+        {
+            OnConfigChangedEvent(new HotReloadEventArgs(QUERY_MANAGER_FACTORY_ON_CONFIG_CHANGED, message));
+            OnConfigChangedEvent(new HotReloadEventArgs(METADATA_PROVIDER_FACTORY_ON_CONFIG_CHANGED, message));
+            OnConfigChangedEvent(new HotReloadEventArgs(QUERY_ENGINE_FACTORY_ON_CONFIG_CHANGED, message));
+            OnConfigChangedEvent(new HotReloadEventArgs(MUTATION_ENGINE_FACTORY_ON_CONFIG_CHANGED, message));
+            OnConfigChangedEvent(new HotReloadEventArgs(DOCUMENTOR_ON_CONFIG_CHANGED, message));
+
+            // Order of event firing matters: Authorization rules can only be updated after the
+            // MetadataProviderFactory has been updated with latest database object metadata.
+            // RuntimeConfig must already be updated and is implied to have been updated by the time
+            // this function is called.
+            OnConfigChangedEvent(new HotReloadEventArgs(AUTHZ_RESOLVER_ON_CONFIG_CHANGED, message));
+
+            // Order of event firing matters: Eviction must be done before creating a new schema and then updating the schema.
+            OnConfigChangedEvent(new HotReloadEventArgs(GRAPHQL_SCHEMA_EVICTION_ON_CONFIG_CHANGED, message));
+            OnConfigChangedEvent(new HotReloadEventArgs(GRAPHQL_SCHEMA_CREATOR_ON_CONFIG_CHANGED, message));
+            OnConfigChangedEvent(new HotReloadEventArgs(GRAPHQL_SCHEMA_REFRESH_ON_CONFIG_CHANGED, message));
+        }
+
+        // Log Level Initializer is outside of if statement as it can be updated on both development and production mode.
+        OnConfigChangedEvent(new HotReloadEventArgs(LOG_LEVEL_INITIALIZER_ON_CONFIG_CHANGE, message));
     }
 
     /// <summary>
@@ -388,4 +395,29 @@ public void RestoreLkgConfig()
     {
         RuntimeConfig = LastValidRuntimeConfig;
     }
+
+    /// <summary>
+    /// Uses the Last Valid Runtime Config and inserts the log-level property to the Runtime Config that will be used
+    /// during the hot-reload if DAB is in Production Mode, this means that only changes to log-level will be registered.
+    /// This is done in order to ensure that no unwanted changes are honored during hot-reload in Production Mode.
+    /// </summary>
+    public void InsertWantedChangesInProductionMode()
+    {
+        if (!RuntimeConfig!.IsDevelopmentMode())
+        {
+            // Creates copy of last valid runtime config and only adds the new logger level changes
+            RuntimeConfig runtimeConfigCopy = LastValidRuntimeConfig! with
+            {
+                Runtime = LastValidRuntimeConfig.Runtime! with
+                {
+                    Telemetry = LastValidRuntimeConfig.Runtime!.Telemetry! with
+                    {
+                        LoggerLevel = RuntimeConfig.Runtime!.Telemetry!.LoggerLevel
+                    }
+                }
+            };
+
+            RuntimeConfig = runtimeConfigCopy;
+        }
+    }
 }

src/Core/Configurations/RuntimeConfigProvider.cs

@@ -314,6 +314,10 @@ public void ValidateConfig()
             ILogger<RuntimeConfigValidator> logger = loggerFactory.CreateLogger<RuntimeConfigValidator>();
             RuntimeConfigValidator runtimeConfigValidator = new(this, fileSystem, logger, true);
 
+            // This function only works if DAB is started in Production Mode
+            _configLoader.InsertWantedChangesInProductionMode();
+
+            // Checks if the new config is valid or invalid
             _configLoader.IsNewConfigValidated = runtimeConfigValidator.TryValidateConfig(ConfigFilePath, loggerFactory).Result;
 
             // Saves the lastValidRuntimeConfig as the new RuntimeConfig if it is validated for hot reload

src/Service.Tests/Configuration/HotReload/ConfigurationHotReloadTests.cs

@@ -13,6 +13,7 @@
 using Azure.DataApiBuilder.Service.Tests.SqlTests;
 using Microsoft.AspNetCore.TestHost;
 using Microsoft.Extensions.DependencyInjection;
+using Microsoft.Extensions.Logging;
 using Microsoft.VisualStudio.TestTools.UnitTesting;
 
 namespace Azure.DataApiBuilder.Service.Tests.Configuration.HotReload;
@@ -49,6 +50,7 @@ private static void GenerateConfigFile(
         string restEnabled = "true",
         string gQLPath = "/graphQL",
         string gQLEnabled = "true",
+        string logFilter = "debug",
         string entityName = "Book",
         string sourceObject = "books",
         string gQLEntityEnabled = "true",
@@ -91,6 +93,11 @@ private static void GenerateConfigFile(
                             ""provider"": ""StaticWebApps""
                           },
                           ""mode"": ""development""
+                        },
+                        ""telemetry"": {
+                          ""log-level"": {
+                            ""default"": """ + logFilter + @"""
+                          }
                         }
                       },
                     ""entities"": {
@@ -542,6 +549,35 @@ public async Task HotReloadConfigDataSource()
         SqlTestHelper.PerformTestEqualJsonStrings(_bookDBOContents, reloadGQLContents.GetProperty("items").ToString());
     }
 
+    /// <summary>
+    /// Hot reload the configuration file so that it updated the log-level property.
+    /// Then we assert that the log-level property is properly updated by ensuring it is 
+    /// not the same as the previous log-level and asserting it is the expected log-level.
+    /// </summary>
+    [TestCategory(MSSQL_ENVIRONMENT)]
+    [TestMethod]
+    public void HotReloadLogLevel()
+    {
+        // Arange
+        LogLevel expectedLogLevel = LogLevel.Trace;
+        string expectedFilter = "trace";
+        RuntimeConfig previousRuntimeConfig = _configProvider.GetConfig();
+        LogLevel previouslogLevel = previousRuntimeConfig.GetConfiguredLogLevel();
+
+        //Act
+        GenerateConfigFile(
+            connectionString: $"{ConfigurationTests.GetConnectionStringFromEnvironmentConfig(TestCategory.MSSQL).Replace("\\", "\\\\")}",
+            logFilter: expectedFilter);
+        System.Threading.Thread.Sleep(3000);
+
+        RuntimeConfig updatedRuntimeConfig = _configProvider.GetConfig();
+        LogLevel actualLogLevel = updatedRuntimeConfig.GetConfiguredLogLevel();
+
+        //Assert
+        Assert.AreNotEqual(previouslogLevel, actualLogLevel);
+        Assert.AreEqual(expectedLogLevel, actualLogLevel);
+    }
+
     /// <summary>
     /// Hot reload the configuration file so that it changes from one connection string
     /// to an invalid connection string, then it hot reloads once more to the original

src/Service/Program.cs

@@ -9,6 +9,7 @@
 using System.Threading.Tasks;
 using Azure.DataApiBuilder.Config;
 using Azure.DataApiBuilder.Service.Exceptions;
+using Azure.DataApiBuilder.Service.Telemetry;
 using Microsoft.ApplicationInsights;
 using Microsoft.AspNetCore;
 using Microsoft.AspNetCore.Hosting;
@@ -133,17 +134,26 @@ private static ParseResult GetParseResult(Command cmd, string[] args)
         /// </summary>
         /// <param name="logLevel">minimum log level.</param>
         /// <param name="appTelemetryClient">Telemetry client</param>
-        public static ILoggerFactory GetLoggerFactoryForLogLevel(LogLevel logLevel, TelemetryClient? appTelemetryClient = null)
+        public static ILoggerFactory GetLoggerFactoryForLogLevel(LogLevel logLevel, TelemetryClient? appTelemetryClient = null, LogLevelInitializer? logLevelInitializer = null)
         {
             return LoggerFactory
                 .Create(builder =>
                 {
                     // Category defines the namespace we will log from,
                     // including all sub-domains. ie: "Azure" includes
                     // "Azure.DataApiBuilder.Service"
-                    builder.AddFilter(category: "Microsoft", logLevel);
-                    builder.AddFilter(category: "Azure", logLevel);
-                    builder.AddFilter(category: "Default", logLevel);
+                    if (logLevelInitializer is null)
+                    {
+                        builder.AddFilter(category: "Microsoft", logLevel);
+                        builder.AddFilter(category: "Azure", logLevel);
+                        builder.AddFilter(category: "Default", logLevel);
+                    }
+                    else
+                    {
+                        builder.AddFilter(category: "Microsoft", level => level >= logLevelInitializer.MinLogLevel);
+                        builder.AddFilter(category: "Azure", level => level >= logLevelInitializer.MinLogLevel);
+                        builder.AddFilter(category: "Default", level => level >= logLevelInitializer.MinLogLevel);
+                    }
 
                     // For Sending all the ILogger logs to Application Insights
                     if (Startup.AppInsightsOptions.Enabled && !string.IsNullOrWhiteSpace(Startup.AppInsightsOptions.ConnectionString))
@@ -157,8 +167,15 @@ public static ILoggerFactory GetLoggerFactoryForLogLevel(LogLevel logLevel, Tele
                                 }
                             },
                             configureApplicationInsightsLoggerOptions: (options) => { }
-                        )
-                        .AddFilter<ApplicationInsightsLoggerProvider>(category: string.Empty, logLevel);
+                        );
+                        if (logLevelInitializer is null)
+                        {
+                            builder.AddFilter<ApplicationInsightsLoggerProvider>(category: string.Empty, logLevel);
+                        }
+                        else
+                        {
+                            builder.AddFilter<ApplicationInsightsLoggerProvider>(category: string.Empty, level => level >= logLevelInitializer.MinLogLevel);
+                        }
                     }
 
                     if (Startup.OpenTelemetryOptions.Enabled && !string.IsNullOrWhiteSpace(Startup.OpenTelemetryOptions.Endpoint))