From 62957072f971d6ec201ab13b3bd6eff089ad0d9f Mon Sep 17 00:00:00 2001 From: Scott Stauffer Date: Sun, 18 Oct 2026 08:25:49 -0500 Subject: [PATCH 1/2] feat: log each call under the agent whose token it carries App:AgentTokens maps agent names to bearer tokens and replaces App:AuthToken. The middleware sets the matched agent as the request's user, and every query_database, list_tables, describe_table and /api/query call is logged with its name ("unauthenticated" over stdio or without tokens). Blank or shared tokens stop the server at startup. Calls refused before they reach the database (unknown database, a statement SqlGuard rejects, invalid parameters, a missing password) are now logged as warnings with their SQL, and requests with a missing or unknown token are logged with their path and remote address. appsettings.Production.json starts each log entry with the UTC time. --- .github/workflows/ci.yml | 2 +- Http/HttpSecurity.cs | 82 ++++++++++++++------- Program.cs | 4 +- README.md | 29 +++++--- Services/QueryService.cs | 63 ++++++++++------ Tools/SqlTools.cs | 12 ++- appsettings.Production.json | 7 ++ appsettings.json | 2 +- tests/SqlMcp.Tests/HealthTests.cs | 6 +- tests/SqlMcp.Tests/HttpSecurityTests.cs | 97 +++++++++++++++++++++++-- 10 files changed, 234 insertions(+), 70 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 467c975..af0a064 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -97,7 +97,7 @@ jobs: - name: Serves health, rejects requests without the token, runs as non-root run: | - docker run -d --name app -e App__AuthToken=ci-token -p 8080:8080 sql-mcp + docker run -d --name app -e App__AgentTokens__ci=ci-token -p 8080:8080 sql-mcp for i in $(seq 30); do curl -sf localhost:8080/health && break; sleep 1; done test "$(curl -s -o /dev/null -w '%{http_code}' localhost:8080/health)" = 200 test "$(curl -s -o /dev/null -w '%{http_code}' -X POST localhost:8080/mcp)" = 401 diff --git a/Http/HttpSecurity.cs b/Http/HttpSecurity.cs index 47dd6aa..10e201b 100644 --- a/Http/HttpSecurity.cs +++ b/Http/HttpSecurity.cs @@ -1,37 +1,53 @@ using System.Net; +using System.Security.Claims; using System.Security.Cryptography; using System.Text; namespace SqlMcp.Http; /// -/// Protects the HTTP transport. Requests to /mcp and /api/* must carry -/// "Authorization: Bearer {App:AuthToken}" when a token is configured, and any request -/// with an Origin header must come from App:AllowedOrigins (the MCP spec requires -/// Origin checks so a web page can't reach a local server through DNS rebinding). -/// Without a token the server refuses to listen beyond loopback unless -/// App:AllowUnauthenticated is set. +/// Protects the HTTP transport. When App:AgentTokens maps agent names to tokens, requests +/// to /mcp and /api/* must carry "Authorization: Bearer {token}" for one of them, and the +/// request's user is that agent, so each call is logged under its name. Any request with +/// an Origin header must come from App:AllowedOrigins (the MCP spec requires Origin +/// checks so a web page can't reach a local server through DNS rebinding). Without +/// tokens the server refuses to listen beyond loopback unless App:AllowUnauthenticated +/// is set. /// public static class HttpSecurity { public const string DefaultUrls = "http://localhost:8080"; /// - /// Throws when the server would accept unauthenticated requests from other machines. + /// Throws, listing every problem, when an agent token is blank or shared, or when the + /// server would accept unauthenticated requests from other machines. /// public static void ValidateStartup(IConfiguration config) { - if (!string.IsNullOrEmpty(config["App:AuthToken"]) || config.GetValue("App:AllowUnauthenticated", false)) - return; - - var exposed = ParseUrls(config["App:Urls"] ?? DefaultUrls).Where(u => !IsLoopback(u)).ToList(); - if (exposed.Count > 0) - throw new InvalidOperationException( - $"Refusing to listen on {string.Join(", ", exposed)} without authentication. " + - "Set App:AuthToken (env App__AuthToken) to require a bearer token, bind to localhost, " + - "or set App:AllowUnauthenticated to true if something in front of this server authenticates."); + var errors = new List(); + var agents = ReadAgentTokens(config); + foreach (var (name, token) in agents.Where(a => string.IsNullOrWhiteSpace(a.Token))) + errors.Add($"Agent '{name}' has no token in App:AgentTokens."); + foreach (var shared in agents.Where(a => !string.IsNullOrWhiteSpace(a.Token)).GroupBy(a => a.Token).Where(g => g.Count() > 1)) + errors.Add($"Agents {string.Join(", ", shared.Select(a => $"'{a.Name}'"))} share a token, so their calls can't be told apart."); + + if (agents.Count == 0 && !config.GetValue("App:AllowUnauthenticated", false)) + { + var exposed = ParseUrls(config["App:Urls"] ?? DefaultUrls).Where(u => !IsLoopback(u)).ToList(); + if (exposed.Count > 0) + errors.Add($"Refusing to listen on {string.Join(", ", exposed)} without authentication. " + + "Give each agent a token under App:AgentTokens (env App__AgentTokens__), bind to localhost, " + + "or set App:AllowUnauthenticated to true if something in front of this server authenticates."); + } + + if (errors.Count > 0) + throw new InvalidOperationException("Invalid configuration:" + string.Concat(errors.Select(e => $"{Environment.NewLine} - {e}"))); } + /// App:AgentTokens as (agent name, token) pairs. + public static List<(string Name, string? Token)> ReadAgentTokens(IConfiguration config) => + [.. config.GetSection("App:AgentTokens").GetChildren().Select(c => (c.Key, c.Value))]; + public static IEnumerable ParseUrls(string urls) => urls.Split(';', StringSplitOptions.RemoveEmptyEntries | StringSplitOptions.TrimEntries); @@ -55,8 +71,10 @@ public static bool IsLoopback(string url) public static void UseHttpSecurity(this WebApplication app) { - var token = app.Configuration["App:AuthToken"]; - var expected = string.IsNullOrEmpty(token) ? null : SHA256.HashData(Encoding.UTF8.GetBytes(token)); + var agents = ReadAgentTokens(app.Configuration) + .Select(a => (a.Name, Hash: SHA256.HashData(Encoding.UTF8.GetBytes(a.Token!)))) + .ToList(); + var logger = app.Services.GetRequiredService().CreateLogger(typeof(HttpSecurity)); var allowedOrigins = new HashSet( app.Configuration.GetSection("App:AllowedOrigins").Get() ?? [], StringComparer.OrdinalIgnoreCase); @@ -71,11 +89,17 @@ public static void UseHttpSecurity(this WebApplication app) return; } - if (expected is not null && RequiresAuth(context.Request.Path) && !HasValidToken(context.Request, expected)) + if (agents.Count > 0 && RequiresAuth(context.Request.Path)) { - context.Response.StatusCode = StatusCodes.Status401Unauthorized; - context.Response.Headers.WWWAuthenticate = "Bearer"; - return; + if (FindAgent(context.Request, agents) is not { } agent) + { + logger.LogWarning("Rejected {Method} {Path} from {RemoteIp}: missing or unknown bearer token.", + context.Request.Method, context.Request.Path, context.Connection.RemoteIpAddress); + context.Response.StatusCode = StatusCodes.Status401Unauthorized; + context.Response.Headers.WWWAuthenticate = "Bearer"; + return; + } + context.User = new ClaimsPrincipal(new ClaimsIdentity([new Claim(ClaimTypes.Name, agent)], "Bearer")); } await next(); @@ -85,15 +109,21 @@ public static void UseHttpSecurity(this WebApplication app) private static bool RequiresAuth(PathString path) => !path.Equals("/health", StringComparison.OrdinalIgnoreCase); - private static bool HasValidToken(HttpRequest request, byte[] expected) + /// The agent whose token the request carries, or null. + private static string? FindAgent(HttpRequest request, List<(string Name, byte[] Hash)> agents) { var header = request.Headers.Authorization.ToString(); const string prefix = "Bearer "; if (!header.StartsWith(prefix, StringComparison.OrdinalIgnoreCase)) - return false; + return null; - // Compare fixed-length hashes so neither content nor length leaks through timing. + // Compare fixed-length hashes so neither content nor length leaks through timing, + // and check every agent so the time taken doesn't say which one matched. var presented = SHA256.HashData(Encoding.UTF8.GetBytes(header[prefix.Length..].Trim())); - return CryptographicOperations.FixedTimeEquals(presented, expected); + string? match = null; + foreach (var (name, hash) in agents) + if (CryptographicOperations.FixedTimeEquals(presented, hash)) + match = name; + return match; } } diff --git a/Program.cs b/Program.cs index 348aab7..1b565b5 100644 --- a/Program.cs +++ b/Program.cs @@ -77,9 +77,9 @@ statusCode: ready ? StatusCodes.Status200OK : StatusCodes.Status503ServiceUnavailable); }); - app.MapPost("/api/query", async (QueryService svc, QueryRequest req, CancellationToken ct) => + app.MapPost("/api/query", async (QueryService svc, QueryRequest req, HttpContext context, CancellationToken ct) => { - var result = await svc.ExecuteAsync(req, ct); + var result = await svc.ExecuteAsync(req, context.User.Identity?.Name, ct); if (result.IsError) return Results.Problem(result.Error); return Results.Ok(result.Value); diff --git a/README.md b/README.md index 7933138..d125987 100644 --- a/README.md +++ b/README.md @@ -65,7 +65,7 @@ Streamable HTTP: "sql": { "type": "http", "url": "http://localhost:8080/mcp", - "headers": { "Authorization": "Bearer " } + "headers": { "Authorization": "Bearer " } } } } @@ -86,9 +86,9 @@ All settings live in `appsettings.json`. | Key | Default | Description | |-----|---------|-------------| | `App:Urls` | `http://localhost:8080` | Bind address(es), `;`-separated. Override with env var `App__Urls`. | -| `App:AuthToken` | _(none)_ | Bearer token required on `/mcp` and `/api/*`. Set it with env var `App__AuthToken` rather than in the file. Required to listen beyond localhost. | +| `App:AgentTokens` | `{}` | Each agent's name and the bearer token it sends on `/mcp` and `/api/*`, e.g. `{"reporting": ""}`. Calls are logged under the agent's name (see [Logging](#logging)). Set tokens with env vars such as `App__AgentTokens__reporting` rather than in the file, and keep names to letters, digits and underscores so they work as variable names everywhere. A blank token, or one shared by two agents, stops the server at startup. Required to listen beyond localhost. | | `App:AllowedOrigins` | `[]` | Browser origins allowed to call the server. Requests carrying any other `Origin` header are rejected. | -| `App:AllowUnauthenticated` | `false` | Allow listening beyond localhost without `AuthToken`, for when a proxy in front authenticates. | +| `App:AllowUnauthenticated` | `false` | Allow listening beyond localhost without `AgentTokens`, for when a proxy in front authenticates. | | `App:MaxRows` | `1000` | Maximum rows returned per query, and tables per `list_tables`. Response includes `"truncated": true` when the limit is hit. | | `App:QueryTimeoutSeconds` | `30` | Per-query timeout in seconds; a query that runs longer fails with "Query timed out after N s". Also how long a query waits for a free slot when `MaxConcurrentQueries` are already running. | | `App:MaxValueLength` | `10000` | Longest string returned for a single value, in characters. Longer text and binary values are cut off and marked `… [truncated: N characters in total]`. | @@ -133,7 +133,18 @@ For local development, put real connection strings in `appsettings.Development.j ### Logging -Each tool call is logged by `SqlMcp.Services.QueryService`: the database, the SQL (or the schema lookup), the names of any parameters, how long it took and how many rows it returned. Parameter values are never logged. Failures are logged as warnings. `appsettings.Production.json` keeps this category at `Information` while everything else is at `Warning`; set it to `Warning` to log only failures. In stdio mode all logs go to stderr. +Each tool call and `/api/query` request is logged by `SqlMcp.Services.QueryService`: the agent, the database, the SQL (or the schema lookup), the names of any parameters, how long it took and how many rows it returned. Parameter values are never logged. + +``` +2026-10-18T14:02:11.384Z info: SqlMcp.Services.QueryService[0] + Ran query: SELECT id FROM orders on prod for reporting in 12 ms, 3 rows. +2026-10-18T14:02:40.019Z warn: SqlMcp.Services.QueryService[0] + Refused query: DELETE FROM orders on prod for reporting: Only SELECT queries (including CTEs) are permitted. +``` + +The agent is the name its token has in `App:AgentTokens`. Over stdio, or over HTTP without agent tokens, it is `unauthenticated`. Calls refused before they reach the database (an unknown database, a statement that isn't a read, invalid parameters) are logged as warnings with the SQL, so the log shows what each agent tried as well as what ran. Failures are warnings too. A request with a missing or unknown token is logged as a warning by `SqlMcp.Http.HttpSecurity`, with its path and remote address but not the token. + +`appsettings.Production.json` keeps `QueryService` at `Information` while everything else is at `Warning`; set it to `Warning` to log only refusals and failures. It also starts each entry with the UTC time; under systemd, journald records the time instead. In stdio mode all logs go to stderr. ### Environment variable overrides @@ -249,7 +260,7 @@ curl -s http://localhost:8080/mcp \ { "status": "unavailable", "databases": { "prod": "ok", "reporting": "Database 'reporting' is disabled because its login can modify data. The server log lists why." } } ``` -It requires the bearer token when `App:AuthToken` is set, since it names the databases. Readiness checks aren't written to the query log. +It requires an agent's token when `App:AgentTokens` is set, since it names the databases. Readiness checks aren't written to the query log. --- @@ -287,7 +298,7 @@ Queries come from AI agents, so every query passes three layers before anything **What agents can still do:** read anything the login can read. Grant `SELECT` only on what agents should see. Two cases fall outside the audit: grants made after a passing audit (noticed within five minutes), and on SQL Server, CLR functions created with `EXTERNAL_ACCESS` or `UNSAFE` that the login can call. -**HTTP transport.** By default the server listens on `localhost` only. To listen beyond it, set `App:AuthToken`: clients then send `Authorization: Bearer ` on `/mcp` and `/api/*` (`/health` stays open for probes). The server refuses to start on a non-loopback address without a token unless `App:AllowUnauthenticated` is `true`. Requests that carry an `Origin` header not listed in `App:AllowedOrigins` are rejected, so a web page can't reach a local server through DNS rebinding. The stdio transport is only reachable by the process that launched it. +**HTTP transport.** By default the server listens on `localhost` only. To listen beyond it, give each agent its own token under `App:AgentTokens`: clients then send `Authorization: Bearer ` on `/mcp` and `/api/*` (`/health` stays open for probes), and their calls are logged under the agent's name. Revoking an agent means removing its entry and restarting. The server refuses to start on a non-loopback address without tokens unless `App:AllowUnauthenticated` is `true`. Requests that carry an `Origin` header not listed in `App:AllowedOrigins` are rejected, so a web page can't reach a local server through DNS rebinding. The stdio transport is only reachable by the process that launched it. **Values in queries.** Agents should pass values through `parameters` (see [`query_database`](#query_database)) rather than splicing them into the SQL. Bound values can't change a query's structure, whatever quotes or keywords they contain. Statement validation still applies to the SQL text itself, and catches injected statements in SQL an agent built by concatenating strings. @@ -316,13 +327,13 @@ No .NET runtime needed on the target machine. ```bash docker build -t sql-mcp . docker run -p 8080:8080 \ - -e App__AuthToken="$(openssl rand -hex 32)" \ + -e App__AgentTokens__reporting="$(openssl rand -hex 32)" \ -e DB_PROD_PASSWORD=secret \ -v /path/to/appsettings.json:/app/appsettings.json \ sql-mcp ``` -The image listens on all interfaces inside the container, so it won't start without `App__AuthToken`. It runs as the base image's unprivileged `app` user (uid 1654), so a mounted `appsettings.json` must be readable by that user. Its `HEALTHCHECK` runs `dotnet sql-mcp.dll --healthcheck`, which calls `/health` on the configured port and exits 0 or 1. Use the same command for health checks anywhere curl isn't installed. +The image listens on all interfaces inside the container, so it won't start without at least one `App__AgentTokens__`. It runs as the base image's unprivileged `app` user (uid 1654), so a mounted `appsettings.json` must be readable by that user. Its `HEALTHCHECK` runs `dotnet sql-mcp.dll --healthcheck`, which calls `/health` on the configured port and exits 0 or 1. Use the same command for health checks anywhere curl isn't installed. ### Linux — systemd service @@ -339,7 +350,7 @@ WorkingDirectory=/opt/sql-mcp Restart=always Environment=ASPNETCORE_ENVIRONMENT=Production Environment=DB_PROD_PASSWORD=secret -Environment=App__AuthToken= +Environment=App__AgentTokens__reporting= [Install] WantedBy=multi-user.target diff --git a/Services/QueryService.cs b/Services/QueryService.cs index ffd7d25..293c6cd 100644 --- a/Services/QueryService.cs +++ b/Services/QueryService.cs @@ -138,27 +138,32 @@ private void ValidateDatabases(List errors) ? $"environment variable {db.PasswordEnvVar}, which holds its password, is not set." : null; - public async Task> ExecuteAsync(QueryRequest req, CancellationToken ct = default) + /// + /// Runs a read-only query. agent names the caller in the log; null means it wasn't + /// authenticated (stdio, or HTTP without App:AgentTokens). + /// + public async Task> ExecuteAsync(QueryRequest req, string? agent = null, CancellationToken ct = default) { + var refused = $"query: {req.Sql}"; if (string.IsNullOrWhiteSpace(req.DbName) || req.Sql is null) - return new(null!, "Both dbName and sql are required."); + return Refuse(refused, req.DbName, agent, "Both dbName and sql are required."); var db = FindDatabase(req.DbName); if (db == null) - return new(null!, UnknownDatabase(req.DbName)); + return Refuse(refused, req.DbName, agent, UnknownDatabase(req.DbName)); var verdict = SqlGuard.Validate(req.Sql, db.Provider); if (!verdict.IsAllowed) - return new(null!, verdict.Error!); + return Refuse(refused, db.Name, agent, verdict.Error!); var (parameters, parameterError) = QueryParameters.Parse(req.Parameters); if (parameterError is not null) - return new(null!, parameterError); + return Refuse(refused, db.Name, agent, parameterError); var operation = parameters.Count == 0 ? $"query: {verdict.Sql}" : $"query with parameters {string.Join(", ", parameters.Select(p => p.Key))}: {verdict.Sql}"; - return await RunAsync(db, operation, async newCommand => + return await RunAsync(db, operation, agent, async newCommand => { await using var cmd = newCommand(); cmd.CommandText = verdict.Sql; @@ -171,13 +176,14 @@ public async Task> ExecuteAsync(QueryRequest req, Ca /// /// Lists the tables and views the login can read, optionally in one schema. /// - public async Task> ListTablesAsync(string dbName, string? schema, CancellationToken ct = default) + public async Task> ListTablesAsync(string dbName, string? schema, string? agent = null, CancellationToken ct = default) { + var operation = schema is null ? "list_tables" : $"list_tables in {schema}"; var db = FindDatabase(dbName); if (db == null) - return new(null!, UnknownDatabase(dbName)); + return Refuse(operation, dbName, agent, UnknownDatabase(dbName)); - return await RunAsync(db, schema is null ? "list_tables" : $"list_tables in {schema}", async newCommand => + return await RunAsync(db, operation, agent, async newCommand => { var tables = await SchemaCatalog.FindTablesAsync(newCommand, db.Provider, NullIfBlank(schema), null, _maxRows, ct); return tables.Count > _maxRows @@ -191,13 +197,13 @@ public async Task> ListTablesAsync(string dbName, stri /// table is looked up across all non-system schemas, and "schema.table" is accepted. /// public async Task> DescribeTableAsync( - string dbName, string table, string? schema, CancellationToken ct = default) + string dbName, string table, string? schema, string? agent = null, CancellationToken ct = default) { var db = FindDatabase(dbName); if (db == null) - return new(null!, UnknownDatabase(dbName)); + return Refuse($"describe_table {table}", dbName, agent, UnknownDatabase(dbName)); if (string.IsNullOrWhiteSpace(table)) - return new(null!, "table is required."); + return Refuse("describe_table", db.Name, agent, "table is required."); table = table.Trim(); schema = NullIfBlank(schema); @@ -206,7 +212,7 @@ public async Task> DescribeTableAsync( (schema, table) = (table[..dot], table[(dot + 1)..]); string? notFound = null; - var result = await RunAsync(db, $"describe_table {(schema is null ? table : $"{schema}.{table}")}", async newCommand => + var result = await RunAsync(db, $"describe_table {(schema is null ? table : $"{schema}.{table}")}", agent, async newCommand => { var matches = await SchemaCatalog.FindTablesAsync(newCommand, db.Provider, schema, table, 50, ct); @@ -235,17 +241,20 @@ public async Task> DescribeTableAsync( /// Connects, checks the login, and runs work inside a read-only transaction that is /// always rolled back. Commands from newCommand are bound to that transaction. /// - private async Task> RunAsync(DbConfig db, string operation, Func, Task> work, CancellationToken ct, bool log = true) + private async Task> RunAsync(DbConfig db, string operation, string? agent, Func, Task> work, CancellationToken ct, bool log = true) { if (MissingPassword(db) is { } missing) - return new(default, $"Database '{db.Name}' is unavailable: {missing}"); + { + var unavailable = $"Database '{db.Name}' is unavailable: {missing}"; + return log ? Refuse(operation, db.Name, agent, unavailable) : new(default, unavailable); + } // Bounds the connections one busy agent can hold open against a database. Callers // wait up to the query timeout for a free slot. var slot = _slots[db.Name]; if (!await slot.WaitAsync(TimeSpan.FromSeconds(_queryTimeoutSeconds), ct)) { - _logger.LogWarning("Rejected {Operation} on {Database}: all query slots stayed busy for {Seconds} s.", operation, db.Name, _queryTimeoutSeconds); + _logger.LogWarning("Rejected {Operation} on {Database} for {Agent}: all query slots stayed busy for {Seconds} s.", operation, db.Name, Who(agent), _queryTimeoutSeconds); return new(default, $"Database '{db.Name}' is busy: too many queries are already running. Try again shortly."); } @@ -257,15 +266,15 @@ private async Task> RunAsync(DbConfig db, string operation, if (!log) return result; if (result.IsError) - _logger.LogWarning("Failed {Operation} on {Database} after {ElapsedMs:F0} ms: {Error}", operation, db.Name, elapsed, result.Error); + _logger.LogWarning("Failed {Operation} on {Database} for {Agent} after {ElapsedMs:F0} ms: {Error}", operation, db.Name, Who(agent), elapsed, result.Error); else - _logger.LogInformation("Ran {Operation} on {Database} in {ElapsedMs:F0} ms, {Rows} rows{Truncated}.", - operation, db.Name, elapsed, CountRows(result.Value), IsTruncated(result.Value) ? " (truncated)" : ""); + _logger.LogInformation("Ran {Operation} on {Database} for {Agent} in {ElapsedMs:F0} ms, {Rows} rows{Truncated}.", + operation, db.Name, Who(agent), elapsed, CountRows(result.Value), IsTruncated(result.Value) ? " (truncated)" : ""); return result; } catch (OperationCanceledException) { - _logger.LogInformation("Cancelled {Operation} on {Database} after {ElapsedMs:F0} ms.", operation, db.Name, Stopwatch.GetElapsedTime(started).TotalMilliseconds); + _logger.LogInformation("Cancelled {Operation} on {Database} for {Agent} after {ElapsedMs:F0} ms.", operation, db.Name, Who(agent), Stopwatch.GetElapsedTime(started).TotalMilliseconds); throw; } finally @@ -274,6 +283,18 @@ private async Task> RunAsync(DbConfig db, string operation, } } + /// + /// Logs a call turned away before it reached the database, such as a statement + /// SqlGuard rejected, so the log shows what each agent tried as well as what ran. + /// + private Result Refuse(string operation, string? dbName, string? agent, string error) + { + _logger.LogWarning("Refused {Operation} on {Database} for {Agent}: {Error}", operation, dbName, Who(agent), error); + return new(default!, error); + } + + private static string Who(string? agent) => agent ?? "unauthenticated"; + private static int CountRows(object? value) => value switch { QueryResult q => q.Rows.Length, @@ -390,7 +411,7 @@ public async Task> CheckDatabasesAsync(CancellationTo { var checks = _dbs.Select(async db => { - var result = await RunAsync(db, "readiness check", _ => Task.FromResult(true), ct, log: false); + var result = await RunAsync(db, "readiness check", null, _ => Task.FromResult(true), ct, log: false); return (db.Name, Status: result.Error ?? "ok"); }); return (await Task.WhenAll(checks)).ToDictionary(c => c.Name, c => c.Status); diff --git a/Tools/SqlTools.cs b/Tools/SqlTools.cs index b79dc17..9ef0cca 100644 --- a/Tools/SqlTools.cs +++ b/Tools/SqlTools.cs @@ -24,31 +24,37 @@ public sealed class SqlTools(QueryService svc) [McpServerTool(Name = "list_tables", ReadOnly = true, Idempotent = true)] [Description("List the tables and views the database login can read, as JSON. System schemas are left out unless named.")] public async Task ListTables( + RequestContext context, [Description("Database name from list_databases.")] string dbName, [Description("Only list this schema (on MySQL, the database). Optional.")] string? schema = null, CancellationToken cancellationToken = default) => - Serialize(await svc.ListTablesAsync(dbName, schema, cancellationToken)); + Serialize(await svc.ListTablesAsync(dbName, schema, Agent(context), cancellationToken)); [McpServerTool(Name = "describe_table", ReadOnly = true, Idempotent = true)] [Description("Describe a table or view's columns: name, data type, nullability and primary key, as JSON.")] public async Task DescribeTable( + RequestContext context, [Description("Database name from list_databases.")] string dbName, [Description("Table or view name, optionally schema-qualified (\"sales.orders\"). Case-insensitive.")] string table, [Description("Schema containing the table. Optional; needed only when the name exists in more than one schema.")] string? schema = null, CancellationToken cancellationToken = default) => - Serialize(await svc.DescribeTableAsync(dbName, table, schema, cancellationToken)); + Serialize(await svc.DescribeTableAsync(dbName, table, schema, Agent(context), cancellationToken)); [McpServerTool(Name = "query_database", ReadOnly = true)] [Description("Execute a read-only SELECT query on the specified database and return the columns and rows as JSON. " + "Pass values through parameters rather than writing them into the SQL: they are bound by the database, " + "so quotes in values need no escaping and can't change the query.")] public async Task QueryDatabase( + RequestContext context, [Description("Database name from list_databases.")] string dbName, [Description("SELECT query to execute. Refer to parameters as @name on SQL Server, Postgres and MySQL, and as :name on Oracle.")] string sql, [Description("Values for the query's placeholders, by name without the @ or :, e.g. {\"customer\": \"O'Brien\", \"minTotal\": 100}. " + "Values may be strings, numbers, booleans or null. Optional.")] Dictionary? parameters = null, CancellationToken cancellationToken = default) => - Serialize(await svc.ExecuteAsync(new QueryRequest(dbName, sql, parameters), cancellationToken)); + Serialize(await svc.ExecuteAsync(new QueryRequest(dbName, sql, parameters), Agent(context), cancellationToken)); + + // The agent HttpSecurity matched the bearer token to; null over stdio or without tokens. + private static string? Agent(RequestContext context) => context.User?.Identity?.Name; // An expected failure (unknown database, rejected statement, refused login) is an isError result, not an // exception: the SDK would log a thrown one as unhandled, with a stack trace, and prefix its message. diff --git a/appsettings.Production.json b/appsettings.Production.json index de6eb6e..29ef160 100644 --- a/appsettings.Production.json +++ b/appsettings.Production.json @@ -4,6 +4,13 @@ "Default": "Warning", "Microsoft.AspNetCore": "Warning", "SqlMcp.Services.QueryService": "Information" + }, + "Console": { + "FormatterName": "simple", + "FormatterOptions": { + "TimestampFormat": "yyyy-MM-ddTHH:mm:ss.fffZ ", + "UseUtcTimestamp": true + } } } } diff --git a/appsettings.json b/appsettings.json index 38222b6..0978e09 100644 --- a/appsettings.json +++ b/appsettings.json @@ -1,7 +1,7 @@ { "App": { "Urls": "http://localhost:8080", - "AuthToken": "", + "AgentTokens": {}, "AllowedOrigins": [], "MaxRows": 1000, "QueryTimeoutSeconds": 30, diff --git a/tests/SqlMcp.Tests/HealthTests.cs b/tests/SqlMcp.Tests/HealthTests.cs index f848dfe..b8f0967 100644 --- a/tests/SqlMcp.Tests/HealthTests.cs +++ b/tests/SqlMcp.Tests/HealthTests.cs @@ -21,7 +21,11 @@ public void Dials_the_first_url_on_localhost(string urls, string expected) => Assert.Equal(expected, HealthCheck.LocalUrl(urls)); private static HttpClient Client(string? token = null) => - new WebApplicationFactory().WithWebHostBuilder(b => b.UseSetting("App:AuthToken", token ?? "")).CreateClient(); + new WebApplicationFactory().WithWebHostBuilder(b => + { + if (token is not null) + b.UseSetting("App:AgentTokens:test", token); + }).CreateClient(); // The sample config's databases have no passwords set, so none are ready. [Fact] diff --git a/tests/SqlMcp.Tests/HttpSecurityTests.cs b/tests/SqlMcp.Tests/HttpSecurityTests.cs index 0828c48..a360e4c 100644 --- a/tests/SqlMcp.Tests/HttpSecurityTests.cs +++ b/tests/SqlMcp.Tests/HttpSecurityTests.cs @@ -1,6 +1,7 @@ using Microsoft.AspNetCore.Hosting; using Microsoft.AspNetCore.Mvc.Testing; using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.Logging; using SqlMcp.Http; using System.Net; using System.Net.Http.Headers; @@ -47,31 +48,53 @@ public void Refuses_to_start_unauthenticated_on_all_interfaces() } [Fact] - public void Starts_on_all_interfaces_with_a_token_or_an_explicit_opt_out() + public void Starts_on_all_interfaces_with_agent_tokens_or_an_explicit_opt_out() { - HttpSecurity.ValidateStartup(Config(("App:Urls", "http://*:8080"), ("App:AuthToken", "secret"))); + HttpSecurity.ValidateStartup(Config(("App:Urls", "http://*:8080"), ("App:AgentTokens:reporting", "secret"))); HttpSecurity.ValidateStartup(Config(("App:Urls", "http://*:8080"), ("App:AllowUnauthenticated", "true"))); } + [Fact] + public void Refuses_blank_and_shared_agent_tokens() + { + var ex = Assert.Throws(() => HttpSecurity.ValidateStartup(Config( + ("App:AgentTokens:blank", ""), + ("App:AgentTokens:reporting", "same"), + ("App:AgentTokens:billing", "same"), + ("App:AgentTokens:support", "other")))); + + Assert.Contains("Agent 'blank' has no token", ex.Message); + Assert.Contains("'reporting'", ex.Message); + Assert.Contains("'billing'", ex.Message); + Assert.Contains("share a token", ex.Message); + Assert.DoesNotContain("'support'", ex.Message); + } + private const string ListDatabasesCall = """{"jsonrpc":"2.0","id":1,"method":"tools/call","params":{"name":"list_databases","arguments":{}}}"""; - private static HttpClient Client(string? token = null, string[]? allowedOrigins = null) + private static HttpClient Client(string? token = null, string[]? allowedOrigins = null, LogCollector? logs = null) { var factory = new WebApplicationFactory().WithWebHostBuilder(b => { - b.UseSetting("App:AuthToken", token ?? ""); + if (token is not null) + { + b.UseSetting("App:AgentTokens:reporting", token); + b.UseSetting("App:AgentTokens:billing", token + "-billing"); + } for (int i = 0; i < (allowedOrigins?.Length ?? 0); i++) b.UseSetting($"App:AllowedOrigins:{i}", allowedOrigins![i]); + if (logs is not null) + b.ConfigureLogging(l => l.AddProvider(logs)); }); return factory.CreateClient(); } - private static HttpRequestMessage McpRequest(string? bearer = null, string? origin = null) + private static HttpRequestMessage McpRequest(string? bearer = null, string? origin = null, string body = ListDatabasesCall) { var request = new HttpRequestMessage(HttpMethod.Post, "/mcp") { - Content = new StringContent(ListDatabasesCall, Encoding.UTF8, "application/json") + Content = new StringContent(body, Encoding.UTF8, "application/json") }; request.Headers.Accept.ParseAdd("application/json"); request.Headers.Accept.ParseAdd("text/event-stream"); @@ -104,6 +127,54 @@ public async Task With_a_token_configured_mcp_requires_it() var right = await client.SendAsync(McpRequest(bearer: "s3cret")); Assert.Equal(HttpStatusCode.OK, right.StatusCode); Assert.Contains("samplePostgres", await right.Content.ReadAsStringAsync()); + + var otherAgent = await client.SendAsync(McpRequest(bearer: "s3cret-billing")); + Assert.Equal(HttpStatusCode.OK, otherAgent.StatusCode); + } + + private const string DeleteCall = + """{"jsonrpc":"2.0","id":1,"method":"tools/call","params":{"name":"query_database","arguments":{"dbName":"samplePostgres","sql":"DELETE FROM orders"}}}"""; + + [Fact] + public async Task Logs_each_call_under_the_agent_whose_token_it_carries() + { + var logs = new LogCollector(); + var client = Client(token: "s3cret", logs: logs); + + await client.SendAsync(McpRequest(bearer: "s3cret", body: DeleteCall)); + await client.SendAsync(new HttpRequestMessage(HttpMethod.Post, "/api/query") + { + Content = new StringContent("""{"dbName":"nope","sql":"SELECT 1"}""", Encoding.UTF8, "application/json"), + Headers = { Authorization = new AuthenticationHeaderValue("Bearer", "s3cret-billing") } + }); + + var refused = Assert.Single(logs.Messages, m => m.Text.Contains("DELETE FROM orders")); + Assert.Equal(LogLevel.Warning, refused.Level); + Assert.Contains("Refused query: DELETE FROM orders on samplePostgres for reporting:", refused.Text); + Assert.Contains(logs.Messages, m => m.Text.Contains("Refused query: SELECT 1 on nope for billing:")); + } + + [Fact] + public async Task Without_tokens_calls_are_logged_as_unauthenticated() + { + var logs = new LogCollector(); + + await Client(logs: logs).SendAsync(McpRequest(body: DeleteCall)); + + Assert.Contains(logs.Messages, m => m.Text.Contains("on samplePostgres for unauthenticated:")); + } + + [Fact] + public async Task Logs_requests_rejected_for_their_token() + { + var logs = new LogCollector(); + + await Client(token: "s3cret", logs: logs).SendAsync(McpRequest(bearer: "guess")); + + var rejected = Assert.Single(logs.Messages, m => m.Text.StartsWith("Rejected POST /mcp")); + Assert.Equal(LogLevel.Warning, rejected.Level); + Assert.Contains("missing or unknown bearer token", rejected.Text); + Assert.DoesNotContain(logs.Messages, m => m.Text.Contains("guess")); } [Fact] @@ -132,4 +203,18 @@ public async Task Accepts_allowed_origins() var response = await Client(allowedOrigins: ["https://app.example"]).SendAsync(McpRequest(origin: "https://app.example")); Assert.Equal(HttpStatusCode.OK, response.StatusCode); } + + internal sealed class LogCollector : ILoggerProvider, ILogger + { + public List<(LogLevel Level, string Text)> Messages { get; } = []; + public ILogger CreateLogger(string categoryName) => this; + public IDisposable? BeginScope(TState state) where TState : notnull => null; + public bool IsEnabled(LogLevel logLevel) => true; + public void Log(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func formatter) + { + lock (Messages) + Messages.Add((logLevel, formatter(state, exception))); + } + public void Dispose() { } + } } From 3a2a212c1238d5c84044bd67319138b7e7b26a2b Mon Sep 17 00:00:00 2001 From: Scott Stauffer Date: Sun, 18 Oct 2026 08:31:59 -0500 Subject: [PATCH 2/2] fix: log list_databases, and a describe_table that finds no table as a failure describe_table logged a missing or ambiguous table as having run, with 0 rows. The work passed to RunAsync now returns a result, so describe reports that outcome as an error and it is logged as a failure. list_databases, which logged nothing, now logs the agent and how many databases it listed. --- README.md | 4 +- Services/QueryService.cs | 42 ++++++++++--------- Tools/SqlTools.cs | 3 +- tests/SqlMcp.Tests/HttpSecurityTests.cs | 2 + .../QueryServiceIntegrationTests.cs | 7 +++- 5 files changed, 35 insertions(+), 23 deletions(-) diff --git a/README.md b/README.md index d125987..dc52c67 100644 --- a/README.md +++ b/README.md @@ -133,7 +133,7 @@ For local development, put real connection strings in `appsettings.Development.j ### Logging -Each tool call and `/api/query` request is logged by `SqlMcp.Services.QueryService`: the agent, the database, the SQL (or the schema lookup), the names of any parameters, how long it took and how many rows it returned. Parameter values are never logged. +Each tool call and `/api/query` request is logged by `SqlMcp.Services.QueryService`: the agent, the database, the SQL (or the schema lookup), the names of any parameters, how long it took and how many rows it returned (for `list_databases`, the agent and how many databases there are). Parameter values are never logged. ``` 2026-10-18T14:02:11.384Z info: SqlMcp.Services.QueryService[0] @@ -142,7 +142,7 @@ Each tool call and `/api/query` request is logged by `SqlMcp.Services.QueryServi Refused query: DELETE FROM orders on prod for reporting: Only SELECT queries (including CTEs) are permitted. ``` -The agent is the name its token has in `App:AgentTokens`. Over stdio, or over HTTP without agent tokens, it is `unauthenticated`. Calls refused before they reach the database (an unknown database, a statement that isn't a read, invalid parameters) are logged as warnings with the SQL, so the log shows what each agent tried as well as what ran. Failures are warnings too. A request with a missing or unknown token is logged as a warning by `SqlMcp.Http.HttpSecurity`, with its path and remote address but not the token. +The agent is the name its token has in `App:AgentTokens`. Over stdio, or over HTTP without agent tokens, it is `unauthenticated`. Calls refused before they reach the database (an unknown database, a statement that isn't a read, invalid parameters) are logged as warnings with the SQL, so the log shows what each agent tried as well as what ran. Failures are warnings too, including a `describe_table` for a table that doesn't exist or matches more than one. A request with a missing or unknown token is logged as a warning by `SqlMcp.Http.HttpSecurity`, with its path and remote address but not the token. `appsettings.Production.json` keeps `QueryService` at `Information` while everything else is at `Warning`; set it to `Warning` to log only refusals and failures. It also starts each entry with the UTC time; under systemd, journald records the time instead. In stdio mode all logs go to stderr. diff --git a/Services/QueryService.cs b/Services/QueryService.cs index 293c6cd..60d2156 100644 --- a/Services/QueryService.cs +++ b/Services/QueryService.cs @@ -169,7 +169,7 @@ public async Task> ExecuteAsync(QueryRequest req, st cmd.CommandText = verdict.Sql; foreach (var (name, value) in parameters) QueryParameters.Add(cmd, db.Provider, name, value); - return await ReadResultAsync(cmd, ct); + return Ok(await ReadResultAsync(cmd, ct)); }, ct); } @@ -186,9 +186,9 @@ public async Task> ListTablesAsync(string dbName, stri return await RunAsync(db, operation, agent, async newCommand => { var tables = await SchemaCatalog.FindTablesAsync(newCommand, db.Provider, NullIfBlank(schema), null, _maxRows, ct); - return tables.Count > _maxRows + return Ok(tables.Count > _maxRows ? new TableList([.. tables.Take(_maxRows)], Truncated: true) - : new TableList([.. tables]); + : new TableList([.. tables])); }, ct); } @@ -211,8 +211,7 @@ public async Task> DescribeTableAsync( if (schema is null && dot > 0 && dot < table.Length - 1) (schema, table) = (table[..dot], table[(dot + 1)..]); - string? notFound = null; - var result = await RunAsync(db, $"describe_table {(schema is null ? table : $"{schema}.{table}")}", agent, async newCommand => + return await RunAsync(db, $"describe_table {(schema is null ? table : $"{schema}.{table}")}", agent, async newCommand => { var matches = await SchemaCatalog.FindTablesAsync(newCommand, db.Provider, schema, table, 50, ct); @@ -223,25 +222,24 @@ public async Task> DescribeTableAsync( if (matches.Count != 1) { var name = schema is null ? table : $"{schema}.{table}"; - notFound = matches.Count == 0 + return new Result(null, matches.Count == 0 ? $"Table '{name}' was not found in database '{db.Name}', or the login can't read it. Call list_tables to see what it can read." - : $"'{name}' matches more than one table: {string.Join(", ", matches.Select(m => $"{m.Schema}.{m.Name}"))}. Pass schema to choose one."; - return null!; + : $"'{name}' matches more than one table: {string.Join(", ", matches.Select(m => $"{m.Schema}.{m.Name}"))}. Pass schema to choose one."); } var match = matches[0]; var columns = await SchemaCatalog.GetColumnsAsync(newCommand, db.Provider, match, ct); - return new TableDescription(match.Schema, match.Name, match.Type, columns); + return Ok(new TableDescription(match.Schema, match.Name, match.Type, columns)); }, ct); - - return notFound is null ? result : new(null!, notFound); } /// /// Connects, checks the login, and runs work inside a read-only transaction that is - /// always rolled back. Commands from newCommand are bound to that transaction. + /// always rolled back. Commands from newCommand are bound to that transaction. work + /// returns an error for an outcome that isn't a database error but still failed, such + /// as a table that wasn't found, so it's logged as a failure. /// - private async Task> RunAsync(DbConfig db, string operation, string? agent, Func, Task> work, CancellationToken ct, bool log = true) + private async Task> RunAsync(DbConfig db, string operation, string? agent, Func, Task>> work, CancellationToken ct, bool log = true) { if (MissingPassword(db) is { } missing) { @@ -295,6 +293,8 @@ private Result Refuse(string operation, string? dbName, string? ag private static string Who(string? agent) => agent ?? "unauthenticated"; + private static Result Ok(T value) => new(value, null); + private static int CountRows(object? value) => value switch { QueryResult q => q.Rows.Length, @@ -305,7 +305,7 @@ private Result Refuse(string operation, string? dbName, string? ag private static bool IsTruncated(object? value) => value is QueryResult { Truncated: true } or TableList { Truncated: true }; - private async Task> RunWithRetryAsync(DbConfig db, Func, Task> work, CancellationToken ct) + private async Task> RunWithRetryAsync(DbConfig db, Func, Task>> work, CancellationToken ct) { for (int attempt = 0; ; attempt++) { @@ -344,7 +344,7 @@ private async Task> RunWithRetryAsync(DbConfig db, Func false, }; - private async Task> RunOnceAsync(DbConfig db, Func, Task> work, CancellationToken ct) + private async Task> RunOnceAsync(DbConfig db, Func, Task>> work, CancellationToken ct) { await using var conn = db.GetFactory().CreateConnection()!; conn.ConnectionString = ResolveConnectionString(db); @@ -356,13 +356,13 @@ private async Task> RunOnceAsync(DbConfig db, Func + return await work(() => { var cmd = conn.CreateCommand(); cmd.Transaction = tx; cmd.CommandTimeout = _queryTimeoutSeconds; return cmd; - }), null!); + }); } finally { @@ -401,7 +401,11 @@ private async Task IsLoginReadOnlyAsync(DbConfig db, DbConnection conn, Ca return audit.Findings.Count == 0; } - public string[] ListDatabases() => [.. _dbs.Select(d => d.Name)]; + public string[] ListDatabases(string? agent = null) + { + _logger.LogInformation("Listed {Count} databases for {Agent}.", _dbs.Count, Who(agent)); + return [.. _dbs.Select(d => d.Name)]; + } /// /// Connects to every database, runs the login audit and opens the read-only @@ -411,7 +415,7 @@ public async Task> CheckDatabasesAsync(CancellationTo { var checks = _dbs.Select(async db => { - var result = await RunAsync(db, "readiness check", null, _ => Task.FromResult(true), ct, log: false); + var result = await RunAsync(db, "readiness check", null, _ => Task.FromResult(Ok(true)), ct, log: false); return (db.Name, Status: result.Error ?? "ok"); }); return (await Task.WhenAll(checks)).ToDictionary(c => c.Name, c => c.Status); diff --git a/Tools/SqlTools.cs b/Tools/SqlTools.cs index 9ef0cca..3c2d516 100644 --- a/Tools/SqlTools.cs +++ b/Tools/SqlTools.cs @@ -19,7 +19,8 @@ public sealed class SqlTools(QueryService svc) [McpServerTool(Name = "list_databases", ReadOnly = true, Idempotent = true)] [Description("List the names of the databases this server can query.")] - public string ListDatabases() => JsonSerializer.Serialize(svc.ListDatabases(), JsonOptions); + public string ListDatabases(RequestContext context) => + JsonSerializer.Serialize(svc.ListDatabases(Agent(context)), JsonOptions); [McpServerTool(Name = "list_tables", ReadOnly = true, Idempotent = true)] [Description("List the tables and views the database login can read, as JSON. System schemas are left out unless named.")] diff --git a/tests/SqlMcp.Tests/HttpSecurityTests.cs b/tests/SqlMcp.Tests/HttpSecurityTests.cs index a360e4c..7caa64d 100644 --- a/tests/SqlMcp.Tests/HttpSecurityTests.cs +++ b/tests/SqlMcp.Tests/HttpSecurityTests.cs @@ -141,6 +141,7 @@ public async Task Logs_each_call_under_the_agent_whose_token_it_carries() var logs = new LogCollector(); var client = Client(token: "s3cret", logs: logs); + await client.SendAsync(McpRequest(bearer: "s3cret")); await client.SendAsync(McpRequest(bearer: "s3cret", body: DeleteCall)); await client.SendAsync(new HttpRequestMessage(HttpMethod.Post, "/api/query") { @@ -152,6 +153,7 @@ await client.SendAsync(new HttpRequestMessage(HttpMethod.Post, "/api/query") Assert.Equal(LogLevel.Warning, refused.Level); Assert.Contains("Refused query: DELETE FROM orders on samplePostgres for reporting:", refused.Text); Assert.Contains(logs.Messages, m => m.Text.Contains("Refused query: SELECT 1 on nope for billing:")); + Assert.Contains(logs.Messages, m => m.Text == "Listed 4 databases for reporting."); } [Fact] diff --git a/tests/SqlMcp.Tests/QueryServiceIntegrationTests.cs b/tests/SqlMcp.Tests/QueryServiceIntegrationTests.cs index 3126136..534aef7 100644 --- a/tests/SqlMcp.Tests/QueryServiceIntegrationTests.cs +++ b/tests/SqlMcp.Tests/QueryServiceIntegrationTests.cs @@ -534,10 +534,15 @@ public async Task Reports_a_missing_table(DbProvider provider) { var db = RequireDb(provider); - var result = await Service(db).DescribeTableAsync("test", "sqlmcp_no_such_table", null); + var logger = new ListLogger(); + + var result = await Service(db, logger: logger).DescribeTableAsync("test", "sqlmcp_no_such_table", null, agent: "reporting"); Assert.NotNull(result.Error); Assert.Contains("list_tables", result.Error); + var failed = Assert.Single(logger.Messages, m => m.Text.Contains("describe_table sqlmcp_no_such_table")); + Assert.Equal(LogLevel.Warning, failed.Level); + Assert.StartsWith("Failed describe_table sqlmcp_no_such_table on test for reporting", failed.Text); } [SkippableTheory]