Skip to content
55 changes: 37 additions & 18 deletions src/Cli.Tests/EndToEndTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -811,8 +811,9 @@ public Task TestUpdatingStoredProcedureWithRestMethods()

/// <summary>
/// Test to validate that the engine starts successfully when --verbose and --LogLevel
/// options are used with the start command
/// This test does not validate whether the engine logs messages at the specified log level
/// options are used with the start command, for log levels at or below Information.
/// CLI phase messages (version info, config path) are expected in the output because
/// they are logged at Information level.
/// </summary>
/// <param name="logLevelOption">Log level options</param>
[DataTestMethod]
Expand All @@ -821,24 +822,12 @@ public Task TestUpdatingStoredProcedureWithRestMethods()
[DataRow("--LogLevel 0", DisplayName = "LogLevel 0 from command line.")]
[DataRow("--LogLevel 1", DisplayName = "LogLevel 1 from command line.")]
[DataRow("--LogLevel 2", DisplayName = "LogLevel 2 from command line.")]
[DataRow("--LogLevel 3", DisplayName = "LogLevel 3 from command line.")]
[DataRow("--LogLevel 4", DisplayName = "LogLevel 4 from command line.")]
[DataRow("--LogLevel 5", DisplayName = "LogLevel 5 from command line.")]
[DataRow("--LogLevel 6", DisplayName = "LogLevel 6 from command line.")]
[DataRow("--LogLevel Trace", DisplayName = "LogLevel Trace from command line.")]
[DataRow("--LogLevel Debug", DisplayName = "LogLevel Debug from command line.")]
[DataRow("--LogLevel Information", DisplayName = "LogLevel Information from command line.")]
[DataRow("--LogLevel Warning", DisplayName = "LogLevel Warning from command line.")]
[DataRow("--LogLevel Error", DisplayName = "LogLevel Error from command line.")]
[DataRow("--LogLevel Critical", DisplayName = "LogLevel Critical from command line.")]
[DataRow("--LogLevel None", DisplayName = "LogLevel None from command line.")]
[DataRow("--LogLevel tRace", DisplayName = "Case sensitivity: LogLevel Trace from command line.")]
[DataRow("--LogLevel DebUG", DisplayName = "Case sensitivity: LogLevel Debug from command line.")]
[DataRow("--LogLevel information", DisplayName = "Case sensitivity: LogLevel Information from command line.")]
[DataRow("--LogLevel waRNing", DisplayName = "Case sensitivity: LogLevel Warning from command line.")]
[DataRow("--LogLevel eRROR", DisplayName = "Case sensitivity: LogLevel Error from command line.")]
[DataRow("--LogLevel CrItIcal", DisplayName = "Case sensitivity: LogLevel Critical from command line.")]
[DataRow("--LogLevel NONE", DisplayName = "Case sensitivity: LogLevel None from command line.")]
public void TestEngineStartUpWithVerboseAndLogLevelOptions(string logLevelOption)
{
_fileSystem!.File.WriteAllText(TEST_RUNTIME_CONFIG_FILE, INITIAL_CONFIG);
Expand All @@ -857,6 +846,40 @@ public void TestEngineStartUpWithVerboseAndLogLevelOptions(string logLevelOption
StringAssert.Contains(output, $"User provided config file: {TEST_RUNTIME_CONFIG_FILE}", StringComparison.Ordinal);
}

/// <summary>
/// Test to validate that the engine starts successfully when --LogLevel is set to Warning
/// or above. At these levels, CLI phase messages (logged at Information) are suppressed,
/// so no stdout output is expected during the CLI phase.
/// </summary>
/// <param name="logLevelOption">Log level options</param>
[DataTestMethod]
[DataRow("--LogLevel 3", DisplayName = "LogLevel 3 from command line.")]
[DataRow("--LogLevel 4", DisplayName = "LogLevel 4 from command line.")]
[DataRow("--LogLevel 5", DisplayName = "LogLevel 5 from command line.")]
[DataRow("--LogLevel 6", DisplayName = "LogLevel 6 from command line.")]
[DataRow("--LogLevel Warning", DisplayName = "LogLevel Warning from command line.")]
[DataRow("--LogLevel Error", DisplayName = "LogLevel Error from command line.")]
[DataRow("--LogLevel Critical", DisplayName = "LogLevel Critical from command line.")]
[DataRow("--LogLevel None", DisplayName = "LogLevel None from command line.")]
[DataRow("--LogLevel waRNing", DisplayName = "Case sensitivity: LogLevel Warning from command line.")]
[DataRow("--LogLevel eRROR", DisplayName = "Case sensitivity: LogLevel Error from command line.")]
[DataRow("--LogLevel CrItIcal", DisplayName = "Case sensitivity: LogLevel Critical from command line.")]
[DataRow("--LogLevel NONE", DisplayName = "Case sensitivity: LogLevel None from command line.")]
public void TestEngineStartUpWithHighLogLevelOptions(string logLevelOption)
{
_fileSystem!.File.WriteAllText(TEST_RUNTIME_CONFIG_FILE, INITIAL_CONFIG);

using Process process = ExecuteDabCommand(
command: $"start --config {TEST_RUNTIME_CONFIG_FILE}",
logLevelOption
);

// CLI phase messages are at Information level and will be suppressed by Warning+.
// Verify the engine started (process not immediately exited) then clean up.
Assert.IsFalse(process.HasExited);
Comment on lines +878 to +879
Copy link

Copilot AI Mar 12, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This test asserts Assert.IsFalse(process.HasExited) immediately after starting the process, which is race-prone: a failing process can still be running at the exact moment of the check, and a slow-starting process might not have fully initialized yet. Consider adding a small wait/poll window (e.g., wait a short duration and then assert it's still running, or wait for a known readiness signal when available) to make the test deterministic.

Suggested change
// Verify the engine started (process not immediately exited) then clean up.
Assert.IsFalse(process.HasExited);
// Verify the engine did not exit within a short timeout, then clean up.
bool exitedWithinTimeout = process.WaitForExit(1000);
Assert.IsFalse(exitedWithinTimeout);

Copilot uses AI. Check for mistakes.
process.Kill();
}

/// <summary>
/// Validates that valid usage of verbs and associated options produce exit code 0 (CliReturnCode.SUCCESS).
/// Verifies that explicitly implemented verbs (add, update, init, start) and appropriately
Expand Down Expand Up @@ -1088,10 +1111,6 @@ public async Task TestExitOfRuntimeEngineWithInvalidConfig(
output = await process.StandardOutput.ReadLineAsync();
Assert.IsNotNull(output);
StringAssert.Contains(output, $"Setting default minimum LogLevel:", StringComparison.Ordinal);

output = await process.StandardOutput.ReadLineAsync();
Assert.IsNotNull(output);
StringAssert.Contains(output, "Starting the runtime engine...", StringComparison.Ordinal);
}
else
{
Expand Down
1 change: 0 additions & 1 deletion src/Cli/Program.cs
Original file line number Diff line number Diff line change
Expand Up @@ -37,7 +37,6 @@ public static int Main(string[] args)
// Sets up the filesystem used for reading and writing runtime configuration files.
IFileSystem fileSystem = new FileSystem();
FileSystemRuntimeConfigLoader loader = new(fileSystem, handler: null, isCliLoader: true);

return Execute(args, cliLogger, fileSystem, loader);
}

Expand Down
70 changes: 57 additions & 13 deletions src/Config/FileSystemRuntimeConfigLoader.cs
Original file line number Diff line number Diff line change
Expand Up @@ -59,6 +59,13 @@ public class FileSystemRuntimeConfigLoader : RuntimeConfigLoader
/// </summary>
private readonly IFileSystem _fileSystem;

/// <summary>
/// Logger used to log all the events that occur inside of FileSystemRuntimeConfigLoader
/// </summary>
private ILogger<FileSystemRuntimeConfigLoader>? _logger;

private StartupLogBuffer? _logBuffer;

Comment on lines +62 to +68
Copy link

Copilot AI Mar 12, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

StartupLogBuffer is introduced as a dependency here, but there is no implementation for this type in the repo. This will fail compilation unless the buffer class is added (and ideally unit-tested for thread safety since config loading/hot-reload can be concurrent).

Copilot uses AI. Check for mistakes.
public const string CONFIGFILE_NAME = "dab-config";
public const string CONFIG_EXTENSION = ".json";
public const string ENVIRONMENT_PREFIX = "DAB_";
Expand All @@ -82,13 +89,17 @@ public FileSystemRuntimeConfigLoader(
HotReloadEventHandler<HotReloadEventArgs>? handler = null,
string baseConfigFilePath = DEFAULT_CONFIG_FILE_NAME,
string? connectionString = null,
bool isCliLoader = false)
bool isCliLoader = false,
ILogger<FileSystemRuntimeConfigLoader>? logger = null,
StartupLogBuffer? logBuffer = null)
: base(handler, connectionString)
{
_fileSystem = fileSystem;
_baseConfigFilePath = baseConfigFilePath;
ConfigFilePath = GetFinalConfigFilePath();
_isCliLoader = isCliLoader;
_logger = logger;
_logBuffer = logBuffer;
}

/// <summary>
Expand Down Expand Up @@ -196,7 +207,14 @@ public bool TryLoadConfig(
{
if (_fileSystem.File.Exists(path))
{
Console.WriteLine($"Loading config file from {_fileSystem.Path.GetFullPath(path)}.");
if (_logger is null)
{
_logBuffer?.BufferLog(LogLevel.Information, $"Loading config file from {_fileSystem.Path.GetFullPath(path)}.");
}
else
{
_logger?.LogInformation($"Loading config file from {_fileSystem.Path.GetFullPath(path)}.");
}

// Use File.ReadAllText because DAB doesn't need write access to the file
// and ensures the file handle is released immediately after reading.
Expand All @@ -215,7 +233,15 @@ public bool TryLoadConfig(
}
catch (IOException ex)
{
Console.WriteLine($"IO Exception, retrying due to {ex.Message}");
if (_logger is null)
{
_logBuffer?.BufferLog(LogLevel.Warning, $"IO Exception, retrying due to {ex.Message}");
}
else
{
_logger?.LogWarning($"IO Exception, retrying due to {ex.Message}");
}

if (runCount == FileUtilities.RunLimit)
{
throw;
Expand All @@ -238,8 +264,14 @@ public bool TryLoadConfig(
{
if (TrySetupConfigFileWatcher())
{
Console.WriteLine("Monitoring config: {0} for hot-reloading.", ConfigFilePath);
logger?.LogInformation("Monitoring config: {ConfigFilePath} for hot-reloading.", ConfigFilePath);
if (_logger is null)
{
_logBuffer?.BufferLog(LogLevel.Information, $"Monitoring config: {ConfigFilePath} for hot-reloading.");
}
else
{
_logger?.LogInformation($"Monitoring config: {ConfigFilePath} for hot-reloading.");
}
}

// When isDevMode is not null it means we are in a hot-reload scenario, and need to save the previous
Expand All @@ -249,13 +281,13 @@ public bool TryLoadConfig(
// Log error when the mode is changed during hot-reload.
if (isDevMode != this.RuntimeConfig.IsDevelopmentMode())
{
if (logger is null)
if (_logger is null)
{
Console.WriteLine("Hot-reload doesn't support switching mode. Please restart the service to switch the mode.");
_logBuffer?.BufferLog(LogLevel.Error, "Hot-reload doesn't support switching mode. Please restart the service to switch the mode.");
}
else
{
logger.LogError("Hot-reload doesn't support switching mode. Please restart the service to switch the mode.");
_logger?.LogError("Hot-reload doesn't support switching mode. Please restart the service to switch the mode.");
}
}

Expand All @@ -281,15 +313,14 @@ public bool TryLoadConfig(
return false;
}

if (logger is null)
string errorMessage = $"Unable to find config file: {path} does not exist.";
if (_logger is null)
{
string errorMessage = $"Unable to find config file: {path} does not exist.";
Console.Error.WriteLine(errorMessage);
_logBuffer?.BufferLog(LogLevel.Error, errorMessage);
}
else
{
string errorMessage = "Unable to find config file: {path} does not exist.";
logger.LogError(message: errorMessage, path);
_logger?.LogError(message: errorMessage);
}
Comment on lines +316 to 324
Copy link

Copilot AI Mar 12, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

When the config file is missing, this now only buffers/logs the error and no longer writes to Console.Error. If _logger is null and no buffer is provided (e.g. CLI loader construction currently passes neither), the user may get no error output at all. Consider falling back to Console.Error.WriteLine(...) when both _logger and _logBuffer are null, so failures are always visible.

Copilot uses AI. Check for mistakes.

config = null;
Expand Down Expand Up @@ -516,4 +547,17 @@ public void UpdateConfigFilePath(string filePath)
_baseConfigFilePath = filePath;
ConfigFilePath = filePath;
}

public void SetLogger(ILogger<FileSystemRuntimeConfigLoader> logger)
{
_logger = logger;
}

/// <summary>
/// Flush all logs from the buffer after the log level is set from the RuntimeConfig.
/// </summary>
public void FlushLogBuffer()
{
_logBuffer?.FlushToLogger(_logger);
}
}
4 changes: 2 additions & 2 deletions src/Config/ObjectModel/RuntimeConfig.cs
Original file line number Diff line number Diff line change
Expand Up @@ -767,7 +767,6 @@ Runtime.Telemetry.LoggerLevel is null ||
/// </summary>
public LogLevel GetConfiguredLogLevel(string loggerFilter = "")
{

if (!IsLogLevelNull())
{
int max = 0;
Expand All @@ -788,7 +787,8 @@ public LogLevel GetConfiguredLogLevel(string loggerFilter = "")
return (LogLevel)value;
}

Runtime!.Telemetry!.LoggerLevel!.TryGetValue("default", out value);
value = Runtime!.Telemetry!.LoggerLevel!
.FirstOrDefault(kvp => kvp.Key.Equals("default", StringComparison.OrdinalIgnoreCase)).Value;
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Consider SingleOrDefault() for the strange but possible scenario where Default and default are both in the configuration. Single ensures there is only one, while OrDefault allows it to be missing.

if (value is not null)
{
return (LogLevel)value;
Expand Down
45 changes: 45 additions & 0 deletions src/Config/StartupLogBuffer.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,45 @@
// Copyright (c) Microsoft Corporation.
// Licensed under the MIT License.

using System.Collections.Concurrent;
using Microsoft.Extensions.Logging;

namespace Azure.DataApiBuilder.Config
{
/// <summary>
/// A general-purpose log buffer that stores log entries before the final log level is determined.
/// Can be used across different components during startup to capture important early logs.
/// </summary>
public class StartupLogBuffer
{
private readonly ConcurrentQueue<(LogLevel LogLevel, string Message)> _logBuffer;
private readonly object _flushLock = new();

public StartupLogBuffer()
{
_logBuffer = new();
}

/// <summary>
/// Buffers a log entry with a specific category name.
/// </summary>
public void BufferLog(LogLevel logLevel, string message)
{
_logBuffer.Enqueue((logLevel, message));
}

/// <summary>
/// Flushes all buffered logs to a single target logger.
/// </summary>
public void FlushToLogger(ILogger? targetLogger)
{
lock (_flushLock)
{
while (_logBuffer.TryDequeue(out (LogLevel LogLevel, string Message) entry))
{
targetLogger?.Log(entry.LogLevel, message: entry.Message);
}
}
}
}
}
2 changes: 1 addition & 1 deletion src/Core/Configurations/RuntimeConfigValidator.cs
Original file line number Diff line number Diff line change
Expand Up @@ -1585,7 +1585,7 @@ private static bool IsLoggerFilterValid(string loggerFilter)
{
for (int j = 0; j < loggerSub.Length; j++)
{
if (!loggerSub[j].Equals(validFiltersSub[j]))
if (!loggerSub[j].Equals(validFiltersSub[j], StringComparison.OrdinalIgnoreCase))
{
isValid = false;
break;
Expand Down
1 change: 1 addition & 0 deletions src/Service.Tests/Configuration/ConfigurationTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -4138,6 +4138,7 @@ public void ValidLogLevelFilters(LogLevel logLevel, Type loggingType)
[DataTestMethod]
[TestCategory(TestCategory.MSSQL)]
[DataRow(LogLevel.Trace, "default")]
[DataRow(LogLevel.Warning, "Default")]
[DataRow(LogLevel.Debug, "Azure")]
[DataRow(LogLevel.Information, "Azure.DataApiBuilder")]
[DataRow(LogLevel.Warning, "Azure.DataApiBuilder.Core")]
Expand Down
18 changes: 14 additions & 4 deletions src/Service/Program.cs
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@ namespace Azure.DataApiBuilder.Service
public class Program
{
public static bool IsHttpsRedirectionDisabled { get; private set; }
public static DynamicLogLevelProvider LogLevelProvider = new();

Comment on lines 35 to 37
Copy link

Copilot AI Mar 12, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

DynamicLogLevelProvider is referenced/instantiated here, but the type does not exist in the repo (no matches found). As-is, this change will fail compilation; the PR likely needs to include the new provider implementation (or remove the reference).

Copilot uses AI. Check for mistakes.
public static void Main(string[] args)
{
Expand All @@ -59,7 +60,6 @@ public static void Main(string[] args)

public static bool StartEngine(string[] args, bool runMcpStdio, string? mcpRole)
{
Console.WriteLine("Starting the runtime engine...");
try
{
IHost host = CreateHostBuilder(args, runMcpStdio, mcpRole).Build();
Expand Down Expand Up @@ -107,9 +107,19 @@ public static IHostBuilder CreateHostBuilder(string[] args, bool runMcpStdio, st
McpStdioHelper.ConfigureMcpStdio(builder, mcpRole);
}
})
.ConfigureServices((context, services) =>
{
services.AddSingleton(LogLevelProvider);
})
.ConfigureLogging(logging =>
{
logging.AddFilter("Microsoft", logLevel => LogLevelProvider.ShouldLog(logLevel));
logging.AddFilter("Microsoft.Hosting.Lifetime", logLevel => LogLevelProvider.ShouldLog(logLevel));
})
.ConfigureWebHostDefaults(webBuilder =>
{
Startup.MinimumLogLevel = GetLogLevelFromCommandLineArgs(args, out Startup.IsLogLevelOverriddenByCli);
LogLevelProvider.SetInitialLogLevel(Startup.MinimumLogLevel, Startup.IsLogLevelOverriddenByCli);
ILoggerFactory loggerFactory = GetLoggerFactoryForLogLevel(Startup.MinimumLogLevel, stdio: runMcpStdio);
ILogger<Startup> startupLogger = loggerFactory.CreateLogger<Startup>();
DisableHttpsRedirectionIfNeeded(args);
Expand Down Expand Up @@ -185,9 +195,9 @@ public static ILoggerFactory GetLoggerFactoryForLogLevel(
// "Azure.DataApiBuilder.Service"
if (logLevelInitializer is null)
{
builder.AddFilter(category: "Microsoft", logLevel);
builder.AddFilter(category: "Azure", logLevel);
builder.AddFilter(category: "Default", logLevel);
builder.AddFilter(category: "Microsoft", logLevel => LogLevelProvider.ShouldLog(logLevel));
builder.AddFilter(category: "Azure", logLevel => LogLevelProvider.ShouldLog(logLevel));
builder.AddFilter(category: "Default", logLevel => LogLevelProvider.ShouldLog(logLevel));
}
else
{
Expand Down
Loading
Loading