From 13aba6401f30ae14c5e173867c8143ade553108c Mon Sep 17 00:00:00 2001 From: Anusha Kolan Date: Wed, 13 May 2026 12:24:09 -0700 Subject: [PATCH 1/3] Fix MCP CLI logging: apply colors and respect config log-level (#3508) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## Why make this change? Two bugs were discovered in the CLI logging behavior when running DAB in MCP stdio mode: 1. **Missing colors**: When `start --mcp-stdio --LogLevel ` was used, the CLI's own startup logs (e.g., "Setting minimum LogLevel: Information.") appeared on stderr **without any colors**, while engine logs were properly colored. This created an inconsistent visual experience. 2. **Missing CLI logs with config-only log level**: When `start --mcp-stdio` was used with the `runtime.telemetry.log-level` set in the config file (and no `--LogLevel` CLI flag), CLI startup logs were **completely suppressed**, even though the user had clearly expressed an intent to see logs at that level. ## What is this change? The CLI logger (`CustomLoggerProvider`) only knew about CLI overrides (`--LogLevel`). It never learned that the runtime config file can also explicitly request a log level. As a result: - It defaulted to `LogLevel.None` (suppress all) whenever `--LogLevel` was absent in MCP mode, ignoring the config. - The MCP stderr code path also skipped the foreground/background color formatting that the non-MCP path applied. This change makes the CLI logger aware of both override sources and applies colors consistently in both stdout (non-MCP) and stderr (MCP) paths. ### Modified files: - `src/Cli/Utils.cs` — Added `IsLogLevelOverriddenByConfig` (bool) and `ConfigLogLevel` (LogLevel) static properties. - `src/Cli/ConfigGenerator.cs` — In `TryStartEngineWithOptions()`, sets the new properties when `RuntimeConfig.HasExplicitLogLevel()` is true. - `src/Cli/CustomLoggerProvider.cs`: - Constructor: chooses minimum log level from CLI → Config → None. - `Log()`: suppresses only when **neither** CLI nor config set a level; applies foreground/background colors before writing the abbreviation to stderr in MCP mode. ## How was this tested? Manually tested all combinations of MCP / non-MCP × CLI override / config override / no override: | # | Scenario | Expected | Result | |---|----------|----------|--------| | 1 | MCP, no flags, no config log-level | No CLI logs (clean stdout) | ✅ | | 2 | MCP + `--LogLevel Information` | CLI logs on stderr with **green** `info:` | ✅ | | 3 | MCP + config `log-level` only | CLI logs on stderr with **green** `info:` | ✅ Bug 2 fixed | | 4 | MCP + `--LogLevel Warning` + config `log-level: Information` | CLI wins → no `info:` shown | ✅ | | 5 | Non-MCP mode | Unchanged behavior | ✅ | | 6 | MCP + `--LogLevel Warning` (StaticWebApps config) | **Yellow** `warn:` shown | ✅ Bug 1 fixed | ## Note This is a follow-up bug fix on top of PR #3419 (MCP Set Log Level) and PR #3484 (MCP notifications/message). It targets `main`. --------- Co-authored-by: Aniruddh Munde (cherry picked from commit 6f986c7a4d26a6b41c291f94ff5d8fddb5530f3c) --- src/Cli.Tests/CustomLoggerTests.cs | 197 ++++++++++++++++++++++------- src/Cli/ConfigGenerator.cs | 15 +++ src/Cli/CustomLoggerProvider.cs | 57 +++++++-- src/Cli/Utils.cs | 12 ++ 4 files changed, 220 insertions(+), 61 deletions(-) diff --git a/src/Cli.Tests/CustomLoggerTests.cs b/src/Cli.Tests/CustomLoggerTests.cs index 951cbc6a77..449e9bd48e 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.IsLogLevelOverriddenByCli = false; + Cli.Utils.IsLogLevelOverriddenByConfig = 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.IsLogLevelOverriddenByCli = 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.IsLogLevelOverriddenByConfig = 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.IsLogLevelOverriddenByCli = true; + Cli.Utils.CliLogLevel = LogLevel.Warning; + Cli.Utils.IsLogLevelOverriddenByConfig = 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/ConfigGenerator.cs b/src/Cli/ConfigGenerator.cs index 8a416e26ca..7e4416db2b 100644 --- a/src/Cli/ConfigGenerator.cs +++ b/src/Cli/ConfigGenerator.cs @@ -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.IsLogLevelOverriddenByConfig = 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.IsLogLevelOverriddenByConfig = 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..e8c49e97ca 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.IsLogLevelOverriddenByCli + ? Cli.Utils.CliLogLevel + : Cli.Utils.IsLogLevelOverriddenByConfig + ? 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.IsLogLevelOverriddenByCli && !Cli.Utils.IsLogLevelOverriddenByConfig) { 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/Utils.cs b/src/Cli/Utils.cs index 1f9ef6d282..817c73b64c 100644 --- a/src/Cli/Utils.cs +++ b/src/Cli/Utils.cs @@ -40,6 +40,18 @@ public class Utils /// public static LogLevel CliLogLevel { get; set; } = LogLevel.Information; + /// + /// When true, the runtime config file explicitly set a log-level value. + /// This allows CLI logs to be written to stderr in MCP mode even when no --LogLevel flag was provided. + /// + public static bool IsLogLevelOverriddenByConfig { get; set; } + + /// + /// The log level specified via runtime config file's log-level setting. + /// Only valid when IsLogLevelOverriddenByConfig 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 From 170940c5241322fe26f79ff8c4ce91c4a44c183a Mon Sep 17 00:00:00 2001 From: Anusha Kolan Date: Fri, 15 May 2026 17:08:06 -0700 Subject: [PATCH 2/3] Allow MCP agent to override CLI and Config log levels (Agent > CLI > Config) (#3544) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## Why make this change? Closes #3533— *Log-level precedence should be Agent > CLI > Config; MCP `logging/setLevel` is silently ignored when CLI/Config set a level.* The runtime today implements **CLI > Config > Agent**: once `--LogLevel` is passed or `runtime.telemetry.log-level` is set, the agent's request silently no-ops. There is no way for an agent to dial verbosity up or down at runtime, which defeats the purpose of MCP `logging/setLevel`. The team locked the corrected precedence on 5/1 : **Agent > CLI > Config > defaults**. The agent must always be able to override; CLI still beats Config when the agent doesn't speak up; defaults (Production = Error, Development = Debug, `--mcp-stdio` = None) are unchanged. ## What is this change? [`DynamicLogLevelProvider`](src/Service/Telemetry/DynamicLogLevelProvider.cs) is the single chokepoint for all log-level updates. The fix: - `UpdateFromMcp` no longer rejects when CLI or Config has set a level. It updates the level, flips a new `IsAgentOverriding` flag, and emits an `Information` audit log ("Log level updated to {Level} via MCP logging/setLevel (agent override)."). - `UpdateFromRuntimeConfig` is guarded so a config hot-reload won't overwrite an Agent- or CLI-set level. - [`ILogLevelController`](src/Core/Telemetry/ILogLevelController.cs) gains `IsAgentOverriding` and updated XML docs. - [`Startup.cs`](src/Service/Startup.cs) wires a logger on the provider once `ILoggerFactory` exists, so the audit log reaches the standard pipeline. - [`McpStdioServer.HandleSetLevel`](src/Azure.DataApiBuilder.Mcp/Core/McpStdioServer.cs) enables the MCP notification writer **before** calling `UpdateFromMcp` so the audit log surfaces to the agent. CLI > Config, default levels, and the `--mcp-stdio` default of `None` are unchanged. ## How was this tested? - [ ] Integration Tests - [x] Unit Tests - [x] Manual end-to-end test against live SQL Server with the MCP Inspector ### Unit tests Added 1 new test and updated existing ones in [`DynamicLogLevelProviderTests`](src/Service.Tests/UnitTests/DynamicLogLevelProviderTests.cs) to lock Agent > CLI > Config under both single-call and concurrent paths. All 9 tests pass. ### Manual end-to-end test Started the engine with `--mcp-stdio --LogLevel Error` and drove it from the MCP Inspector against a live SQL Server. | # | What | How | Result | | --- | --- | --- | --- | | 1 | Agent sets level to debug | Send `logging/setLevel { level: "debug" }` | Success response ✅ | | 2 | Audit log surfaces | Watch MCP notifications | Info notification with override message received ✅ | | 3 | Debug logs flow despite `--LogLevel Error` | Trigger activity (e.g. `tools/list`) | Debug notifications received ✅ | Also spot-checked HTTP mode: Config-only, CLI-over-Config, and Config-alone all behave as before. ## Sample Request(s) ### MCP `logging/setLevel` from the agent Request: ```json { "jsonrpc": "2.0", "id": 2, "method": "logging/setLevel", "params": { "level": "debug" } } ``` Response: ```json { "jsonrpc": "2.0", "id": 2, "result": {} } ``` Followed by the new visibility notification: ```json { "jsonrpc": "2.0", "method": "notifications/message", "params": { "level": "info", "logger": "Azure.DataApiBuilder.Service.Telemetry.DynamicLogLevelProvider", "data": "Log level updated to Debug via MCP logging/setLevel (agent override)." } } ``` ### CLI usage (precedence still works as expected) ```bash # Agent can override even when CLI pins the level: dab start --mcp-stdio --LogLevel Error # → agent sends logging/setLevel debug → debug logs flow # CLI still beats Config when no agent is involved: dab start --LogLevel Warning --config dab-config.json # config has log-level: Information # → only Warning and above appear # Config alone, no CLI, no agent — unchanged: dab start --config dab-config.json # config has log-level: Information # → info: lines visible, debug: filtered out ``` (cherry picked from commit fcb09b8f4b5feb2c8f47f60ed0811f03d3627c70) --- .../Core/McpStdioServer.cs | 80 +++++---- src/Cli.Tests/CustomLoggerTests.cs | 12 +- src/Cli.Tests/EndToEndTests.cs | 14 +- src/Cli/ConfigGenerator.cs | 4 +- src/Cli/CustomLoggerProvider.cs | 6 +- src/Cli/Program.cs | 2 +- src/Cli/Utils.cs | 13 +- src/Core/Telemetry/ILogLevelController.cs | 31 ++-- .../UnitTests/DynamicLogLevelProviderTests.cs | 156 ++++++++++++++++-- src/Service/Program.cs | 22 +-- src/Service/Startup.cs | 15 +- .../Telemetry/DynamicLogLevelProvider.cs | 104 +++++++----- 12 files changed, 322 insertions(+), 137 deletions(-) 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/Cli.Tests/CustomLoggerTests.cs b/src/Cli.Tests/CustomLoggerTests.cs index 449e9bd48e..8c08efc3e6 100644 --- a/src/Cli.Tests/CustomLoggerTests.cs +++ b/src/Cli.Tests/CustomLoggerTests.cs @@ -23,8 +23,8 @@ public class CustomLoggerTests public void ResetMcpStaticState() { Cli.Utils.IsMcpStdioMode = false; - Cli.Utils.IsLogLevelOverriddenByCli = false; - Cli.Utils.IsLogLevelOverriddenByConfig = false; + Cli.Utils.IsCliOverriding = false; + Cli.Utils.IsConfigOverriding = false; Cli.Utils.CliLogLevel = LogLevel.Information; Cli.Utils.ConfigLogLevel = LogLevel.Information; } @@ -114,7 +114,7 @@ public void Mcp_NoOverrides_SuppressesAllOutput() public void Mcp_CliOverride_WritesToStderrAndHonorsCliLevel() { Cli.Utils.IsMcpStdioMode = true; - Cli.Utils.IsLogLevelOverriddenByCli = true; + Cli.Utils.IsCliOverriding = true; Cli.Utils.CliLogLevel = LogLevel.Warning; (string stdout, string stderr) = CaptureConsole(() => @@ -140,7 +140,7 @@ public void Mcp_CliOverride_WritesToStderrAndHonorsCliLevel() public void Mcp_ConfigOverride_WritesToStderrAndHonorsConfigLevel() { Cli.Utils.IsMcpStdioMode = true; - Cli.Utils.IsLogLevelOverriddenByConfig = true; + Cli.Utils.IsConfigOverriding = true; Cli.Utils.ConfigLogLevel = LogLevel.Information; (string stdout, string stderr) = CaptureConsole(() => @@ -163,9 +163,9 @@ public void Mcp_ConfigOverride_WritesToStderrAndHonorsConfigLevel() public void Mcp_CliOverridePrecedesConfigOverride() { Cli.Utils.IsMcpStdioMode = true; - Cli.Utils.IsLogLevelOverriddenByCli = true; + Cli.Utils.IsCliOverriding = true; Cli.Utils.CliLogLevel = LogLevel.Warning; - Cli.Utils.IsLogLevelOverriddenByConfig = true; + Cli.Utils.IsConfigOverriding = true; Cli.Utils.ConfigLogLevel = LogLevel.Information; (_, string stderr) = CaptureConsole(() => 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/ConfigGenerator.cs b/src/Cli/ConfigGenerator.cs index 7e4416db2b..b14a183b67 100644 --- a/src/Cli/ConfigGenerator.cs +++ b/src/Cli/ConfigGenerator.cs @@ -2755,7 +2755,7 @@ public static bool TryStartEngineWithOptions(StartOptions options, FileSystemRun // Reset the config-based override flag so stale state from a prior call // (these are static) cannot leak into the current run. - Utils.IsLogLevelOverriddenByConfig = false; + Utils.IsConfigOverriding = false; Utils.ConfigLogLevel = LogLevel.Information; if (options.LogLevel is not null) @@ -2782,7 +2782,7 @@ public static bool TryStartEngineWithOptions(StartOptions options, FileSystemRun // when the user expressed intent via the config file rather than --LogLevel. if (deserializedRuntimeConfig.HasExplicitLogLevel()) { - Utils.IsLogLevelOverriddenByConfig = true; + Utils.IsConfigOverriding = true; Utils.ConfigLogLevel = minimumLogLevel; } } diff --git a/src/Cli/CustomLoggerProvider.cs b/src/Cli/CustomLoggerProvider.cs index e8c49e97ca..80a046a042 100644 --- a/src/Cli/CustomLoggerProvider.cs +++ b/src/Cli/CustomLoggerProvider.cs @@ -34,9 +34,9 @@ public class CustomConsoleLogger : ILogger public CustomConsoleLogger(LogLevel minimumLogLevel = LogLevel.Information) { _minimumLogLevel = Cli.Utils.IsMcpStdioMode - ? (Cli.Utils.IsLogLevelOverriddenByCli + ? (Cli.Utils.IsCliOverriding ? Cli.Utils.CliLogLevel - : Cli.Utils.IsLogLevelOverriddenByConfig + : Cli.Utils.IsConfigOverriding ? Cli.Utils.ConfigLogLevel : LogLevel.None) : minimumLogLevel; @@ -103,7 +103,7 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except // In that case, write to stderr to keep stdout clean for JSON-RPC. if (Cli.Utils.IsMcpStdioMode) { - if (!Cli.Utils.IsLogLevelOverriddenByCli && !Cli.Utils.IsLogLevelOverriddenByConfig) + if (!Cli.Utils.IsCliOverriding && !Cli.Utils.IsConfigOverriding) { return; // Suppress entirely when no explicit log level } 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 817c73b64c..8f309407a8 100644 --- a/src/Cli/Utils.cs +++ b/src/Cli/Utils.cs @@ -29,26 +29,27 @@ 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 file explicitly set a log-level value. + /// 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 IsLogLevelOverriddenByConfig { get; set; } + public static bool IsConfigOverriding { get; set; } /// /// The log level specified via runtime config file's log-level setting. - /// Only valid when IsLogLevelOverriddenByConfig is true. + /// Only valid when IsConfigOverriding is true. /// public static LogLevel ConfigLogLevel { get; set; } = LogLevel.Information; 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/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 841a34483c..7c57769f13 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(); @@ -703,6 +703,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)) @@ -914,7 +925,7 @@ private static void EvictGraphQLSchema(IRequestExecutorManager requestExecutorRe /// 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; } /// From 1ad220625640c0da53cb24afdc35362f4105cc30 Mon Sep 17 00:00:00 2001 From: Anusha Kolan Date: Mon, 18 May 2026 19:22:00 -0700 Subject: [PATCH 3/3] Added missing stored procedure parameters in describe_entities response. (#3425) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## Why make this change? Closes #3400. `describe_entities` could return stored-procedure entities with empty or partial `parameters` metadata when parameters were not fully listed in config. MCP clients/agents then missed required inputs and `execute_entity` calls failed. ## What is this change? `describe_entities` now uses the runtime database metadata as the source of truth for stored-procedure parameter discovery, with config acting as an overlay on top. Per the rules locked in #3400: - **Names** come from the database. Config never overrides parameter names. - **`required`** defaults to `true`. Config overrides per-parameter when the user explicitly supplies it. To make this round-trip cleanly through JSON deserialization, `ParameterMetadata.Required` is now `bool?` so "user omitted the key" is distinct from "user wrote `required: false`". The global `JsonSerializer` policy `DefaultIgnoreCondition.WhenWritingNull` keeps generated configs clean. - **`default`** is config-only. T-SQL doesn't expose parameter defaults via metadata for ordinary stored procedures, so the DB-side value is unreliable. - **`description`** is config-only. There is no DB column carrying per-parameter descriptions. - Parameters discovered from the database that are not listed in config are still surfaced (with `required: true`, no default, no description) so agents can see and call them. The merge itself is already performed upstream in `SqlMetadataProvider.FillSchemaForStoredProcedureAsync`, which populates `DatabaseStoredProcedure.StoredProcedureDefinition.Parameters` with config values laid over the introspected DB schema. `DescribeEntitiesTool.BuildParameterMetadataInfo` projects that already-merged structure directly, instead of carrying its own parallel merge. If the upstream merge invariant is ever violated (i.e. an SP entity reaches `describe_entities` without populated DB metadata), the tool throws inside the per-entity `try` and the surrounding `catch` drops just that entity from the response. Returning the SP with `parameters: []` would be indistinguishable from a real zero-parameter SP and would mislead the agent into calling the SP with no arguments. A config that declares an SP parameter the DB does not have continues to fail loudly at `InitializeAsync` (via `HandleOrRecordException`), so `describe_entities` never runs against a half-merged state in production. ## How was this tested? - [x] Unit tests (projection logic, with the merged `ParameterDefinition` dictionary supplied directly) - [x] Integration tests against a live SQL Server (real `MsSqlMetadataProvider`, real merge, real DB introspection) - [x] Manual stdio MCP testing ### Unit tests — `DescribeEntitiesStoredProcedureParametersTests` These tests pass a hand-built `Dictionary` representing the post-merge state and verify the projection without touching a database. | Test | What it locks in | | --- | --- | | `MixedConfiguredAndUnconfiguredParameters_ProjectsBoth` | A parameter with config overrides and one without are projected side-by-side: the overridden param reflects config; the non-overridden one defaults to `required=true`, `default=null`, `description=""`. | | `ExplicitRequiredFalse_IsHonored` (`WithDefault` / `WithoutDefault`) | An explicit `required=false` written onto the `ParameterDefinition` by the upstream merge is honored both with and without a `Default` value. | | `DropsEntity_WhenStoredProcedureMetadataIsMissing` | If the upstream invariant ever regresses and an SP entity has no `DatabaseStoredProcedure`, the tool drops that entity from the response rather than returning it with `parameters=[]`. When it's the only entity, the tool returns the `NoEntitiesConfigured` error result. | ### Integration tests — `DescribeEntitiesStoredProcedureParametersMsSqlIntegrationTests` (`TestCategory.MSSQL`) Extend `SqlTestBase`, so they bootstrap the real `MsSqlMetadataProvider` against the live test database via `dab-config.MsSql.json` and `DatabaseSchema-MsSql.sql`. These exercise the actual config-onto-DB merge that the unit tests cannot. | Test | SP / config | What it locks in | | --- | --- | --- | | `StoredProcedureWithNoDbOrConfigParameters_EmitsEmptyParametersArray` | `GetBooks` → `get_books` (0 DB params, no config overrides) | A truly zero-parameter SP emits `parameters: []`. | | `DbParameterWithoutConfigOverride_DefaultsToRequiredTrue` | `GetBook` → `get_book_by_id @id int` (no config override) | A DB-discovered parameter with no config entry comes out `required=true, default=null, description=""`. | | `DbParametersWithConfigOverrides_MergesConfigValuesOntoDbParameters` | `InsertBook` → `insert_book @title, @publisher_id` (config sets both `required=false` with defaults) | Config-side `required`/`default` flow onto DB-discovered params end-to-end. | | `PartialConfigOverride_MergesOverriddenParamAndDefaultsTheOther` | `update_book_title @id, @title` (config overrides `id` only) | Mixed merge against a real SP: the overridden param reflects config; the non-overridden one falls back to the merge defaults. | | `SqlMetadataProvider_FailsAtInit_WhenConfigDeclaresParameterNotInDb` | `get_book_by_id` with a bogus extra param in config | Locks in the upstream invariant `DescribeEntitiesTool` depends on: a config that declares a parameter the DB does not have throws `DataApiBuilderException` at `InitializeAsync` (mentioning both the bogus param name and the SP name), so the tool never reaches a half-merged state in production. | ### Manual end-to-end test Validated against a live SQL Server over the MCP stdio transport. Each test entity is backed by the same two-parameter stored-procedure shape — `(@id INT, @locale NVARCHAR(10) = 'en-US')` — and each entity declares its parameters differently in `dab-config.json` so we can verify how config and DB metadata combine. The custom-tool entity is backed by a separate two-parameter SP that takes a search title and a max-row count.
Stored procedure DDL ```sql -- Each test entity gets its own SP with the same shape so config on one -- entity does not pollute the shared parameter metadata of another. CREATE PROCEDURE dbo.get_book_full @id INT, @locale NVARCHAR(10) = 'en-US' AS ... CREATE PROCEDURE dbo.get_book_partial @id INT, @locale NVARCHAR(10) = 'en-US' AS ... CREATE PROCEDURE dbo.get_book_empty @id INT, @locale NVARCHAR(10) = 'en-US' AS ... CREATE PROCEDURE dbo.search_books @title NVARCHAR(200), @max_results INT AS ... ```
Entities in dab-config.json ```jsonc "BookFull": { "source": { "object": "dbo.get_book_full", "type": "stored-procedure", "parameters": [ { "name": "id", "required": true, "default": "42", "description": "Book id from config" }, { "name": "locale", "required": false, "default": "fr-FR", "description": "Locale from config" } ] }, "permissions": [{ "role": "anonymous", "actions": [{ "action": "execute" }] }] }, "BookPartial": { "source": { "object": "dbo.get_book_partial", "type": "stored-procedure", "parameters": { "id": 1 } // old object form; no `required`, locale omitted }, "permissions": [{ "role": "anonymous", "actions": [{ "action": "execute" }] }] }, "BookEmpty": { "source": { "object": "dbo.get_book_empty", "type": "stored-procedure" // no parameters block at all }, "permissions": [{ "role": "anonymous", "actions": [{ "action": "execute" }] }] }, "SearchBooks": { "source": { "object": "dbo.search_books", "type": "stored-procedure", "parameters": [ { "name": "title", "required": true, "description": "Substring to search for in book title" }, { "name": "max_results", "required": true, "description": "Maximum rows to return" } ] }, "mcp": { "custom-tool": true }, "permissions": [{ "role": "anonymous", "actions": [{ "action": "execute" }] }] } ```
**T1 — `tools/call describe_entities`** (verifies the metadata returned to MCP clients) For each entity below, the columns show what the tool reported for each parameter. The "What this verifies" column explains why this row matters. | Entity (config shape) | Param | required | default | description | What this verifies | | --- | --- | --- | --- | --- | --- | | `BookFull` — config sets `required`, `default`, `description` for both params | `id` | true | `"42"` | `"Book id from config"` | Explicit per-param config flows through unchanged. | | `BookFull` | `locale` | false | `"fr-FR"` | `"Locale from config"` | Explicit `required: false` from the user is still honored (rule 2: config overrides default). | | `BookPartial` — config uses old object form `"parameters": { "id": 1 }` (no `required` key, `locale` not mentioned) | `id` | true | `"1"` | `""` | Old-format config supplies the default; absent `required` defaults to **true** (the fix). | | `BookPartial` | `locale` | true | `null` | `""` | Param is in the SP but not in config — still surfaced from DB metadata, defaults to **required: true** (the fix; rule 5). | | `BookEmpty` — no `parameters` block in config at all | `id` | true | `null` | `""` | Both params discovered purely from DB metadata, defaulting to required (the fix; rule 5). | | `BookEmpty` | `locale` | true | `null` | `""` | Same as above. | | `SearchBooks` — `mcp.custom-tool: true`; config marks both params `required: true` with descriptions | `title` | true | `null` | `"Substring to search for in book title"` | Entities marked as custom tools still appear in `describe_entities` with the same merge rules applied. | | `SearchBooks` | `max_results` | true | `null` | `"Maximum rows to return"` | Same as above. | **T2 — `tools/call execute_entity`** for `BookEmpty` (no params declared in config) with arguments `{ "entity": "BookEmpty", "parameters": { "id": 2, "locale": "fr-FR" } }` → `status: success`, returns the row for id=2 (`"Le Petit Prince"`). Confirms an agent that follows the `describe_entities` output can invoke the SP successfully even when the config declares zero parameters. **T3 — `tools/call execute_entity`** for `BookPartial` with no `parameters` argument → `status: success`, returns the row `{ id: 1, title: "The Pragmatic Programmer", locale: "en-US" }`. The returned `id=1` matches the config-supplied default `"1"`, and `locale="en-US"` matches the T-SQL `DEFAULT 'en-US'` on `@locale`. Confirms that omitted parameters fall back to whichever default is available. **T4 — `tools/call search_books`** (the custom-tool surface for `SearchBooks`) with `{ "title": "Pr", "max_results": 5 }` → `status: success`, returns 2 rows whose titles contain "Pr": `"The Pragmatic Programmer"` and `"Le Petit Prince"`. Confirms a stored procedure exposed as a top-level MCP custom tool can be invoked end-to-end with the new `Required` semantics. (cherry picked from commit 73e6b14fda27cfd17c567d0d87e9ad2065fca6e7) --- .../BuiltInTools/DescribeEntitiesTool.cs | 99 +++-- .../Utils/McpMetadataHelper.cs | 38 +- ...tyWithSourceAsStoredProcedure.verified.txt | 3 - ...ests.UpdateDatabaseSourceName.verified.txt | 3 - src/Cli/ConfigGenerator.cs | 2 +- .../DatabasePrimitives/DatabaseObject.cs | 2 +- src/Config/ObjectModel/ParameterMetadata.cs | 2 +- .../Mcp/DescribeEntitiesFilteringTests.cs | 45 +++ ...rocedureParametersMsSqlIntegrationTests.cs | 361 ++++++++++++++++++ ...eEntitiesStoredProcedureParametersTests.cs | 292 ++++++++++++++ 10 files changed, 814 insertions(+), 33 deletions(-) create mode 100644 src/Service.Tests/Mcp/DescribeEntitiesStoredProcedureParametersMsSqlIntegrationTests.cs create mode 100644 src/Service.Tests/Mcp/DescribeEntitiesStoredProcedureParametersTests.cs 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/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/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 b14a183b67..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 }); } 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/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(); + } + } +}