Skip to content

Commit 14cb7b1

Browse files
RubenCerna2079CopilotAniruddh25anushakolanJerryNixon
authored
Cherry-Pick LogLevel & Health Checks Bug Fix (#3249)
## Why make this change? This change ports the fix for the log-level bugs and the fix for the health checks bug ## What is this change? Cherry-picked changes: - #3203 - #2997 ## How was this tested? These changes were already tested in the original PR - [ ] Integration Tests - [ ] Unit Tests --------- Co-authored-by: Copilot <[email protected]> Co-authored-by: Aniruddh Munde <[email protected]> Co-authored-by: Anusha Kolan <[email protected]> Co-authored-by: Aniruddh25 <[email protected]> Co-authored-by: JerryNixon <[email protected]>
1 parent 76b4d4f commit 14cb7b1

11 files changed

Lines changed: 255 additions & 37 deletions

File tree

‎src/Cli.Tests/EndToEndTests.cs‎

Lines changed: 0 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1087,10 +1087,6 @@ public async Task TestExitOfRuntimeEngineWithInvalidConfig(
10871087
output = await process.StandardOutput.ReadLineAsync();
10881088
Assert.IsNotNull(output);
10891089
StringAssert.Contains(output, $"Setting default minimum LogLevel:", StringComparison.Ordinal);
1090-
1091-
output = await process.StandardOutput.ReadLineAsync();
1092-
Assert.IsNotNull(output);
1093-
StringAssert.Contains(output, "Starting the runtime engine...", StringComparison.Ordinal);
10941090
}
10951091
else
10961092
{

‎src/Config/FileSystemRuntimeConfigLoader.cs‎

Lines changed: 50 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -58,6 +58,13 @@ public class FileSystemRuntimeConfigLoader : RuntimeConfigLoader
5858
/// </summary>
5959
private readonly IFileSystem _fileSystem;
6060

61+
/// <summary>
62+
/// Logger used to log all the events that occur inside of FileSystemRuntimeConfigLoader
63+
/// </summary>
64+
private ILogger<FileSystemRuntimeConfigLoader>? _logger;
65+
66+
private StartupLogBuffer? _logBuffer;
67+
6168
public const string CONFIGFILE_NAME = "dab-config";
6269
public const string CONFIG_EXTENSION = ".json";
6370
public const string ENVIRONMENT_PREFIX = "DAB_";
@@ -81,13 +88,17 @@ public FileSystemRuntimeConfigLoader(
8188
HotReloadEventHandler<HotReloadEventArgs>? handler = null,
8289
string baseConfigFilePath = DEFAULT_CONFIG_FILE_NAME,
8390
string? connectionString = null,
84-
bool isCliLoader = false)
91+
bool isCliLoader = false,
92+
ILogger<FileSystemRuntimeConfigLoader>? logger = null,
93+
StartupLogBuffer? logBuffer = null)
8594
: base(handler, connectionString)
8695
{
8796
_fileSystem = fileSystem;
8897
_baseConfigFilePath = baseConfigFilePath;
8998
ConfigFilePath = GetFinalConfigFilePath();
9099
_isCliLoader = isCliLoader;
100+
_logger = logger;
101+
_logBuffer = logBuffer;
91102
}
92103

93104
/// <summary>
@@ -195,7 +206,7 @@ public bool TryLoadConfig(
195206
{
196207
if (_fileSystem.File.Exists(path))
197208
{
198-
Console.WriteLine($"Loading config file from {_fileSystem.Path.GetFullPath(path)}.");
209+
SendLogToBufferOrLogger(LogLevel.Information, $"Loading config file from {_fileSystem.Path.GetFullPath(path)}.");
199210

200211
// Use File.ReadAllText because DAB doesn't need write access to the file
201212
// and ensures the file handle is released immediately after reading.
@@ -214,7 +225,8 @@ public bool TryLoadConfig(
214225
}
215226
catch (IOException ex)
216227
{
217-
Console.WriteLine($"IO Exception, retrying due to {ex.Message}");
228+
SendLogToBufferOrLogger(LogLevel.Warning, $"IO Exception, retrying due to {ex.Message}");
229+
218230
if (runCount == FileUtilities.RunLimit)
219231
{
220232
throw;
@@ -237,8 +249,7 @@ public bool TryLoadConfig(
237249
{
238250
if (TrySetupConfigFileWatcher())
239251
{
240-
Console.WriteLine("Monitoring config: {0} for hot-reloading.", ConfigFilePath);
241-
logger?.LogInformation("Monitoring config: {ConfigFilePath} for hot-reloading.", ConfigFilePath);
252+
SendLogToBufferOrLogger(LogLevel.Information, $"Monitoring config: {ConfigFilePath} for hot-reloading.");
242253
}
243254

244255
// When isDevMode is not null it means we are in a hot-reload scenario, and need to save the previous
@@ -248,14 +259,7 @@ public bool TryLoadConfig(
248259
// Log error when the mode is changed during hot-reload.
249260
if (isDevMode != this.RuntimeConfig.IsDevelopmentMode())
250261
{
251-
if (logger is null)
252-
{
253-
Console.WriteLine("Hot-reload doesn't support switching mode. Please restart the service to switch the mode.");
254-
}
255-
else
256-
{
257-
logger.LogError("Hot-reload doesn't support switching mode. Please restart the service to switch the mode.");
258-
}
262+
SendLogToBufferOrLogger(LogLevel.Error, "Hot-reload doesn't support switching mode. Please restart the service to switch the mode.");
259263
}
260264

261265
RuntimeConfig.Runtime.Host.Mode = (bool)isDevMode ? HostMode.Development : HostMode.Production;
@@ -280,16 +284,8 @@ public bool TryLoadConfig(
280284
return false;
281285
}
282286

283-
if (logger is null)
284-
{
285-
string errorMessage = $"Unable to find config file: {path} does not exist.";
286-
Console.Error.WriteLine(errorMessage);
287-
}
288-
else
289-
{
290-
string errorMessage = "Unable to find config file: {path} does not exist.";
291-
logger.LogError(message: errorMessage, path);
292-
}
287+
string errorMessage = $"Unable to find config file: {path} does not exist.";
288+
SendLogToBufferOrLogger(LogLevel.Error, errorMessage);
293289

294290
config = null;
295291
return false;
@@ -515,4 +511,35 @@ public void UpdateConfigFilePath(string filePath)
515511
_baseConfigFilePath = filePath;
516512
ConfigFilePath = filePath;
517513
}
514+
515+
public void SetLogger(ILogger<FileSystemRuntimeConfigLoader> logger)
516+
{
517+
_logger = logger;
518+
}
519+
520+
/// <summary>
521+
/// Flush all logs from the buffer after the log level is set from the RuntimeConfig.
522+
/// </summary>
523+
public void FlushLogBuffer()
524+
{
525+
_logBuffer?.FlushToLogger(_logger);
526+
}
527+
528+
/// <summary>
529+
/// Helper method that sends the log to the buffer if the logger has not being set up.
530+
/// Else, it will send the log to the logger.
531+
/// </summary>
532+
/// <param name="logLevel">LogLevel of the log.</param>
533+
/// <param name="message">Message that will be printed in the log.</param>
534+
private void SendLogToBufferOrLogger(LogLevel logLevel, string message)
535+
{
536+
if (_logger is null)
537+
{
538+
_logBuffer?.BufferLog(logLevel, message);
539+
}
540+
else
541+
{
542+
_logger?.Log(logLevel, message);
543+
}
544+
}
518545
}

‎src/Config/ObjectModel/RuntimeConfig.cs‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -714,7 +714,6 @@ Runtime.Telemetry.LoggerLevel is null ||
714714
/// </summary>
715715
public LogLevel GetConfiguredLogLevel(string loggerFilter = "")
716716
{
717-
718717
if (!IsLogLevelNull())
719718
{
720719
int max = 0;
@@ -735,7 +734,8 @@ public LogLevel GetConfiguredLogLevel(string loggerFilter = "")
735734
return (LogLevel)value;
736735
}
737736

738-
Runtime!.Telemetry!.LoggerLevel!.TryGetValue("default", out value);
737+
value = Runtime!.Telemetry!.LoggerLevel!
738+
.SingleOrDefault(kvp => kvp.Key.Equals("default", StringComparison.OrdinalIgnoreCase)).Value;
739739
if (value is not null)
740740
{
741741
return (LogLevel)value;

‎src/Config/StartupLogBuffer.cs‎

Lines changed: 45 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,45 @@
1+
// Copyright (c) Microsoft Corporation.
2+
// Licensed under the MIT License.
3+
4+
using System.Collections.Concurrent;
5+
using Microsoft.Extensions.Logging;
6+
7+
namespace Azure.DataApiBuilder.Config
8+
{
9+
/// <summary>
10+
/// A general-purpose log buffer that stores log entries before the final log level is determined.
11+
/// Can be used across different components during startup to capture important early logs.
12+
/// </summary>
13+
public class StartupLogBuffer
14+
{
15+
private readonly ConcurrentQueue<(LogLevel LogLevel, string Message)> _logBuffer;
16+
private readonly object _flushLock = new();
17+
18+
public StartupLogBuffer()
19+
{
20+
_logBuffer = new();
21+
}
22+
23+
/// <summary>
24+
/// Buffers a log entry with a specific category name.
25+
/// </summary>
26+
public void BufferLog(LogLevel logLevel, string message)
27+
{
28+
_logBuffer.Enqueue((logLevel, message));
29+
}
30+
31+
/// <summary>
32+
/// Flushes all buffered logs to a single target logger.
33+
/// </summary>
34+
public void FlushToLogger(ILogger? targetLogger)
35+
{
36+
lock (_flushLock)
37+
{
38+
while (_logBuffer.TryDequeue(out (LogLevel LogLevel, string Message) entry))
39+
{
40+
targetLogger?.Log(entry.LogLevel, message: entry.Message);
41+
}
42+
}
43+
}
44+
}
45+
}

‎src/Core/Configurations/RuntimeConfigValidator.cs‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1502,7 +1502,7 @@ private static bool IsLoggerFilterValid(string loggerFilter)
15021502
{
15031503
for (int j = 0; j < loggerSub.Length; j++)
15041504
{
1505-
if (!loggerSub[j].Equals(validFiltersSub[j]))
1505+
if (!loggerSub[j].Equals(validFiltersSub[j], StringComparison.OrdinalIgnoreCase))
15061506
{
15071507
isValid = false;
15081508
break;

‎src/Service.Tests/Configuration/ConfigurationTests.cs‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4057,6 +4057,7 @@ public void ValidLogLevelFilters(LogLevel logLevel, Type loggingType)
40574057
[DataTestMethod]
40584058
[TestCategory(TestCategory.MSSQL)]
40594059
[DataRow(LogLevel.Trace, "default")]
4060+
[DataRow(LogLevel.Warning, "Default")]
40604061
[DataRow(LogLevel.Debug, "Azure")]
40614062
[DataRow(LogLevel.Information, "Azure.DataApiBuilder")]
40624063
[DataRow(LogLevel.Warning, "Azure.DataApiBuilder.Core")]

‎src/Service.Tests/Configuration/HealthEndpointTests.cs‎

Lines changed: 88 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -564,6 +564,94 @@ private static RuntimeConfig CreateRuntimeConfig(Dictionary<string, Entity> enti
564564
return runtimeConfig;
565565
}
566566

567+
/// <summary>
568+
/// Verifies that stored procedures are excluded from health check results.
569+
/// Creates a config with both a table entity and a stored procedure entity,
570+
/// then validates that only the table entity appears in the health endpoint response.
571+
/// </summary>
572+
[TestMethod]
573+
[TestCategory(TestCategory.MSSQL)]
574+
public async Task HealthEndpoint_ExcludesStoredProcedures()
575+
{
576+
// Create a table entity
577+
Entity tableEntity = new(
578+
Health: new(enabled: true),
579+
Source: new("books", EntitySourceType.Table, null, null),
580+
Fields: null,
581+
Rest: new(Enabled: true),
582+
GraphQL: new("book", "bookLists", true),
583+
Permissions: new[] { ConfigurationTests.GetMinimalPermissionConfig(AuthorizationResolver.ROLE_ANONYMOUS) },
584+
Relationships: null,
585+
Mappings: null);
586+
587+
// Create a stored procedure entity - using an actual stored procedure from test schema
588+
Entity storedProcEntity = new(
589+
Health: new(enabled: true),
590+
Source: new("get_books", EntitySourceType.StoredProcedure, null, null),
591+
Fields: null,
592+
Rest: new(Enabled: true),
593+
GraphQL: new("executeGetBooks", "executeGetBooksList", true),
594+
Permissions: new[] { ConfigurationTests.GetMinimalPermissionConfig(AuthorizationResolver.ROLE_ANONYMOUS) },
595+
Relationships: null,
596+
Mappings: null);
597+
598+
Dictionary<string, Entity> entityMap = new()
599+
{
600+
{ "Book", tableEntity },
601+
{ "GetBooks", storedProcEntity }
602+
};
603+
604+
RuntimeConfig runtimeConfig = CreateRuntimeConfig(
605+
entityMap,
606+
enableGlobalRest: true,
607+
enableGlobalGraphql: true,
608+
enabledGlobalMcp: true,
609+
enableGlobalHealth: true,
610+
enableDatasourceHealth: true,
611+
hostMode: HostMode.Development);
612+
613+
WriteToCustomConfigFile(runtimeConfig);
614+
615+
string[] args = new[]
616+
{
617+
$"--ConfigFileName={CUSTOM_CONFIG_FILENAME}"
618+
};
619+
620+
using (TestServer server = new(Program.CreateWebHostBuilder(args)))
621+
using (HttpClient client = server.CreateClient())
622+
{
623+
HttpRequestMessage healthRequest = new(HttpMethod.Get, $"{BASE_DAB_URL}/health");
624+
HttpResponseMessage response = await client.SendAsync(healthRequest);
625+
626+
Assert.AreEqual(HttpStatusCode.OK, response.StatusCode, "Health endpoint should return OK");
627+
628+
string responseBody = await response.Content.ReadAsStringAsync();
629+
Dictionary<string, JsonElement> responseProperties = JsonSerializer.Deserialize<Dictionary<string, JsonElement>>(responseBody);
630+
631+
// Get the checks array
632+
Assert.IsTrue(responseProperties.TryGetValue("checks", out JsonElement checksElement), "Response should contain 'checks' property");
633+
Assert.AreEqual(JsonValueKind.Array, checksElement.ValueKind, "Checks should be an array");
634+
635+
// Get all entity names from the health check results
636+
List<string> entityNamesInHealthCheck = new();
637+
foreach (JsonElement check in checksElement.EnumerateArray())
638+
{
639+
if (check.TryGetProperty("name", out JsonElement nameElement))
640+
{
641+
entityNamesInHealthCheck.Add(nameElement.GetString());
642+
}
643+
}
644+
645+
// Verify that the table entity (Book) appears in health checks
646+
Assert.IsTrue(entityNamesInHealthCheck.Contains("Book"),
647+
"Table entity 'Book' should be included in health check results");
648+
649+
// Verify that the stored procedure entity (GetBooks) does NOT appear in health checks
650+
Assert.IsFalse(entityNamesInHealthCheck.Contains("GetBooks"),
651+
"Stored procedure entity 'GetBooks' should be excluded from health check results");
652+
}
653+
}
654+
567655
private static void WriteToCustomConfigFile(RuntimeConfig runtimeConfig)
568656
{
569657
File.WriteAllText(

‎src/Service/HealthCheck/HealthCheckHelper.cs‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -198,10 +198,11 @@ private async Task UpdateDataSourceHealthCheckResultsAsync(ComprehensiveHealthCh
198198

199199
// Updates the Entity Health Check Results in the response.
200200
// Goes through the entities one by one and executes the rest and graphql checks (if enabled).
201+
// Stored procedures are excluded from health checks because they require parameters and are not guaranteed to be deterministic.
201202
private async Task UpdateEntityHealthCheckResultsAsync(ComprehensiveHealthCheckReport report, RuntimeConfig runtimeConfig)
202203
{
203204
List<KeyValuePair<string, Entity>> enabledEntities = runtimeConfig.Entities.Entities
204-
.Where(e => e.Value.IsEntityHealthEnabled)
205+
.Where(e => e.Value.IsEntityHealthEnabled && e.Value.Source.Type != EntitySourceType.StoredProcedure)
205206
.ToList();
206207

207208
if (enabledEntities.Count == 0)

‎src/Service/Program.cs‎

Lines changed: 14 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -33,6 +33,7 @@ namespace Azure.DataApiBuilder.Service
3333
public class Program
3434
{
3535
public static bool IsHttpsRedirectionDisabled { get; private set; }
36+
public static DynamicLogLevelProvider LogLevelProvider = new();
3637

3738
public static void Main(string[] args)
3839
{
@@ -59,7 +60,6 @@ public static void Main(string[] args)
5960

6061
public static bool StartEngine(string[] args, bool runMcpStdio, string? mcpRole)
6162
{
62-
Console.WriteLine("Starting the runtime engine...");
6363
try
6464
{
6565
IHost host = CreateHostBuilder(args, runMcpStdio, mcpRole).Build();
@@ -107,9 +107,19 @@ public static IHostBuilder CreateHostBuilder(string[] args, bool runMcpStdio, st
107107
McpStdioHelper.ConfigureMcpStdio(builder, mcpRole);
108108
}
109109
})
110+
.ConfigureServices((context, services) =>
111+
{
112+
services.AddSingleton(LogLevelProvider);
113+
})
114+
.ConfigureLogging(logging =>
115+
{
116+
logging.AddFilter("Microsoft", logLevel => LogLevelProvider.ShouldLog(logLevel));
117+
logging.AddFilter("Microsoft.Hosting.Lifetime", logLevel => LogLevelProvider.ShouldLog(logLevel));
118+
})
110119
.ConfigureWebHostDefaults(webBuilder =>
111120
{
112121
Startup.MinimumLogLevel = GetLogLevelFromCommandLineArgs(args, out Startup.IsLogLevelOverriddenByCli);
122+
LogLevelProvider.SetInitialLogLevel(Startup.MinimumLogLevel, Startup.IsLogLevelOverriddenByCli);
113123
ILoggerFactory loggerFactory = GetLoggerFactoryForLogLevel(Startup.MinimumLogLevel, stdio: runMcpStdio);
114124
ILogger<Startup> startupLogger = loggerFactory.CreateLogger<Startup>();
115125
DisableHttpsRedirectionIfNeeded(args);
@@ -185,9 +195,9 @@ public static ILoggerFactory GetLoggerFactoryForLogLevel(
185195
// "Azure.DataApiBuilder.Service"
186196
if (logLevelInitializer is null)
187197
{
188-
builder.AddFilter(category: "Microsoft", logLevel);
189-
builder.AddFilter(category: "Azure", logLevel);
190-
builder.AddFilter(category: "Default", logLevel);
198+
builder.AddFilter(category: "Microsoft", logLevel => LogLevelProvider.ShouldLog(logLevel));
199+
builder.AddFilter(category: "Azure", logLevel => LogLevelProvider.ShouldLog(logLevel));
200+
builder.AddFilter(category: "Default", logLevel => LogLevelProvider.ShouldLog(logLevel));
191201
}
192202
else
193203
{

0 commit comments

Comments
 (0)