Hot Reload for Loggers (#2634)

## Why make this change?
Closes issues #2580 and #2582

## What is this change?
Adds hot reload feature for loggers which makes it possible for the user
to change the log level filters without restarting the application. This
is done by ensuring that the logger factories are updated when there is
a hot reload event.
This feature is also available in production mode, it is the only hot
reloadable property in production mode.

## How was this tested?
- [ ] Integration Tests
- [x] Unit Tests
- [X] Manual Testing

Test added:
- Check if log-level value is properly updated with hot reload, by
checking if it is different from previous value and if it is the
expected value.

## Sample Request(s)
Before hot reload:

![image](https://github.com/user-attachments/assets/70f3c3e7-936c-44df-85ba-a6c1f9b08dd7)

![image](https://github.com/user-attachments/assets/daffabb4-f542-4bdc-8d1b-56a3aa7961c8)

After hot reload:

![image](https://github.com/user-attachments/assets/8bc14fce-ef8a-4b4e-99b0-16f81bb0e04e)

![image](https://github.com/user-attachments/assets/f6ba26ea-720c-40de-983b-f33db969d349)

---------

Co-authored-by: Ruben Cerna <[email protected]>

Author: RubenCerna2079

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