diff --git a/src/Azure.DataApiBuilder.Mcp/BuiltInTools/DescribeEntitiesTool.cs b/src/Azure.DataApiBuilder.Mcp/BuiltInTools/DescribeEntitiesTool.cs index 95e37c4498..d7fd058ea3 100644 --- a/src/Azure.DataApiBuilder.Mcp/BuiltInTools/DescribeEntitiesTool.cs +++ b/src/Azure.DataApiBuilder.Mcp/BuiltInTools/DescribeEntitiesTool.cs @@ -3,6 +3,7 @@ using System.Text.Json; using Azure.DataApiBuilder.Auth; +using Azure.DataApiBuilder.Config.DatabasePrimitives; using Azure.DataApiBuilder.Config.ObjectModel; using Azure.DataApiBuilder.Core.Authorization; using Azure.DataApiBuilder.Core.Configurations; @@ -177,15 +178,37 @@ public Task ExecuteAsync( try { + DatabaseObject? databaseObject = null; + if (entity.Source.Type == EntitySourceType.StoredProcedure) + { + databaseObject = McpMetadataHelper.TryResolveDatabaseObject( + entityName, + runtimeConfig, + serviceProvider, + out string resolveError, + cancellationToken); + + if (databaseObject is null) + { + // Init normally populates DatabaseStoredProcedure for every SP entity + // (or throws and aborts startup). Reaching here means an init invariant + // regressed. Throw so the surrounding catch drops just this entity from + // the response - returning the SP with no parameter info would mislead + // the agent into thinking the SP takes no arguments. + throw new InvalidOperationException( + $"Could not resolve DB metadata for stored procedure entity '{entityName}'. Error: {resolveError}"); + } + } + Dictionary entityInfo = nameOnly ? BuildBasicEntityInfo(entityName, entity) - : BuildFullEntityInfo(entityName, entity, currentUserRole); + : BuildFullEntityInfo(entityName, entity, currentUserRole, databaseObject); entityList.Add(entityInfo); } catch (Exception ex) { - logger?.LogWarning(ex, "Failed to build info for entity {EntityName}", entityName); + logger?.LogWarning(ex, "Failed to build info for entity '{EntityName}'", entityName); } } } @@ -403,10 +426,11 @@ private static bool ShouldIncludeEntity(string entityName, HashSet? enti /// The name of the entity to include in the dictionary. /// The entity object from which to extract additional information. /// The role of the current user, used to determine permissions. + /// The resolved database object metadata if available. /// /// A dictionary containing the entity's name, description, fields, parameters (if applicable), and permissions. /// - private static Dictionary BuildFullEntityInfo(string entityName, Entity entity, string? currentUserRole) + private static Dictionary BuildFullEntityInfo(string entityName, Entity entity, string? currentUserRole, DatabaseObject? databaseObject) { // Use GraphQL singular name as alias if available, otherwise use entity name string displayName = !string.IsNullOrWhiteSpace(entity.GraphQL?.Singular) @@ -422,7 +446,7 @@ private static bool ShouldIncludeEntity(string entityName, HashSet? enti if (entity.Source.Type == EntitySourceType.StoredProcedure) { - info["parameters"] = BuildParameterMetadataInfo(entity.Source.Parameters); + info["parameters"] = BuildParameterMetadataInfo(databaseObject); } info["permissions"] = BuildPermissionsInfo(entity, currentUserRole); @@ -456,33 +480,62 @@ private static List BuildFieldMetadataInfo(List? fields) } /// - /// Builds a list of parameter metadata objects containing information about each parameter. + /// Builds the parameter list for a stored procedure entity. + /// Each entry has: name, required, default, description. + /// + /// The per-field rules are agreed in issue #3400: + /// name - DB metadata is the source of truth; config cannot override. + /// required - defaults to true when not set in config. + /// (SQL Server's is_nullable describes the type, not whether the + /// parameter must be supplied at call time, so it is unreliable.) + /// default - config-only. T-SQL parameter defaults are not exposed as + /// structured metadata, so they cannot be discovered from the DB. + /// description - config-only. SQL Server has no description column for parameters. + /// + /// The merge of config onto DB metadata is already performed upstream by + /// / + /// when populating + /// . Each therefore + /// already reflects the config overlay; we just project it. + /// + /// For an SP entity that successfully initialized, the metadata provider always has a + /// populated : init throws otherwise (e.g. + /// SqlMetadataProvider.FillSchemaForStoredProcedureAsync raises via HandleOrRecordException + /// when config declares a parameter the DB doesn't have, and startup aborts). If this + /// invariant ever regresses we throw rather than fabricate empty parameter info, so the + /// surrounding per-entity catch drops just this entity from the response. /// - /// A list of objects representing the parameters to process. Can be null. - /// A list of dictionaries, each containing the parameter's name, whether it is required, its default - /// value, and its description. Returns an empty list if is null. - private static List BuildParameterMetadataInfo(List? parameters) + /// DB metadata for the entity. Must be a populated . + /// A list whose elements are dictionaries (one per parameter), each with the keys + /// name, required, default, and description. + /// Thrown when is not a with a populated . + private static List BuildParameterMetadataInfo(DatabaseObject? databaseObject) { - List result = new(); - - if (parameters != null) + IReadOnlyDictionary? dbParameters = + (databaseObject as DatabaseStoredProcedure)?.StoredProcedureDefinition?.Parameters + ?? throw new InvalidOperationException( + "Stored-procedure metadata is missing at describe_entities time. " + + "SqlMetadataProvider.FillSchemaForStoredProcedureAsync should have populated this during init."); + + List result = new(dbParameters.Count); + foreach ((string parameterName, ParameterDefinition definition) in dbParameters) { - foreach (ParameterMetadata param in parameters) - { - Dictionary paramInfo = new() - { - ["name"] = param.Name, - ["required"] = param.Required, - ["default"] = param.Default, - ["description"] = param.Description ?? string.Empty - }; - result.Add(paramInfo); - } + result.Add(BuildParameterEntry(parameterName, definition)); } return result; } + private static Dictionary BuildParameterEntry( + string name, + ParameterDefinition definition) => new() + { + ["name"] = name, + ["required"] = definition.Required ?? true, + ["default"] = definition.Default, + ["description"] = definition.Description ?? string.Empty + }; + /// /// Build a list of permission metadata info for the current user's role /// diff --git a/src/Azure.DataApiBuilder.Mcp/Core/McpStdioServer.cs b/src/Azure.DataApiBuilder.Mcp/Core/McpStdioServer.cs index 8ec232981a..e8526df0aa 100644 --- a/src/Azure.DataApiBuilder.Mcp/Core/McpStdioServer.cs +++ b/src/Azure.DataApiBuilder.Mcp/Core/McpStdioServer.cs @@ -261,17 +261,26 @@ private void HandleListTools(JsonElement? id) /// The root JSON element of the incoming JSON-RPC request. /// /// Log level precedence (highest to lowest): - /// 1. CLI --LogLevel flag - cannot be overridden - /// 2. Config runtime.telemetry.log-level - cannot be overridden by MCP - /// 3. MCP logging/setLevel - only works if neither CLI nor Config explicitly set a level - /// 4. Default: None for MCP stdio mode (silent by default to keep stdout clean for JSON-RPC) - /// - /// If CLI or Config set the log level, this method accepts the request but silently ignores it. - /// The client won't get an error, but CLI/Config wins. - /// - /// When MCP sets a level other than "none", this also restores Console.Error to the real stderr - /// stream so that logs become visible (Console may have been redirected to null at startup). - /// It also enables MCP log notifications so logs are sent to the client via notifications/message. + /// 1. MCP logging/setLevel (Agent) - always wins, overrides CLI and Config. + /// 2. CLI --LogLevel flag. + /// 3. Config runtime.telemetry.log-level. + /// 4. Default: None for MCP stdio mode (silent by default to keep stdout clean for JSON-RPC), + /// Error in Production, Debug in Development. + /// + /// Per MCP spec the response is always success (empty result object) even when the input is + /// an unrecognized level — in that case no side effect runs and no state changes. + /// + /// Side effects performed in order on a valid request: + /// 1. Toggle based on the level + /// ("none" disables, anything else enables). This is done BEFORE + /// so the audit log line that + /// UpdateFromMcp emits is forwarded to the agent rather than dropped. + /// 2. Call , which updates the level and + /// flips so subsequent runtime-config + /// hot-reloads do not overwrite the agent's choice. + /// 3. Restore to the real stderr stream when logging is enabled, + /// in case startup redirected it to (default for + /// --mcp-stdio or --LogLevel none). /// private void HandleSetLogLevel(JsonElement? id, JsonElement root) { @@ -299,35 +308,44 @@ private void HandleSetLogLevel(JsonElement? id, JsonElement root) return; } - // Attempt to update the log level - // If CLI or Config overrode, this returns false but we still return success to the client - bool updated = logLevelController.UpdateFromMcp(level); - - // Determine if logging is enabled (level != "none") - // Note: Even if CLI/Config overrode the level, we still enable notifications - // when the client requests logging. They'll get logs at the overridden level. - bool isLoggingEnabled = !string.Equals(level, "none", StringComparison.OrdinalIgnoreCase); - - // Only restore stderr when this MCP call actually changed the effective level. - // If CLI/Config overrode (updated == false), stderr is already in the correct state: - // - CLI/Config level == "none": stderr was redirected to TextWriter.Null at startup - // and must stay that way; restoring it would re-introduce noisy output even - // though the operator explicitly asked for silence. - // - CLI/Config level != "none": stderr was never redirected, so restoring is a no-op. - if (updated && isLoggingEnabled) + // Validate the level BEFORE touching any side-effect (notification writer, stderr). + // "none" is the disable signal and is not a recognized MCP level; everything else + // must round-trip through McpLogLevelConverter so a typo can't silently turn the + // notification stream on while UpdateFromMcp ignores the bad value. + bool isDisableRequest = string.Equals(level, "none", StringComparison.OrdinalIgnoreCase); + bool isValidLevel = isDisableRequest || McpLogLevelConverter.TryConvertFromMcp(level, out _); + if (!isValidLevel) { - RestoreStderrIfNeeded(); + // Unknown level - return success per MCP spec but make no state changes. + WriteResult(id, new { }); + return; } - // Enable or disable MCP log notifications based on the requested level - // When CLI/Config overrode, notifications are still enabled - client asked for logs, - // they just get them at the CLI/Config level instead of the requested level. + bool isLoggingEnabled = !isDisableRequest; + + // Enable or disable MCP log notifications based on the requested level BEFORE updating + // the level. Doing it in this order means the agent-override Information line emitted + // by UpdateFromMcp is forwarded to the agent (otherwise it would be dropped because + // the notification writer was still disabled at the moment of emission). IMcpLogNotificationWriter? notificationWriter = _serviceProvider.GetService(); if (notificationWriter != null) { notificationWriter.IsEnabled = isLoggingEnabled; } + // Update the log level. Validation above guarantees this returns true for non-"none" + // values; for "none" it returns false (no LogLevel mapping) and we just keep + // notifications off without touching the current level. + bool updated = logLevelController.UpdateFromMcp(level); + + // Restore stderr if the agent successfully turned logging on. When `--mcp-stdio` (or + // `--LogLevel none`) was the startup default, stderr was redirected to TextWriter.Null; + // re-enable it now so subsequent logs flow. + if (updated && isLoggingEnabled) + { + RestoreStderrIfNeeded(); + } + // Always return success (empty result object) per MCP spec WriteResult(id, new { }); } diff --git a/src/Azure.DataApiBuilder.Mcp/Utils/McpMetadataHelper.cs b/src/Azure.DataApiBuilder.Mcp/Utils/McpMetadataHelper.cs index 1e79e86b15..2d79649bbb 100644 --- a/src/Azure.DataApiBuilder.Mcp/Utils/McpMetadataHelper.cs +++ b/src/Azure.DataApiBuilder.Mcp/Utils/McpMetadataHelper.cs @@ -13,6 +13,35 @@ namespace Azure.DataApiBuilder.Mcp.Utils /// public static class McpMetadataHelper { + /// + /// Convenience wrapper around for callers that only need the + /// resolved . Returns the database object on success, or null + /// when metadata cannot be resolved (with the failure reason surfaced via ). + /// Callers are responsible for logging at the appropriate verbosity for their tool context. + /// + public static DatabaseObject? TryResolveDatabaseObject( + string entityName, + RuntimeConfig config, + IServiceProvider serviceProvider, + out string error, + CancellationToken cancellationToken = default) + { + if (TryResolveMetadata( + entityName, + config, + serviceProvider, + out _, + out DatabaseObject dbObject, + out _, + out error, + cancellationToken)) + { + return dbObject; + } + + return null; + } + public static bool TryResolveMetadata( string entityName, RuntimeConfig config, @@ -35,7 +64,14 @@ public static bool TryResolveMetadata( return false; } - var metadataProviderFactory = serviceProvider.GetRequiredService(); + // Use GetService (not GetRequiredService) so the helper honours its Try* contract. + Azure.DataApiBuilder.Core.Services.MetadataProviders.IMetadataProviderFactory? metadataProviderFactory = + serviceProvider.GetService(); + if (metadataProviderFactory is null) + { + error = "Metadata provider factory is not registered."; + return false; + } // Resolve datasource name for the entity. try diff --git a/src/Cli.Tests/CustomLoggerTests.cs b/src/Cli.Tests/CustomLoggerTests.cs index 951cbc6a77..8c08efc3e6 100644 --- a/src/Cli.Tests/CustomLoggerTests.cs +++ b/src/Cli.Tests/CustomLoggerTests.cs @@ -4,78 +4,179 @@ namespace Cli.Tests; /// -/// Tests for CustomLoggerProvider and CustomConsoleLogger, verifying -/// that log level labels use ASP.NET Core abbreviated format. +/// Tests for covering both the standard CLI +/// path (writes to stdout/stderr with abbreviated labels) and the MCP stdio path +/// (suppressed by default, opt-in via either CLI --LogLevel or the +/// runtime config's log-level, always routed to stderr to keep the +/// JSON-RPC channel on stdout uncorrupted). /// [TestClass] public class CustomLoggerTests { /// - /// Validates that each enabled log level produces the correct abbreviated label - /// matching ASP.NET Core's default console formatter convention. - /// Trace and Debug are below the logger's minimum level and produce no output. + /// The CustomConsoleLogger reads several static flags from . + /// Reset them around every test so cases cannot leak into each other and so the + /// rest of the test suite continues to see the default (non-MCP) behavior. /// - [DataTestMethod] - [DataRow(LogLevel.Information, "info:")] - [DataRow(LogLevel.Warning, "warn:")] - public void LogOutput_UsesAbbreviatedLogLevelLabels(LogLevel logLevel, string expectedPrefix) + [TestInitialize] + [TestCleanup] + public void ResetMcpStaticState() { - CustomLoggerProvider provider = new(); - ILogger logger = provider.CreateLogger("TestCategory"); + Cli.Utils.IsMcpStdioMode = false; + Cli.Utils.IsCliOverriding = false; + Cli.Utils.IsConfigOverriding = false; + Cli.Utils.CliLogLevel = LogLevel.Information; + Cli.Utils.ConfigLogLevel = LogLevel.Information; + } + /// + /// Redirects Console.Out and Console.Error around + /// and returns whatever was written to each. Restores the original writers + /// on exit. + /// + private static (string Stdout, string Stderr) CaptureConsole(Action action) + { TextWriter originalOut = Console.Out; + TextWriter originalError = Console.Error; + StringWriter stdout = new(); + StringWriter stderr = new(); try { - StringWriter writer = new(); - Console.SetOut(writer); - - logger.Log(logLevel, "test message"); - - string output = writer.ToString(); - Assert.IsTrue( - output.StartsWith(expectedPrefix), - $"Expected output to start with '{expectedPrefix}' but got: '{output}'"); - Assert.IsTrue( - output.Contains("test message"), - $"Expected output to contain 'test message' but got: '{output}'"); + Console.SetOut(stdout); + Console.SetError(stderr); + action(); } finally { Console.SetOut(originalOut); + Console.SetError(originalError); } + + return (stdout.ToString(), stderr.ToString()); } + private static ILogger NewLogger() => + new CustomLoggerProvider().CreateLogger("TestCategory"); + /// - /// Validates that each log level error and above produces the correct abbreviated - /// label matching ASP.NET Core's default console formatter convention. - /// Error and Critical logs should go to the stderr stream. + /// Standard (non-MCP) path: each log level produces the correct abbreviated + /// label matching ASP.NET Core's default console formatter and is routed to + /// stdout for Information/Warning and stderr for Error/Critical. /// [DataTestMethod] - [DataRow(LogLevel.Error, "fail:")] - [DataRow(LogLevel.Critical, "crit:")] - public void LogError_UsesAbbreviatedLogLevelLabels(LogLevel logLevel, string expectedPrefix) + [DataRow(LogLevel.Information, "info:", false)] + [DataRow(LogLevel.Warning, "warn:", false)] + [DataRow(LogLevel.Error, "fail:", true)] + [DataRow(LogLevel.Critical, "crit:", true)] + public void LogOutput_UsesAbbreviatedLogLevelLabels(LogLevel logLevel, string expectedPrefix, bool expectStderr) { - CustomLoggerProvider provider = new(); - ILogger logger = provider.CreateLogger("TestCategory"); + const string Message = "test message"; - TextWriter originalError = Console.Error; - try + (string stdout, string stderr) = CaptureConsole(() => NewLogger().Log(logLevel, Message)); + + string actual = expectStderr ? stderr : stdout; + string other = expectStderr ? stdout : stderr; + + Assert.IsTrue(actual.StartsWith(expectedPrefix), + $"Expected output to start with '{expectedPrefix}' but got: '{actual}'"); + StringAssert.Contains(actual, Message); + Assert.AreEqual(string.Empty, other, + $"Did not expect output on the other stream but got: '{other}'"); + } + + /// + /// MCP stdio mode with no overrides (neither CLI --LogLevel nor + /// config log-level): all output must be suppressed so the JSON-RPC + /// channel stays clean. + /// + [TestMethod] + public void Mcp_NoOverrides_SuppressesAllOutput() + { + Cli.Utils.IsMcpStdioMode = true; + + (string stdout, string stderr) = CaptureConsole(() => { - StringWriter writer = new(); - Console.SetError(writer); - logger.Log(logLevel, "test message"); - - string output = writer.ToString(); - Assert.IsTrue( - output.StartsWith(expectedPrefix), - $"Expected output to start with '{expectedPrefix}' but got: '{output}'"); - Assert.IsTrue( - output.Contains("test message"), - $"Expected output to contain 'test message' but got: '{output}'"); - } - finally + ILogger logger = NewLogger(); + logger.Log(LogLevel.Information, "info should not appear"); + logger.Log(LogLevel.Error, "error should not appear"); + }); + + Assert.AreEqual(string.Empty, stdout, "MCP mode without overrides must not write to stdout."); + Assert.AreEqual(string.Empty, stderr, "MCP mode without overrides must not write to stderr."); + } + + /// + /// MCP stdio mode with a CLI-supplied --LogLevel: logs must always + /// go to stderr (never stdout) and the level threshold from + /// must be honored. + /// + [TestMethod] + public void Mcp_CliOverride_WritesToStderrAndHonorsCliLevel() + { + Cli.Utils.IsMcpStdioMode = true; + Cli.Utils.IsCliOverriding = true; + Cli.Utils.CliLogLevel = LogLevel.Warning; + + (string stdout, string stderr) = CaptureConsole(() => { - Console.SetError(originalError); - } + ILogger logger = NewLogger(); + logger.Log(LogLevel.Information, "filtered info"); // below threshold + logger.Log(LogLevel.Warning, "visible warn"); // at threshold + logger.Log(LogLevel.Error, "visible error"); // above threshold + }); + + Assert.AreEqual(string.Empty, stdout, "MCP mode must never write to stdout."); + Assert.IsFalse(stderr.Contains("filtered info"), $"Below-threshold log should be filtered. Got: '{stderr}'"); + StringAssert.Contains(stderr, "warn: visible warn"); + StringAssert.Contains(stderr, "fail: visible error"); + } + + /// + /// Bug fix: MCP stdio mode where only the runtime config (no CLI flag) + /// supplied the log level. Previously suppressed; must now emit to stderr + /// using . + /// + [TestMethod] + public void Mcp_ConfigOverride_WritesToStderrAndHonorsConfigLevel() + { + Cli.Utils.IsMcpStdioMode = true; + Cli.Utils.IsConfigOverriding = true; + Cli.Utils.ConfigLogLevel = LogLevel.Information; + + (string stdout, string stderr) = CaptureConsole(() => + { + ILogger logger = NewLogger(); + logger.Log(LogLevel.Debug, "filtered debug"); // below threshold + logger.Log(LogLevel.Information, "visible info"); // at threshold + }); + + Assert.AreEqual(string.Empty, stdout, "MCP mode must never write to stdout."); + Assert.IsFalse(stderr.Contains("filtered debug"), $"Below-threshold log should be filtered. Got: '{stderr}'"); + StringAssert.Contains(stderr, "info: visible info"); + } + + /// + /// Precedence: when both CLI and config supply a log level, the CLI value + /// wins (CLI > Config > None). + /// + [TestMethod] + public void Mcp_CliOverridePrecedesConfigOverride() + { + Cli.Utils.IsMcpStdioMode = true; + Cli.Utils.IsCliOverriding = true; + Cli.Utils.CliLogLevel = LogLevel.Warning; + Cli.Utils.IsConfigOverriding = true; + Cli.Utils.ConfigLogLevel = LogLevel.Information; + + (_, string stderr) = CaptureConsole(() => + { + ILogger logger = NewLogger(); + logger.Log(LogLevel.Information, "filtered by CLI Warning"); + logger.Log(LogLevel.Warning, "passes CLI Warning"); + }); + + Assert.IsFalse(stderr.Contains("filtered by CLI Warning"), + $"CLI level should override config and filter Information. Got: '{stderr}'"); + StringAssert.Contains(stderr, "warn: passes CLI Warning"); } } diff --git a/src/Cli.Tests/EndToEndTests.cs b/src/Cli.Tests/EndToEndTests.cs index 33453ddcab..a23f7823d2 100644 --- a/src/Cli.Tests/EndToEndTests.cs +++ b/src/Cli.Tests/EndToEndTests.cs @@ -914,17 +914,17 @@ public async Task TestEngineStartUpWithLogLevelNone(string logLevelOption) Assert.IsTrue(string.IsNullOrEmpty(engineStdOut), $"Expected no output at LogLevel {logLevelOption}, but got: {engineStdOut}"); } - /// Validates that `dab start` correctly sets + /// Validates that `dab start` correctly sets /// based on whether the --LogLevel CLI flag is provided. /// - /// When the --LogLevel flag is provided, IsLogLevelOverriddenByCli should be true. - /// When the --LogLevel flag is omitted (log level comes from the config file), IsLogLevelOverriddenByCli should be false. + /// When the --LogLevel flag is provided, IsCliOverriding should be true. + /// When the --LogLevel flag is omitted (log level comes from the config file), IsCliOverriding should be false. /// /// The --LogLevel CLI flag value, or null to omit the flag. - /// Expected value of Startup.IsLogLevelOverriddenByCli. + /// Expected value of Startup.IsCliOverriding. [DataTestMethod] - [DataRow(null, false, DisplayName = "IsLogLevelOverriddenByCli is false")] - [DataRow(LogLevel.Error, true, DisplayName = "IsLogLevelOverriddenByCli is true")] + [DataRow(null, false, DisplayName = "IsCliOverriding is false")] + [DataRow(LogLevel.Error, true, DisplayName = "IsCliOverriding is true")] public async Task TestStartCommandResolvesLogLevelFromConfigOrFlag( LogLevel? cliLogLevel, bool expectedIsOverridden) @@ -987,7 +987,7 @@ public async Task TestStartCommandResolvesLogLevelFromConfigOrFlag( // Wait for the engine to finish loading the config. await Task.Delay(TimeSpan.FromSeconds(5)); - Assert.AreEqual(expectedIsOverridden, Startup.IsLogLevelOverriddenByCli); + Assert.AreEqual(expectedIsOverridden, Startup.IsCliOverriding); } /// diff --git a/src/Cli.Tests/Snapshots/EndToEndTests.TestConfigGeneratedAfterUpdatingEntityWithSourceAsStoredProcedure.verified.txt b/src/Cli.Tests/Snapshots/EndToEndTests.TestConfigGeneratedAfterUpdatingEntityWithSourceAsStoredProcedure.verified.txt index 49af50b975..3ec0d00bfa 100644 --- a/src/Cli.Tests/Snapshots/EndToEndTests.TestConfigGeneratedAfterUpdatingEntityWithSourceAsStoredProcedure.verified.txt +++ b/src/Cli.Tests/Snapshots/EndToEndTests.TestConfigGeneratedAfterUpdatingEntityWithSourceAsStoredProcedure.verified.txt @@ -5,17 +5,14 @@ Parameters: [ { Name: param1, - Required: false, Default: 123 }, { Name: param2, - Required: false, Default: hello }, { Name: param3, - Required: false, Default: True } ] diff --git a/src/Cli.Tests/Snapshots/UpdateEntityTests.UpdateDatabaseSourceName.verified.txt b/src/Cli.Tests/Snapshots/UpdateEntityTests.UpdateDatabaseSourceName.verified.txt index c479f34a59..01b0d35676 100644 --- a/src/Cli.Tests/Snapshots/UpdateEntityTests.UpdateDatabaseSourceName.verified.txt +++ b/src/Cli.Tests/Snapshots/UpdateEntityTests.UpdateDatabaseSourceName.verified.txt @@ -31,17 +31,14 @@ Parameters: [ { Name: param1, - Required: false, Default: 123 }, { Name: param2, - Required: false, Default: hello }, { Name: param3, - Required: false, Default: True } ] diff --git a/src/Cli/ConfigGenerator.cs b/src/Cli/ConfigGenerator.cs index 8a416e26ca..1820e3b353 100644 --- a/src/Cli/ConfigGenerator.cs +++ b/src/Cli/ConfigGenerator.cs @@ -2562,7 +2562,7 @@ private static bool TryGetUpdatedSourceObjectWithOptions( { Name = newParam.Name, Description = newParam.Description != null ? newParam.Description : match.Description, - Required = newParam.Required, + Required = newParam.Required != null ? newParam.Required : match.Required, Default = newParam.Default != null ? newParam.Default : match.Default }); } @@ -2752,6 +2752,12 @@ public static bool TryStartEngineWithOptions(StartOptions options, FileSystemRun /// - MCP stdio mode: Service defaults to None for clean stdout output /// - Non-MCP mode: Service defaults to Debug (Development) or Error (Production) based on config LogLevel minimumLogLevel; + + // Reset the config-based override flag so stale state from a prior call + // (these are static) cannot leak into the current run. + Utils.IsConfigOverriding = false; + Utils.ConfigLogLevel = LogLevel.Information; + if (options.LogLevel is not null) { if (options.LogLevel is < LogLevel.Trace or > LogLevel.None) @@ -2770,6 +2776,15 @@ public static bool TryStartEngineWithOptions(StartOptions options, FileSystemRun else { minimumLogLevel = deserializedRuntimeConfig.GetConfiguredLogLevel(); + + // Track whether config explicitly set a log level. In MCP stdio mode this + // allows CLI logs to be emitted to stderr (instead of being suppressed) + // when the user expressed intent via the config file rather than --LogLevel. + if (deserializedRuntimeConfig.HasExplicitLogLevel()) + { + Utils.IsConfigOverriding = true; + Utils.ConfigLogLevel = minimumLogLevel; + } } options.CliBuffer.BufferLog(LogLevel.Information, $"Setting minimum LogLevel: {minimumLogLevel}."); diff --git a/src/Cli/CustomLoggerProvider.cs b/src/Cli/CustomLoggerProvider.cs index b99f2597cd..80a046a042 100644 --- a/src/Cli/CustomLoggerProvider.cs +++ b/src/Cli/CustomLoggerProvider.cs @@ -28,14 +28,18 @@ public class CustomConsoleLogger : ILogger private readonly LogLevel _minimumLogLevel; // Minimum LogLevel for CLI output. - // For MCP mode: use CLI's --LogLevel if specified, otherwise suppress all. - // For non-MCP mode: always use Information. + // For MCP mode: prefer CLI's --LogLevel, fall back to config's log-level, otherwise suppress all. + // For non-MCP mode: always use the level passed to the constructor. // Note: --LogLevel is meant for the ENGINE's log level, not CLI's output. public CustomConsoleLogger(LogLevel minimumLogLevel = LogLevel.Information) { _minimumLogLevel = Cli.Utils.IsMcpStdioMode - ? (Cli.Utils.IsLogLevelOverriddenByCli ? Cli.Utils.CliLogLevel : LogLevel.None) - : minimumLogLevel; + ? (Cli.Utils.IsCliOverriding + ? Cli.Utils.CliLogLevel + : Cli.Utils.IsConfigOverriding + ? Cli.Utils.ConfigLogLevel + : LogLevel.None) + : minimumLogLevel; } // Color values based on LogLevel @@ -89,16 +93,17 @@ public CustomConsoleLogger(LogLevel minimumLogLevel = LogLevel.Information) /// /// Creates Log message by setting console message color based on LogLevel. /// In MCP stdio mode: - /// - If user explicitly set --LogLevel: write to stderr (colored output) + /// - If user explicitly set --LogLevel (CLI) or log-level (config): write to stderr (colored output) /// - Otherwise: suppress entirely to keep stdout clean for JSON-RPC protocol. /// public void Log(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func formatter) { - // In MCP stdio mode, only output logs if user explicitly requested a log level. + // In MCP stdio mode, only output logs if user explicitly requested a log level + // via either the CLI --LogLevel flag or the runtime config file's log-level. // In that case, write to stderr to keep stdout clean for JSON-RPC. if (Cli.Utils.IsMcpStdioMode) { - if (!Cli.Utils.IsLogLevelOverriddenByCli) + if (!Cli.Utils.IsCliOverriding && !Cli.Utils.IsConfigOverriding) { return; // Suppress entirely when no explicit log level } @@ -116,7 +121,24 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except // In MCP stdio mode, stdout is reserved for JSON-RPC protocol messages. // Logs must go to stderr to avoid corrupting the MCP communication channel. - Console.Error.WriteLine($"{mcpAbbreviation}: {formatter(state, exception)}"); + // Apply colors so the abbreviation matches the visual style of engine logs. + // try/finally guarantees the original colors are restored even if Write throws, + // otherwise the console would be left tinted (e.g. red on error) for subsequent output. + ConsoleColor mcpOriginalForeGroundColor = Console.ForegroundColor; + ConsoleColor mcpOriginalBackGroundColor = Console.BackgroundColor; + try + { + Console.ForegroundColor = _logLevelToForeGroundConsoleColorMap.GetValueOrDefault(logLevel, ConsoleColor.White); + Console.BackgroundColor = _logLevelToBackGroundConsoleColorMap.GetValueOrDefault(logLevel, ConsoleColor.Black); + Console.Error.Write($"{mcpAbbreviation}:"); + } + finally + { + Console.ForegroundColor = mcpOriginalForeGroundColor; + Console.BackgroundColor = mcpOriginalBackGroundColor; + } + + Console.Error.WriteLine($" {formatter(state, exception)}"); return; } @@ -131,13 +153,22 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except } TextWriter writer = logLevel >= LogLevel.Error ? Console.Error : Console.Out; + // try/finally guarantees the original colors are restored even if Write throws, + // otherwise the console would be left tinted (e.g. red on error) for subsequent output. ConsoleColor originalForeGroundColor = Console.ForegroundColor; ConsoleColor originalBackGroundColor = Console.BackgroundColor; - Console.ForegroundColor = _logLevelToForeGroundConsoleColorMap.GetValueOrDefault(logLevel, ConsoleColor.White); - Console.BackgroundColor = _logLevelToBackGroundConsoleColorMap.GetValueOrDefault(logLevel, ConsoleColor.Black); - writer.Write($"{abbreviation}:"); - Console.ForegroundColor = originalForeGroundColor; - Console.BackgroundColor = originalBackGroundColor; + try + { + Console.ForegroundColor = _logLevelToForeGroundConsoleColorMap.GetValueOrDefault(logLevel, ConsoleColor.White); + Console.BackgroundColor = _logLevelToBackGroundConsoleColorMap.GetValueOrDefault(logLevel, ConsoleColor.Black); + writer.Write($"{abbreviation}:"); + } + finally + { + Console.ForegroundColor = originalForeGroundColor; + Console.BackgroundColor = originalBackGroundColor; + } + writer.WriteLine($" {formatter(state, exception)}"); } diff --git a/src/Cli/Program.cs b/src/Cli/Program.cs index 4783c2292b..6eb89c60d8 100644 --- a/src/Cli/Program.cs +++ b/src/Cli/Program.cs @@ -62,7 +62,7 @@ private static void ParseEarlyFlags(string[] args) } else if (string.Equals(arg, "--LogLevel", StringComparison.OrdinalIgnoreCase) && i + 1 < args.Length) { - Utils.IsLogLevelOverriddenByCli = true; + Utils.IsCliOverriding = true; if (Enum.TryParse(args[i + 1], ignoreCase: true, out LogLevel cliLogLevel)) { Utils.CliLogLevel = cliLogLevel; diff --git a/src/Cli/Utils.cs b/src/Cli/Utils.cs index 1f9ef6d282..8f309407a8 100644 --- a/src/Cli/Utils.cs +++ b/src/Cli/Utils.cs @@ -29,17 +29,30 @@ public class Utils public static bool IsMcpStdioMode { get; set; } /// - /// When true, user explicitly set --LogLevel via CLI (even in MCP mode). + /// When true, the CLI is the source overriding the log level (i.e., --LogLevel was supplied). /// This allows logs to be written to stderr instead of being completely suppressed. /// - public static bool IsLogLevelOverriddenByCli { get; set; } + public static bool IsCliOverriding { get; set; } /// /// The log level specified via CLI --LogLevel flag. - /// Only valid when IsLogLevelOverriddenByCli is true. + /// Only valid when IsCliOverriding is true. /// public static LogLevel CliLogLevel { get; set; } = LogLevel.Information; + /// + /// When true, the runtime config is the source overriding the log level + /// (i.e., runtime.telemetry.log-level was explicitly set). + /// This allows CLI logs to be written to stderr in MCP mode even when no --LogLevel flag was provided. + /// + public static bool IsConfigOverriding { get; set; } + + /// + /// The log level specified via runtime config file's log-level setting. + /// Only valid when IsConfigOverriding is true. + /// + public static LogLevel ConfigLogLevel { get; set; } = LogLevel.Information; + #pragma warning disable CS8618 // Non-nullable field must contain a non-null value when exiting constructor. Consider declaring as nullable. private static ILogger _logger; #pragma warning restore CS8618 diff --git a/src/Config/DatabasePrimitives/DatabaseObject.cs b/src/Config/DatabasePrimitives/DatabaseObject.cs index 9548eda1ba..ea270723ef 100644 --- a/src/Config/DatabasePrimitives/DatabaseObject.cs +++ b/src/Config/DatabasePrimitives/DatabaseObject.cs @@ -133,7 +133,7 @@ public class StoredProcedureDefinition : SourceDefinition public class ParameterDefinition { public string Name { get; set; } = null!; - public bool? Required { get; set; } = false; + public bool? Required { get; set; } public string? Default { get; set; } public string? Description { get; set; } public Type SystemType { get; set; } = null!; diff --git a/src/Config/ObjectModel/ParameterMetadata.cs b/src/Config/ObjectModel/ParameterMetadata.cs index 334979d728..e464262016 100644 --- a/src/Config/ObjectModel/ParameterMetadata.cs +++ b/src/Config/ObjectModel/ParameterMetadata.cs @@ -18,7 +18,7 @@ public class ParameterMetadata /// /// Gets or sets a value indicating whether the parameter is required. /// - public bool Required { get; set; } + public bool? Required { get; set; } /// /// Gets or sets the default value of the parameter, if any. diff --git a/src/Core/Telemetry/ILogLevelController.cs b/src/Core/Telemetry/ILogLevelController.cs index f67424b155..8a8ff0d673 100644 --- a/src/Core/Telemetry/ILogLevelController.cs +++ b/src/Core/Telemetry/ILogLevelController.cs @@ -11,27 +11,36 @@ namespace Azure.DataApiBuilder.Core.Telemetry public interface ILogLevelController { /// - /// Gets a value indicating whether the log level was overridden by CLI arguments. - /// When true, MCP and config-based log level changes are ignored. + /// Gets a value indicating whether the CLI is the source overriding the log level + /// (i.e., --LogLevel was supplied). When true, runtime-config (hot-reload) + /// updates are ignored. /// - bool IsCliOverridden { get; } + bool IsCliOverriding { get; } /// - /// Gets a value indicating whether the log level was explicitly set in the config file. - /// When true along with IsCliOverridden being false, MCP log level changes are ignored. + /// Gets a value indicating whether the runtime config is the source overriding the log + /// level (i.e., runtime.telemetry.log-level was explicitly set). /// - bool IsConfigOverridden { get; } + bool IsConfigOverriding { get; } + + /// + /// Gets a value indicating whether the agent is the source overriding the log level via + /// an MCP logging/setLevel request. When true, runtime-config (hot-reload) updates + /// are ignored so the agent's choice remains in effect. + /// + bool IsAgentOverriding { get; } /// /// Updates the log level from an MCP logging/setLevel request. /// The MCP level string is mapped to the appropriate LogLevel. - /// Log level precedence (highest to lowest): - /// 1. CLI --LogLevel flag (IsCliOverridden = true) - /// 2. Config runtime.telemetry.log-level (IsConfigOverridden = true) - /// 3. MCP logging/setLevel (only works if neither CLI nor Config set a level) + /// Log-level precedence (highest to lowest): + /// 1. Agent (MCP logging/setLevel) — always wins. + /// 2. CLI --LogLevel flag. + /// 3. Config runtime.telemetry.log-level. + /// 4. Defaults. /// /// The MCP log level string (e.g., "debug", "info", "warning", "error"). - /// True if the level was changed; false if CLI or Config override prevented the change. + /// True if the level was changed; false if the input was an unrecognized level. bool UpdateFromMcp(string mcpLevel); } } diff --git a/src/Service.Tests/Mcp/DescribeEntitiesFilteringTests.cs b/src/Service.Tests/Mcp/DescribeEntitiesFilteringTests.cs index 3defc34bba..9d76adf539 100644 --- a/src/Service.Tests/Mcp/DescribeEntitiesFilteringTests.cs +++ b/src/Service.Tests/Mcp/DescribeEntitiesFilteringTests.cs @@ -8,9 +8,12 @@ using System.Threading; using System.Threading.Tasks; using Azure.DataApiBuilder.Auth; +using Azure.DataApiBuilder.Config.DatabasePrimitives; using Azure.DataApiBuilder.Config.ObjectModel; using Azure.DataApiBuilder.Core.Authorization; using Azure.DataApiBuilder.Core.Configurations; +using Azure.DataApiBuilder.Core.Services; +using Azure.DataApiBuilder.Core.Services.MetadataProviders; using Azure.DataApiBuilder.Mcp.BuiltInTools; using Microsoft.AspNetCore.Http; using Microsoft.Extensions.DependencyInjection; @@ -474,12 +477,54 @@ private static IServiceProvider CreateServiceProvider(RuntimeConfig config) mockHttpContextAccessor.Setup(x => x.HttpContext).Returns(mockHttpContext.Object); services.AddSingleton(mockHttpContextAccessor.Object); + // Register a stub IMetadataProviderFactory that returns a populated DatabaseStoredProcedure + // for every stored-procedure entity in the config. DescribeEntitiesTool requires DB metadata + // for SP entities (an init invariant); these filtering tests only exercise the filter logic, + // so an empty-parameter populated entry is enough to satisfy the invariant without affecting + // what is being tested. + RegisterStubMetadataProvider(services, config); + // Add logging services.AddLogging(); return services.BuildServiceProvider(); } + /// + /// Registers a stub that exposes a populated + /// (with an empty + /// dictionary) for every stored-procedure entity in . Mirrors the production + /// invariant that init populates DB metadata for every SP entity before describe_entities runs. + /// + private static void RegisterStubMetadataProvider(ServiceCollection services, RuntimeConfig config) + { + Dictionary entityMap = new(); + foreach (KeyValuePair entry in config.Entities) + { + if (entry.Value.Source.Type == EntitySourceType.StoredProcedure) + { + entityMap[entry.Key] = new DatabaseStoredProcedure(schemaName: "dbo", tableName: entry.Value.Source.Object) + { + SourceType = EntitySourceType.StoredProcedure, + StoredProcedureDefinition = new StoredProcedureDefinition + { + Parameters = new Dictionary() + } + }; + } + } + + Mock mockSqlMetadataProvider = new(); + mockSqlMetadataProvider.Setup(x => x.EntityToDatabaseObject).Returns(entityMap); + mockSqlMetadataProvider.Setup(x => x.GetDatabaseType()).Returns(DatabaseType.MSSQL); + + Mock mockMetadataProviderFactory = new(); + mockMetadataProviderFactory + .Setup(x => x.GetMetadataProvider(It.IsAny())) + .Returns(mockSqlMetadataProvider.Object); + services.AddSingleton(mockMetadataProviderFactory.Object); + } + /// /// Extracts and parses the JSON content from an MCP tool call result. /// Returns the root JsonElement for assertion purposes. diff --git a/src/Service.Tests/Mcp/DescribeEntitiesStoredProcedureParametersMsSqlIntegrationTests.cs b/src/Service.Tests/Mcp/DescribeEntitiesStoredProcedureParametersMsSqlIntegrationTests.cs new file mode 100644 index 0000000000..ef3fcf7816 --- /dev/null +++ b/src/Service.Tests/Mcp/DescribeEntitiesStoredProcedureParametersMsSqlIntegrationTests.cs @@ -0,0 +1,361 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. + +using System; +using System.Collections.Generic; +using System.Linq; +using System.Text.Json; +using System.Threading; +using System.Threading.Tasks; +using Azure.DataApiBuilder.Config.ObjectModel; +using Azure.DataApiBuilder.Core.Authorization; +using Azure.DataApiBuilder.Core.Configurations; +using Azure.DataApiBuilder.Core.Services.MetadataProviders; +using Azure.DataApiBuilder.Mcp.BuiltInTools; +using Azure.DataApiBuilder.Service.Exceptions; +using Azure.DataApiBuilder.Service.Tests.SqlTests; +using Microsoft.AspNetCore.Http; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.VisualStudio.TestTools.UnitTesting; +using ModelContextProtocol.Protocol; +using Moq; + +namespace Azure.DataApiBuilder.Service.Tests.Mcp +{ + /// + /// Integration tests for DescribeEntitiesTool's stored-procedure parameter projection. + /// Verifies the end-to-end behavior: + /// The actual merge of config-side ParameterMetadata onto DB-introspected + /// ParameterDefinitions, performed by + /// . + /// + /// Scenarios (reuse SPs already defined in DatabaseSchema-MsSql.sql / dab-config.MsSql.json): + /// - GetBooks -> SP get_books, zero DB params, no config overrides. + /// - GetBook -> SP get_book_by_id @id int, no config overrides. + /// - InsertBook -> SP insert_book @title, @publisher_id, config sets + /// both to required=false with defaults. + /// - Negative path -> a config that declares an SP parameter the DB does not + /// have must fail at InitializeAsync, which is the + /// load-bearing invariant DescribeEntitiesTool relies on + /// (it no longer carries a config-only fallback path). + /// + [TestClass, TestCategory(TestCategory.MSSQL)] + public class DescribeEntitiesStoredProcedureParametersMsSqlIntegrationTests : SqlTestBase + { + // The base config is captured once at ClassInitialize so test methods do not + // depend on the ASP_NETCORE_ENVIRONMENT variable still being set when they run + // (other test classes may unset it). + private static RuntimeConfig _baseConfig; + + [ClassInitialize] + public static async Task SetupAsync(TestContext context) + { + DatabaseEngine = TestCategory.MSSQL; + await InitializeTestFixture(); + _baseConfig = SqlTestHelper.SetupRuntimeConfig(); + } + + /// + /// SP with zero parameters in the DB and no config-side parameters projects an empty array. + /// + [TestMethod] + public async Task DescribeEntities_StoredProcedureWithNoDbOrConfigParameters_EmitsEmptyParametersArray() + { + JsonElement parameters = await DescribeEntityParametersAsync("GetBooks"); + + Assert.AreEqual(JsonValueKind.Array, parameters.ValueKind); + Assert.AreEqual(0, parameters.GetArrayLength()); + } + + /// + /// SP with one DB parameter and no config-side override: name comes from the DB, + /// required defaults to true, default is null, description is empty. + /// + [TestMethod] + public async Task DescribeEntities_DbParameterWithoutConfigOverride_DefaultsToRequiredTrue() + { + JsonElement parameters = await DescribeEntityParametersAsync("GetBook"); + + Assert.AreEqual(1, parameters.GetArrayLength()); + AssertParameter(parameters, name: "id", expectedRequired: true, expectedDefault: null, expectedDescription: string.Empty); + } + + /// + /// SP with two DB parameters and matching config-side overrides: each parameter's + /// required / default values come from config; name still comes from the DB. + /// This is the scenario that exercises the upstream merge end-to-end. + /// + [TestMethod] + public async Task DescribeEntities_DbParametersWithConfigOverrides_MergesConfigValuesOntoDbParameters() + { + JsonElement parameters = await DescribeEntityParametersAsync("InsertBook"); + + Assert.AreEqual(2, parameters.GetArrayLength()); + AssertParameter(parameters, name: "title", expectedRequired: false, expectedDefault: "randomX", expectedDescription: string.Empty); + AssertParameter(parameters, name: "publisher_id", expectedRequired: false, expectedDefault: "1234", expectedDescription: string.Empty); + } + + /// + /// Mixed merge: an SP has two DB parameters but the config only overrides one of them. + /// The overridden param ('id') must reflect the config-side required/default; the + /// non-overridden param ('title') must fall back to the merge defaults + /// (required=true, default=null). This exercises the per-parameter branch in + /// FillSchemaForStoredProcedureAsync that only applies overrides when the + /// config-side entry exists for that name. + /// + /// The shared config already declares overrides for both parameters of + /// UpdateBookTitle, so we rebuild a fresh metadata provider against a tampered + /// config that keeps only the 'id' override, then restore the shared provider at the + /// end so subsequent tests are unaffected. + /// + [TestMethod] + public async Task DescribeEntities_PartialConfigOverride_MergesOverriddenParamAndDefaultsTheOther() + { + RuntimeConfig baseConfig = _baseConfig; + + const string EntityName = "UpdateBookTitlePartial"; + Entity tamperedEntity = new( + Source: new( + "update_book_title", + EntitySourceType.StoredProcedure, + Parameters: new List + { + // Only 'id' carries a config-side override; 'title' is intentionally + // omitted so the merge must default it to required=true, default=null. + new() { Name = "id", Required = false, Default = "42" } + }, + KeyFields: null), + GraphQL: new(EntityName, EntityName, Enabled: false), + Rest: new(Enabled: false), + Fields: null, + Permissions: new[] + { + new EntityPermission( + Role: "anonymous", + Actions: new[] + { + new EntityAction(Action: EntityActionOperation.Execute, Fields: null, Policy: null) + }) + }, + Relationships: null, + Mappings: null, + Mcp: null); + + // Drop the original UpdateBookTitle entity from the rebuilt config so it does not + // race with the tampered one for the same underlying SP. + Dictionary entityMap = baseConfig.Entities.Entities + .Where(kvp => kvp.Key != "UpdateBookTitle") + .ToDictionary(kvp => kvp.Key, kvp => kvp.Value); + entityMap[EntityName] = tamperedEntity; + RuntimeConfig tamperedConfig = baseConfig with { Entities = new(entityMap) }; + + // Rebuild the shared metadata provider against the tampered config and re-init. + RuntimeConfigProvider tamperedProvider = TestHelper.GenerateInMemoryRuntimeConfigProvider(tamperedConfig); + SetUpSQLMetadataProvider(tamperedProvider); + await _sqlMetadataProvider.InitializeAsync(); + + // Refresh the metadata-provider factory mock so DescribeEntitiesTool sees the + // tampered provider through the standard service-provider wiring. + _metadataProviderFactory = new Mock(); + _metadataProviderFactory.Setup(x => x.GetMetadataProvider(It.IsAny())).Returns(_sqlMetadataProvider); + + try + { + JsonElement parameters = await DescribeEntityParametersAsync(EntityName, tamperedConfig); + + Assert.AreEqual(2, parameters.GetArrayLength()); + AssertParameter(parameters, name: "id", expectedRequired: false, expectedDefault: "42", expectedDescription: string.Empty); + AssertParameter(parameters, name: "title", expectedRequired: true, expectedDefault: null, expectedDescription: string.Empty); + } + finally + { + // Restore the shared fixture's provider/factory so subsequent tests are unaffected. + RuntimeConfigProvider sharedProvider = TestHelper.GenerateInMemoryRuntimeConfigProvider(baseConfig); + SetUpSQLMetadataProvider(sharedProvider); + await _sqlMetadataProvider.InitializeAsync(); + _metadataProviderFactory = new Mock(); + _metadataProviderFactory.Setup(x => x.GetMetadataProvider(It.IsAny())).Returns(_sqlMetadataProvider); + } + } + + /// + /// Locks in the invariant that DescribeEntitiesTool relies on: if a config declares an + /// SP parameter that the DB schema does not have, the metadata provider must fail at + /// InitializeAsync time (so describe_entities never reaches a half-merged state). + /// + /// Builds a fresh MsSqlMetadataProvider with a tampered config (an extra + /// bogus_param on a real SP) and asserts that init throws. + /// + [TestMethod] + public async Task SqlMetadataProvider_FailsAtInit_WhenConfigDeclaresParameterNotInDb() + { + RuntimeConfig baseConfig = _baseConfig; + + const string EntityName = "GetBookWithBogusParam"; + Entity tamperedEntity = new( + Source: new( + "get_book_by_id", + EntitySourceType.StoredProcedure, + Parameters: new List + { + new() { Name = "id" }, + // bogus_param is not declared on dbo.get_book_by_id; init must throw. + new() { Name = "bogus_param", Required = false, Default = "x" } + }, + KeyFields: null), + GraphQL: new(EntityName, EntityName, Enabled: false), + Rest: new(Enabled: false), + Fields: null, + Permissions: new[] + { + new EntityPermission( + Role: "anonymous", + Actions: new[] + { + new EntityAction(Action: EntityActionOperation.Execute, Fields: null, Policy: null) + }) + }, + Relationships: null, + Mappings: null, + Mcp: null); + + Dictionary entityMap = new(baseConfig.Entities.Entities) + { + [EntityName] = tamperedEntity + }; + RuntimeConfig tamperedConfig = baseConfig with { Entities = new(entityMap) }; + + // Bootstrap a fresh provider against the tampered config and verify init fails. + RuntimeConfigProvider tamperedProvider = TestHelper.GenerateInMemoryRuntimeConfigProvider(tamperedConfig); + SetUpSQLMetadataProvider(tamperedProvider); + + DataApiBuilderException ex = await Assert.ThrowsExceptionAsync( + () => _sqlMetadataProvider.InitializeAsync()); + + StringAssert.Contains(ex.Message, "bogus_param"); + StringAssert.Contains(ex.Message, "get_book_by_id"); + + // Restore the shared fixture's provider so subsequent tests in the class are unaffected. + RuntimeConfigProvider sharedProvider = TestHelper.GenerateInMemoryRuntimeConfigProvider(baseConfig); + SetUpSQLMetadataProvider(sharedProvider); + await _sqlMetadataProvider.InitializeAsync(); + } + + /// + /// Invokes describe_entities with an entities filter for the given entity and + /// returns its parameters array. Uses the shared fixture's base config by default. + /// + private static Task DescribeEntityParametersAsync(string entityName) => + DescribeEntityParametersAsync(entityName, _baseConfig); + + /// + /// Overload that lets a test inject a tampered config (e.g. for mixed-merge scenarios) + /// so the tool reads from that config while still using the shared metadata-provider + /// factory mock (which the caller is expected to have refreshed against the same config). + /// + private static async Task DescribeEntityParametersAsync(string entityName, RuntimeConfig config) + { + IServiceProvider serviceProvider = BuildDescribeEntitiesServiceProvider(config); + DescribeEntitiesTool tool = new(); + + string argsJson = JsonSerializer.Serialize(new { entities = new[] { entityName } }); + using JsonDocument arguments = JsonDocument.Parse(argsJson); + + CallToolResult result = await tool.ExecuteAsync(arguments, serviceProvider, CancellationToken.None); + + Assert.IsTrue(result.IsError == false || result.IsError == null, + $"describe_entities returned an error for entity '{entityName}'. Content: {SerializeFirstContent(result)}"); + + return GetEntityParameters(result, entityName); + } + + /// + /// Builds a service provider that wires DescribeEntitiesTool to the shared fixture's + /// real (already initialized against + /// the live database by ) and the real + /// authorization resolver, with a real carrying the + /// anonymous role header. + /// + private static IServiceProvider BuildDescribeEntitiesServiceProvider(RuntimeConfig config) + { + ServiceCollection services = new(); + + // Real RuntimeConfigProvider populated from the provided config snapshot. + RuntimeConfigProvider configProvider = TestHelper.GenerateInMemoryRuntimeConfigProvider(config); + services.AddSingleton(configProvider); + + // Real metadata-provider factory backed by the shared fixture's live provider. + services.AddSingleton(_metadataProviderFactory.Object); + + // Real authorization resolver wired by SqlTestBase against the live config + provider. + services.AddSingleton(_authorizationResolver); + + // Real HttpContext carrying the anonymous role header that DescribeEntitiesTool reads. + DefaultHttpContext httpContext = new(); + httpContext.Request.Headers[AuthorizationResolver.CLIENT_ROLE_HEADER] = AuthorizationResolver.ROLE_ANONYMOUS; + IHttpContextAccessor httpContextAccessor = new HttpContextAccessor { HttpContext = httpContext }; + services.AddSingleton(httpContextAccessor); + + services.AddLogging(); + + return services.BuildServiceProvider(); + } + + private static JsonElement GetEntityParameters(CallToolResult result, string entityName) + { + Assert.IsNotNull(result.Content); + Assert.IsTrue(result.Content.Count > 0); + Assert.IsInstanceOfType(result.Content[0], typeof(TextContentBlock)); + + TextContentBlock firstContent = (TextContentBlock)result.Content[0]; + JsonElement root = JsonDocument.Parse(firstContent.Text).RootElement; + JsonElement entities = root.GetProperty("entities"); + + JsonElement entity = entities.EnumerateArray().Single(e => + string.Equals(e.GetProperty("name").GetString(), entityName, StringComparison.Ordinal)); + + return entity.GetProperty("parameters"); + } + + private static string SerializeFirstContent(CallToolResult result) + { + if (result.Content is null || result.Content.Count == 0) + { + return ""; + } + + return result.Content[0] is TextContentBlock textBlock + ? textBlock.Text ?? string.Empty + : result.Content[0].GetType().Name; + } + + private static void AssertParameter( + JsonElement parameters, + string name, + bool expectedRequired, + string expectedDefault, + string expectedDescription) + { + JsonElement param = parameters.EnumerateArray() + .Single(p => p.GetProperty("name").GetString() == name); + + Assert.AreEqual(expectedRequired, param.GetProperty("required").GetBoolean(), + $"required mismatch for parameter '{name}'."); + + JsonElement defaultElement = param.GetProperty("default"); + if (expectedDefault is null) + { + Assert.AreEqual(JsonValueKind.Null, defaultElement.ValueKind, + $"default should be JSON null for parameter '{name}'."); + } + else + { + Assert.AreEqual(expectedDefault, defaultElement.GetString(), + $"default mismatch for parameter '{name}'."); + } + + Assert.AreEqual(expectedDescription, param.GetProperty("description").GetString(), + $"description mismatch for parameter '{name}'."); + } + } +} diff --git a/src/Service.Tests/Mcp/DescribeEntitiesStoredProcedureParametersTests.cs b/src/Service.Tests/Mcp/DescribeEntitiesStoredProcedureParametersTests.cs new file mode 100644 index 0000000000..8e28e75e89 --- /dev/null +++ b/src/Service.Tests/Mcp/DescribeEntitiesStoredProcedureParametersTests.cs @@ -0,0 +1,292 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. + +using System; +using System.Collections.Generic; +using System.Linq; +using System.Text.Json; +using System.Threading; +using System.Threading.Tasks; +using Azure.DataApiBuilder.Auth; +using Azure.DataApiBuilder.Config.DatabasePrimitives; +using Azure.DataApiBuilder.Config.ObjectModel; +using Azure.DataApiBuilder.Core.Authorization; +using Azure.DataApiBuilder.Core.Configurations; +using Azure.DataApiBuilder.Core.Services; +using Azure.DataApiBuilder.Core.Services.MetadataProviders; +using Azure.DataApiBuilder.Mcp.BuiltInTools; +using Microsoft.AspNetCore.Http; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.VisualStudio.TestTools.UnitTesting; +using ModelContextProtocol.Protocol; +using Moq; + +namespace Azure.DataApiBuilder.Service.Tests.Mcp +{ + /// + /// Tests how DescribeEntitiesTool merges stored-procedure parameter info from the DB and the config. + /// See for the rules. + /// + [TestClass] + public class DescribeEntitiesStoredProcedureParametersTests + { + private const string TEST_ENTITY_NAME = "GetBook"; + + /// + /// When the upstream merge has copied config values onto some parameters but left others + /// untouched, both shapes project correctly side-by-side. This single test exercises + /// both the "override applied" branch (id) and the "no override -> defaults" branch + /// (tenant) of . + /// + [TestMethod] + public async Task DescribeEntities_MixedConfiguredAndUnconfiguredParameters_ProjectsBoth() + { + JsonElement parameters = await RunWithMergedDbParametersAsync( + new Dictionary + { + // id: upstream merge wrote config values onto the ParameterDefinition. + ["id"] = new() { Required = true, Default = "42", Description = "Config description" }, + // tenant: not in config, so the upstream merge left ParameterDefinition untouched. + ["tenant"] = new() + }); + + Assert.AreEqual(2, parameters.GetArrayLength()); + AssertParameter(parameters, name: "id", expectedRequired: true, expectedDefault: "42", expectedDescription: "Config description"); + AssertParameter(parameters, name: "tenant", expectedRequired: true, expectedDefault: null, expectedDescription: string.Empty); + } + + /// + /// An explicit Required=false written onto the ParameterDefinition by the upstream merge + /// is honored both when a Default value is supplied and when it is not. + /// + [DataTestMethod] + [DataRow("en-US", DisplayName = "WithDefault")] + [DataRow(null, DisplayName = "WithoutDefault")] + public async Task DescribeEntities_ExplicitRequiredFalse_IsHonored(string expectedDefault) + { + JsonElement parameters = await RunWithMergedDbParametersAsync( + new Dictionary + { + ["locale"] = new() { Required = false, Default = expectedDefault, Description = "Locale override" } + }); + + Assert.AreEqual(1, parameters.GetArrayLength()); + AssertParameter(parameters, name: "locale", expectedRequired: false, expectedDefault: expectedDefault, expectedDescription: "Locale override"); + } + + // ---------------------------------------------------------------------------------- + // Invariant-violation test. + // + // BuildParameterMetadataInfo trusts the upstream invariant: for any successfully + // initialized stored-procedure entity, the metadata provider has a populated + // DatabaseStoredProcedure. SqlMetadataProvider.FillSchemaForStoredProcedureAsync + // throws via HandleOrRecordException (aborting startup in non-validate mode) if it + // can't populate that schema, so describe_entities never runs against a null/missing + // SP metadata entry in production. + // + // If that invariant ever regresses we throw instead of fabricating empty parameter + // info: returning an SP with parameters=[] would lie to the agent (it can't tell + // "genuinely zero params" apart from "we don't know"). The surrounding per-entity + // catch in DescribeEntitiesTool logs the failure and drops just that entity from the + // response. The test below exercises that path. + // ---------------------------------------------------------------------------------- + + /// + /// When DB metadata is missing for an SP entity, the tool drops the entity from the + /// response rather than returning it with an empty parameters array. + /// + [TestMethod] + public async Task DescribeEntities_DropsEntity_WhenStoredProcedureMetadataIsMissing() + { + RuntimeConfig config = CreateRuntimeConfig(CreateStoredProcedureEntity()); + ServiceCollection services = new(); + RegisterCommonServices(services, config); + // Register metadata provider with no entry for the SP entity. + RegisterMetadataProvider(services, TEST_ENTITY_NAME, dbObject: null); + + IServiceProvider serviceProvider = services.BuildServiceProvider(); + DescribeEntitiesTool tool = new(); + + CallToolResult result = await tool.ExecuteAsync(null, serviceProvider, CancellationToken.None); + + // The only configured entity was dropped, so the tool returns the "no entities" + // error result rather than a successful response containing a misleading entry. + Assert.IsTrue(result.IsError == true, "Expected an error result when the only entity is dropped."); + Assert.IsNotNull(result.Content); + Assert.IsInstanceOfType(result.Content[0], typeof(TextContentBlock)); + string responseText = ((TextContentBlock)result.Content[0]).Text; + StringAssert.Contains(responseText, "NoEntitiesConfigured"); + } + + /// + /// Runs DescribeEntitiesTool against an entity whose DB metadata is already populated. + /// The dictionary represents the state of + /// AFTER the upstream merge in SqlMetadataProvider/MsSqlMetadataProvider has run. + /// + private static Task RunWithMergedDbParametersAsync( + Dictionary mergedDbParameters) + => RunDescribeCoreAsync(dbParameters: mergedDbParameters); + + /// + /// Sets up DI, runs DescribeEntitiesTool, and returns the parameters array of the one entity. + /// + private static async Task RunDescribeCoreAsync( + Dictionary dbParameters) + { + RuntimeConfig config = CreateRuntimeConfig(CreateStoredProcedureEntity()); + ServiceCollection services = new(); + RegisterCommonServices(services, config); + + DatabaseObject dbObject = CreateStoredProcedureObject("dbo", "get_book", dbParameters); + RegisterMetadataProvider(services, TEST_ENTITY_NAME, dbObject); + + IServiceProvider serviceProvider = services.BuildServiceProvider(); + DescribeEntitiesTool tool = new(); + + CallToolResult result = await tool.ExecuteAsync(null, serviceProvider, CancellationToken.None); + Assert.IsTrue(result.IsError == false || result.IsError == null); + + JsonElement entity = GetSingleEntityFromResult(result); + return entity.GetProperty("parameters"); + } + + /// + /// Checks that one parameter in the JSON array has the expected required, default, and description. + /// + /// Expected default value, or null to assert the JSON value is null. + private static void AssertParameter( + JsonElement parameters, + string name, + bool expectedRequired, + string expectedDefault, + string expectedDescription) + { + JsonElement param = parameters.EnumerateArray().Single(p => p.GetProperty("name").GetString() == name); + + Assert.AreEqual(expectedRequired, param.GetProperty("required").GetBoolean(), $"required mismatch for parameter '{name}'."); + + JsonElement defaultElement = param.GetProperty("default"); + if (expectedDefault is null) + { + Assert.AreEqual(JsonValueKind.Null, defaultElement.ValueKind, $"default should be JSON null for parameter '{name}'."); + } + else + { + Assert.AreEqual(expectedDefault, defaultElement.GetString(), $"default mismatch for parameter '{name}'."); + } + + Assert.AreEqual(expectedDescription, param.GetProperty("description").GetString(), $"description mismatch for parameter '{name}'."); + } + + private static RuntimeConfig CreateRuntimeConfig(Entity storedProcedureEntity) + { + Dictionary entities = new() + { + [TEST_ENTITY_NAME] = storedProcedureEntity + }; + + return new RuntimeConfig( + Schema: "test-schema", + DataSource: new DataSource(DatabaseType: DatabaseType.MSSQL, ConnectionString: "", Options: null), + Runtime: new( + Rest: new(), + GraphQL: new(), + Mcp: new(Enabled: true, Path: "/mcp", DmlTools: null), + Host: new(Cors: null, Authentication: null, Mode: HostMode.Development) + ), + Entities: new(entities) + ); + } + + private static Entity CreateStoredProcedureEntity() + { + return new Entity( + Source: new("get_book", EntitySourceType.StoredProcedure, Parameters: null, KeyFields: null), + GraphQL: new(TEST_ENTITY_NAME, TEST_ENTITY_NAME), + Rest: new(Enabled: true), + Fields: null, + Permissions: new[] + { + new EntityPermission( + Role: "anonymous", + Actions: new[] + { + new EntityAction(Action: EntityActionOperation.Execute, Fields: null, Policy: null) + }) + }, + Relationships: null, + Mappings: null, + Mcp: null + ); + } + + private static DatabaseStoredProcedure CreateStoredProcedureObject( + string schema, + string name, + Dictionary parameters) + { + return new DatabaseStoredProcedure(schema, name) + { + SourceType = EntitySourceType.StoredProcedure, + StoredProcedureDefinition = new StoredProcedureDefinition + { + Parameters = parameters + } + }; + } + + private static void RegisterCommonServices(ServiceCollection services, RuntimeConfig config) + { + RuntimeConfigProvider configProvider = TestHelper.GenerateInMemoryRuntimeConfigProvider(config); + services.AddSingleton(configProvider); + + Mock mockAuthResolver = new(); + mockAuthResolver.Setup(x => x.IsValidRoleContext(It.IsAny())).Returns(true); + services.AddSingleton(mockAuthResolver.Object); + + Mock mockHttpContext = new(); + Mock mockRequest = new(); + mockRequest.Setup(x => x.Headers[AuthorizationResolver.CLIENT_ROLE_HEADER]).Returns("anonymous"); + mockHttpContext.Setup(x => x.Request).Returns(mockRequest.Object); + + Mock mockHttpContextAccessor = new(); + mockHttpContextAccessor.Setup(x => x.HttpContext).Returns(mockHttpContext.Object); + services.AddSingleton(mockHttpContextAccessor.Object); + + services.AddLogging(); + } + + /// + /// Registers a mock metadata provider. If is null, the provider has + /// no entry for the entity (simulates DB metadata not available). + /// + private static void RegisterMetadataProvider(ServiceCollection services, string entityName, DatabaseObject dbObject) + { + Dictionary entityMap = dbObject is null + ? new Dictionary() + : new Dictionary { [entityName] = dbObject }; + + Mock mockSqlMetadataProvider = new(); + mockSqlMetadataProvider.Setup(x => x.EntityToDatabaseObject).Returns(entityMap); + mockSqlMetadataProvider.Setup(x => x.GetDatabaseType()).Returns(DatabaseType.MSSQL); + + Mock mockMetadataProviderFactory = new(); + mockMetadataProviderFactory.Setup(x => x.GetMetadataProvider(It.IsAny())).Returns(mockSqlMetadataProvider.Object); + services.AddSingleton(mockMetadataProviderFactory.Object); + } + + private static JsonElement GetSingleEntityFromResult(CallToolResult result) + { + Assert.IsNotNull(result.Content); + Assert.IsTrue(result.Content.Count > 0); + Assert.IsInstanceOfType(result.Content[0], typeof(TextContentBlock)); + + TextContentBlock firstContent = (TextContentBlock)result.Content[0]; + JsonElement root = JsonDocument.Parse(firstContent.Text).RootElement; + JsonElement entities = root.GetProperty("entities"); + + Assert.AreEqual(1, entities.GetArrayLength()); + return entities.EnumerateArray().First(); + } + } +} diff --git a/src/Service.Tests/UnitTests/DynamicLogLevelProviderTests.cs b/src/Service.Tests/UnitTests/DynamicLogLevelProviderTests.cs index 779277c2b5..c74963778e 100644 --- a/src/Service.Tests/UnitTests/DynamicLogLevelProviderTests.cs +++ b/src/Service.Tests/UnitTests/DynamicLogLevelProviderTests.cs @@ -3,7 +3,9 @@ #nullable enable +using System.Collections.Generic; using System.Threading.Tasks; +using Azure.DataApiBuilder.Config.ObjectModel; using Azure.DataApiBuilder.Service.Telemetry; using Microsoft.Extensions.Logging; using Microsoft.VisualStudio.TestTools.UnitTesting; @@ -12,27 +14,28 @@ namespace Azure.DataApiBuilder.Service.Tests.UnitTests { /// /// Unit tests for the DynamicLogLevelProvider class. - /// Tests the MCP logging/setLevel support. + /// Locks the runtime log-level precedence: Agent (MCP) > CLI > Config > defaults. /// [TestClass] public class DynamicLogLevelProviderTests { [DataTestMethod] [DataRow(LogLevel.Error, false, false, "debug", true, LogLevel.Debug, DisplayName = "Valid level change succeeds")] - [DataRow(LogLevel.Error, true, false, "debug", false, LogLevel.Error, DisplayName = "CLI override blocks MCP change")] - [DataRow(LogLevel.Warning, false, true, "debug", false, LogLevel.Warning, DisplayName = "Config override blocks MCP change")] - [DataRow(LogLevel.Error, false, false, "invalid", false, LogLevel.Error, DisplayName = "Invalid level returns false")] + [DataRow(LogLevel.Error, true, false, "debug", true, LogLevel.Debug, DisplayName = "Agent overrides CLI")] + [DataRow(LogLevel.Warning, false, true, "debug", true, LogLevel.Debug, DisplayName = "Agent overrides Config")] + [DataRow(LogLevel.Error, true, true, "debug", true, LogLevel.Debug, DisplayName = "Agent overrides CLI + Config")] + [DataRow(LogLevel.Error, false, false, "invalid", false, LogLevel.Error, DisplayName = "Invalid level returns false and leaves level untouched")] public void UpdateFromMcp_ReturnsExpectedResult( LogLevel initialLevel, - bool isCliOverridden, - bool isConfigOverridden, + bool isCliOverriding, + bool isConfigOverriding, string mcpLevel, bool expectedResult, LogLevel expectedFinalLevel) { // Arrange DynamicLogLevelProvider provider = new(); - provider.SetInitialLogLevel(initialLevel, isCliOverridden, isConfigOverridden); + provider.SetInitialLogLevel(initialLevel, isCliOverriding, isConfigOverriding); // Act bool result = provider.UpdateFromMcp(mcpLevel); @@ -40,6 +43,10 @@ public void UpdateFromMcp_ReturnsExpectedResult( // Assert Assert.AreEqual(expectedResult, result); Assert.AreEqual(expectedFinalLevel, provider.CurrentLogLevel); + + // Successful agent updates must flip IsAgentOverriding so hot-reloads of Config + // don't overwrite the agent's choice. + Assert.AreEqual(expectedResult, provider.IsAgentOverriding); } [TestMethod] @@ -47,7 +54,7 @@ public void ShouldLog_ReturnsCorrectResult() { // Arrange DynamicLogLevelProvider provider = new(); - provider.SetInitialLogLevel(LogLevel.Warning, isCliOverridden: false); + provider.SetInitialLogLevel(LogLevel.Warning, isCliOverriding: false); // Assert - logs at or above Warning should pass Assert.IsTrue(provider.ShouldLog(LogLevel.Warning)); @@ -69,7 +76,7 @@ public void UpdateFromMcp_UnderConcurrency_StaysConsistent() { // Arrange DynamicLogLevelProvider provider = new(); - provider.SetInitialLogLevel(LogLevel.Information, isCliOverridden: false, isConfigOverridden: false); + provider.SetInitialLogLevel(LogLevel.Information, isCliOverriding: false, isConfigOverriding: false); const int iterations = 5_000; @@ -113,27 +120,142 @@ public void UpdateFromMcp_UnderConcurrency_StaysConsistent() } /// - /// CLI override is sticky: once the CLI flag pins the level, no number - /// of MCP logging/setLevel requests (even concurrent) may change + /// The agent always wins. Even when the CLI flag has pinned the level, every MCP + /// logging/setLevel call must succeed and update /// . Validates the - /// precedence guarantee under contention. + /// new precedence guarantee under contention. /// [TestMethod] - public void UpdateFromMcp_CliOverride_StaysStickyUnderConcurrency() + public void UpdateFromMcp_AgentAlwaysWins_UnderConcurrency() { // Arrange — CLI pins level to Warning. DynamicLogLevelProvider provider = new(); - provider.SetInitialLogLevel(LogLevel.Warning, isCliOverridden: true, isConfigOverridden: false); + provider.SetInitialLogLevel(LogLevel.Warning, isCliOverriding: true, isConfigOverriding: false); - // Act — flood with MCP setLevel requests trying to flip it. + // Act — flood with MCP setLevel requests; every one must succeed. Parallel.For(0, 2_000, _ => { bool changed = provider.UpdateFromMcp("debug"); - Assert.IsFalse(changed, "CLI override must block all MCP changes."); + Assert.IsTrue(changed, "Agent must override CLI and Config."); }); - // Assert — level never moved off Warning. + // Assert — final level is the agent-set Debug, and the agent flag is set. + Assert.AreEqual(LogLevel.Debug, provider.CurrentLogLevel); + Assert.IsTrue(provider.IsAgentOverriding); + // CLI flag is informational and stays as set by startup; precedence is enforced + // via IsAgentOverriding in UpdateFromRuntimeConfig. + Assert.IsTrue(provider.IsCliOverriding); + } + + /// + /// Hot-reloading the runtime config must not overwrite an agent-set level. After the + /// agent moves the level via , a + /// subsequent with a + /// different config-pinned level must be ignored. + /// + [TestMethod] + public void UpdateFromRuntimeConfig_RespectsAgentOverride() + { + // Arrange — start at Error (no CLI / Config override), agent then asks for Debug. + DynamicLogLevelProvider provider = new(); + provider.SetInitialLogLevel(LogLevel.Error, isCliOverriding: false, isConfigOverriding: false); + Assert.IsTrue(provider.UpdateFromMcp("debug")); + Assert.AreEqual(LogLevel.Debug, provider.CurrentLogLevel); + + // Build a hot-reloaded RuntimeConfig that explicitly pins log-level to Warning. + RuntimeConfig hotReloadedConfig = BuildRuntimeConfigWithLogLevel(LogLevel.Warning); + + // Act — the hot-reload guard must skip applying Warning because the agent already won. + provider.UpdateFromRuntimeConfig(hotReloadedConfig); + + // Assert — agent's Debug survives. + Assert.AreEqual(LogLevel.Debug, provider.CurrentLogLevel); + Assert.IsTrue(provider.IsAgentOverriding); + } + + /// + /// Hot-reloading the runtime config must not overwrite a CLI-set level. The CLI + /// --LogLevel flag is the operator's deliberate startup choice, so a + /// subsequent with a + /// different config-pinned level must be ignored. + /// + [TestMethod] + public void UpdateFromRuntimeConfig_RespectsCliOverride() + { + // Arrange — CLI pins level to Warning at startup; no agent override. + DynamicLogLevelProvider provider = new(); + provider.SetInitialLogLevel(LogLevel.Warning, isCliOverriding: true, isConfigOverriding: false); + + // Build a hot-reloaded RuntimeConfig that explicitly pins log-level to Information. + RuntimeConfig hotReloadedConfig = BuildRuntimeConfigWithLogLevel(LogLevel.Information); + + // Act — the hot-reload guard must skip applying Information because CLI already won. + provider.UpdateFromRuntimeConfig(hotReloadedConfig); + + // Assert — CLI's Warning survives, and IsConfigOverriding is not flipped because + // the hot-reload short-circuited before reading the config's log level. Assert.AreEqual(LogLevel.Warning, provider.CurrentLogLevel); + Assert.IsTrue(provider.IsCliOverriding); + Assert.IsFalse(provider.IsConfigOverriding); + } + + /// + /// Successive agent calls must each succeed and overwrite the previous agent-set level + /// — covering the full range from (most verbose) to + /// (most restrictive). This locks in the sticky + /// behavior of : once the agent + /// has taken control, every subsequent agent call wins, the flag stays set, and no + /// hot-reload of the runtime config can sneak in between calls to silently flip the + /// level back. The MCP spec doesn't define a "none" level, so the strictest valid + /// MCP level "emergency" (which maps to ) is + /// used as the high-end of the range. + /// + [TestMethod] + public void UpdateFromMcp_SuccessiveCalls_OverwriteAndKeepAgentOverriding() + { + // Arrange — start in the "no overrides" state. + DynamicLogLevelProvider provider = new(); + provider.SetInitialLogLevel(LogLevel.Information, isCliOverriding: false, isConfigOverriding: false); + + // Act + Assert — Debug → Critical (verbose to most-restrictive). + Assert.IsTrue(provider.UpdateFromMcp("debug")); + Assert.AreEqual(LogLevel.Debug, provider.CurrentLogLevel); + Assert.IsTrue(provider.IsAgentOverriding); + + Assert.IsTrue(provider.UpdateFromMcp("emergency")); + Assert.AreEqual(LogLevel.Critical, provider.CurrentLogLevel); + Assert.IsTrue(provider.IsAgentOverriding, "Agent override must remain sticky across successive agent calls."); + + // Act + Assert — Critical → Debug (reverse direction). + Assert.IsTrue(provider.UpdateFromMcp("debug")); + Assert.AreEqual(LogLevel.Debug, provider.CurrentLogLevel); + Assert.IsTrue(provider.IsAgentOverriding); + } + + /// + /// Builds a minimal whose + /// runtime.telemetry.log-level dictionary explicitly pins the default level. + /// Used by hot-reload tests; not intended to model a complete production config. + /// + private static RuntimeConfig BuildRuntimeConfigWithLogLevel(LogLevel level) + { + TelemetryOptions telemetry = new( + LoggerLevel: new Dictionary { ["default"] = level }); + + RuntimeOptions runtime = new( + Rest: null, + GraphQL: null, + Mcp: null, + Host: new HostOptions(Cors: null, Authentication: null, Mode: HostMode.Production), + Telemetry: telemetry); + + DataSource dataSource = new(DatabaseType.MSSQL, "Server=tcp:localhost,1433;", Options: null); + + return new RuntimeConfig( + Schema: null, + DataSource: dataSource, + Entities: new RuntimeEntities(new Dictionary()), + Runtime: runtime); } } } diff --git a/src/Service/Program.cs b/src/Service/Program.cs index 2963f5278b..e83dde30c7 100644 --- a/src/Service/Program.cs +++ b/src/Service/Program.cs @@ -98,9 +98,9 @@ public static bool StartEngine(string[] args, bool runMcpStdio, string? mcpRole) // Initialize log level EARLY, before building the host. // This ensures logging filters are effective during the entire host build process. // For MCP mode, we also read the config file early to check for log level override. - LogLevel initialLogLevel = GetLogLevelFromCommandLineArgsOrConfig(args, runMcpStdio, out bool isCliOverridden, out bool isConfigOverridden); + LogLevel initialLogLevel = GetLogLevelFromCommandLineArgsOrConfig(args, runMcpStdio, out bool isCliOverriding, out bool isConfigOverriding); - LogLevelProvider.SetInitialLogLevel(initialLogLevel, isCliOverridden, isConfigOverridden); + LogLevelProvider.SetInitialLogLevel(initialLogLevel, isCliOverriding, isConfigOverriding); // For MCP stdio mode, redirect Console.Out to keep stdout clean for JSON-RPC. // MCP SDK uses Console.OpenStandardOutput() which gets the real stdout, unaffected by this redirect. @@ -212,7 +212,7 @@ public static IHostBuilder CreateHostBuilder(string[] args, bool runMcpStdio, st // LogLevelProvider was already initialized in StartEngine before CreateHostBuilder. // Use the already-set values to avoid re-parsing args. Startup.MinimumLogLevel = LogLevelProvider.CurrentLogLevel; - Startup.IsLogLevelOverriddenByCli = LogLevelProvider.IsCliOverridden; + Startup.IsCliOverriding = LogLevelProvider.IsCliOverriding; ILoggerFactory loggerFactory = GetLoggerFactoryForLogLevel(Startup.MinimumLogLevel, stdio: runMcpStdio); ILogger startupLogger = loggerFactory.CreateLogger(); DisableHttpsRedirectionIfNeeded(args); @@ -229,13 +229,13 @@ public static IHostBuilder CreateHostBuilder(string[] args, bool runMcpStdio, st /// /// Array that may contain log level information. /// Whether running in MCP stdio mode. - /// Sets if log level is found in the args from CLI. - /// Sets if log level is found in the config file (MCP mode only). + /// Set to true if log level is supplied via CLI args. + /// Set to true if log level is supplied via the config file (MCP mode only). /// Appropriate log level. - private static LogLevel GetLogLevelFromCommandLineArgsOrConfig(string[] args, bool runMcpStdio, out bool isLogLevelOverridenByCli, out bool isConfigOverridden) + private static LogLevel GetLogLevelFromCommandLineArgsOrConfig(string[] args, bool runMcpStdio, out bool isCliOverriding, out bool isConfigOverriding) { LogLevel logLevel; - isConfigOverridden = false; + isConfigOverriding = false; // Check if --LogLevel was explicitly specified via CLI (case-insensitive parsing) int logLevelIndex = Array.FindIndex(args, a => string.Equals(a, "--LogLevel", StringComparison.OrdinalIgnoreCase)); @@ -245,12 +245,12 @@ private static LogLevel GetLogLevelFromCommandLineArgsOrConfig(string[] args, bo { // User explicitly set --LogLevel via CLI (highest priority) logLevel = cliLogLevel; - isLogLevelOverridenByCli = true; + isCliOverriding = true; } else if (runMcpStdio) { // MCP stdio mode without explicit --LogLevel: check config for log level (second priority) - isLogLevelOverridenByCli = false; + isCliOverriding = false; logLevel = LogLevel.None; // Default if config doesn't have log level // Find --config or --ConfigFileName argument, or use default dab-config.json @@ -264,7 +264,7 @@ private static LogLevel GetLogLevelFromCommandLineArgsOrConfig(string[] args, bo if (!string.IsNullOrWhiteSpace(configFilePath) && TryGetLogLevelFromConfig(configFilePath, out LogLevel configLogLevel)) { logLevel = configLogLevel; - isConfigOverridden = true; + isConfigOverriding = true; } } else @@ -274,7 +274,7 @@ private static LogLevel GetLogLevelFromCommandLineArgsOrConfig(string[] args, bo // adjust based on config: Debug for Development mode, Error for Production mode. // This initial value is used before config is loaded. logLevel = LogLevel.Error; - isLogLevelOverridenByCli = false; + isCliOverriding = false; } if (logLevel is > LogLevel.None or < LogLevel.Trace) diff --git a/src/Service/Startup.cs b/src/Service/Startup.cs index f4871b0316..b1c5472bf4 100644 --- a/src/Service/Startup.cs +++ b/src/Service/Startup.cs @@ -78,7 +78,7 @@ public class Startup(IConfiguration configuration, ILogger logger) { public static LogLevel MinimumLogLevel = LogLevel.Error; - public static bool IsLogLevelOverriddenByCli; + public static bool IsCliOverriding; public static AzureLogAnalyticsCustomLogCollector CustomLogCollector = new(); public static ApplicationInsightsOptions AppInsightsOptions = new(); @@ -737,6 +737,17 @@ public void Configure(IApplicationBuilder app, IWebHostEnvironment env, RuntimeC bool isRuntimeReady = false; RuntimeConfig? runtimeConfig = null; + // Wire a logger on the DynamicLogLevelProvider as soon as ILoggerFactory is available + // — ahead of any config-load branch — so an early MCP logging/setLevel call (which can + // arrive before runtime config in the late-configured path) still surfaces its audit + // log line through the standard logging pipeline. + DynamicLogLevelProvider? logLevelProviderForAudit = app.ApplicationServices.GetService(); + ILoggerFactory? earlyLoggerFactory = app.ApplicationServices.GetService(); + if (logLevelProviderForAudit is not null && earlyLoggerFactory is not null) + { + logLevelProviderForAudit.Logger = earlyLoggerFactory.CreateLogger(); + } + try { if (runtimeConfigProvider.TryGetConfig(out runtimeConfig)) @@ -951,7 +962,7 @@ private static void EmitPlaceholderSchema(ISchemaBuilder schemaBuilder) /// public static ILoggerFactory CreateLoggerFactoryForHostedAndNonHostedScenario(IServiceProvider serviceProvider, LogLevelInitializer logLevelInitializer) { - if (!IsLogLevelOverriddenByCli) + if (!IsCliOverriding) { // If the log level is not overridden by command line arguments specified through CLI, // attempt to get the runtime config to determine the loglevel based on host.mode. diff --git a/src/Service/Telemetry/DynamicLogLevelProvider.cs b/src/Service/Telemetry/DynamicLogLevelProvider.cs index 8e29086f52..b405caa7f0 100644 --- a/src/Service/Telemetry/DynamicLogLevelProvider.cs +++ b/src/Service/Telemetry/DynamicLogLevelProvider.cs @@ -6,40 +6,69 @@ namespace Azure.DataApiBuilder.Service.Telemetry { /// /// Provides dynamic log level control with support for CLI override, runtime config, and MCP. + /// Precedence (highest to lowest): Agent (MCP) > CLI > Config > defaults. /// public class DynamicLogLevelProvider : ILogLevelController { + /// + /// Guards mutations of and the override flags so + /// concurrent and + /// calls cannot interleave and break the Agent > CLI > Config precedence. + /// + private readonly object _stateLock = new(); + public LogLevel CurrentLogLevel { get; private set; } - public bool IsCliOverridden { get; private set; } + public bool IsCliOverriding { get; private set; } + + public bool IsConfigOverriding { get; private set; } + + public bool IsAgentOverriding { get; private set; } - public bool IsConfigOverridden { get; private set; } + /// + /// Optional logger used to emit an Information line when the agent successfully overrides + /// the log level. Wired by host startup once the logging pipeline is available; safe to + /// leave unset (e.g. in unit tests). + /// + public ILogger? Logger { get; set; } /// - /// Sets the initial log level, which can be passed from the CLI or the Config file, - /// if not specified, it defaults to None if flag --mcp-stdio, to Error if in Production mode or Debug if in Development mode. - /// Also sets whether the log level was overridden by the CLI, which will prevent updates from runtime config changes. + /// Sets the initial log level from CLI args or the config file. When not specified the level + /// defaults to None for --mcp-stdio, Error in Production, or Debug in Development. + /// The CLI/Config flags drive runtime-config hot-reload behavior; they no longer block + /// agent (MCP) overrides — see . /// /// The initial log level to set. - /// Indicates whether the log level was overridden by the CLI. - /// Indicates whether the log level was overridden by the runtime config. - public void SetInitialLogLevel(LogLevel logLevel = LogLevel.Error, bool isCliOverridden = false, bool isConfigOverridden = false) + /// Indicates whether the CLI is overriding the log level. + /// Indicates whether the runtime config is overriding the log level. + public void SetInitialLogLevel(LogLevel logLevel = LogLevel.Error, bool isCliOverriding = false, bool isConfigOverriding = false) { - CurrentLogLevel = logLevel; - IsCliOverridden = isCliOverridden; - IsConfigOverridden = isConfigOverridden; + lock (_stateLock) + { + CurrentLogLevel = logLevel; + IsCliOverriding = isCliOverriding; + IsConfigOverriding = isConfigOverriding; + } } /// - /// Updates the current log level based on the runtime configuration, unless it was overridden by the CLI. + /// Updates the current log level from a runtime-config (hot-reload) change. + /// Skipped when the CLI or the agent has already overridden, so neither is overwritten. /// /// The runtime configuration to use for updating the log level. /// Optional logger filter to apply when determining the log level. public void UpdateFromRuntimeConfig(RuntimeConfig runtimeConfig, string? loggerFilter = null) { - // Only update if CLI didn't override - if (!IsCliOverridden) + lock (_stateLock) { + // Agent override and CLI override both win over a hot-reloaded Config value. + // The check + assignment must be inside the lock so a concurrent UpdateFromMcp + // cannot slip in between the guard and the write. + if (IsAgentOverriding || IsCliOverriding) + { + return; + } + if (loggerFilter is null) { loggerFilter = string.Empty; @@ -47,47 +76,42 @@ public void UpdateFromRuntimeConfig(RuntimeConfig runtimeConfig, string? loggerF CurrentLogLevel = runtimeConfig.GetConfiguredLogLevel(loggerFilter); - // Track if config explicitly set a non-null log level value. - // This ensures MCP logging/setLevel is only blocked when config - // actually pins a log level, not just when the dictionary exists. - IsConfigOverridden = runtimeConfig.HasExplicitLogLevel(); + // Track if config explicitly set a non-null log level value, so callers can + // distinguish a config-pinned level from defaults. + IsConfigOverriding = runtimeConfig.HasExplicitLogLevel(); } } - /// Updates the log level from an MCP logging/setLevel request. - /// Precedence (highest to lowest): - /// 1. CLI --LogLevel flag (IsCliOverridden = true) - /// 2. Config runtime.telemetry.log-level (IsConfigOverridden = true) - /// 3. MCP logging/setLevel - /// - /// If CLI or Config overrode, this method accepts the request silently but does not change the level. + /// + /// Updates the log level from an MCP logging/setLevel request. + /// The agent always wins over CLI and Config; only an unrecognized level is rejected. /// /// The MCP log level string (e.g., "debug", "info", "warning", "error"). - /// True if the level was changed; false if CLI/Config override prevented the change or level was invalid. + /// True if the level was changed; false only if the input was an unrecognized level. public bool UpdateFromMcp(string mcpLevel) { - // If CLI overrode the log level, accept the request but don't change anything. - // This prevents MCP clients from getting errors, but CLI wins. - if (IsCliOverridden) + if (!McpLogLevelConverter.TryConvertFromMcp(mcpLevel, out LogLevel logLevel)) { + // Unknown level - don't change, but don't fail the MCP call either. return false; } - // If Config explicitly set the log level, accept the request but don't change anything. - // Config has second precedence after CLI. - if (IsConfigOverridden) - { - return false; - } - - if (McpLogLevelConverter.TryConvertFromMcp(mcpLevel, out LogLevel logLevel)) + lock (_stateLock) { CurrentLogLevel = logLevel; - return true; + IsAgentOverriding = true; } - // Unknown level - don't change, but don't fail either - return false; + // Surface the override so operators can see the agent moved the level. + // Logged outside the lock so logger sinks can't deadlock with state mutations. + // Emitted at Information and subject to the operator's configured filter, like + // any other log line — the JSON-RPC request/response itself is the protocol-level + // audit, so there's no need to bypass the filter here. + Logger?.LogInformation( + "Log level updated to {LogLevel} via MCP logging/setLevel (agent override).", + logLevel); + + return true; } ///