From e75e40e85aada82a6d8278828e10bd8c6e59ab68 Mon Sep 17 00:00:00 2001 From: Widthdom Date: Mon, 25 May 2026 05:31:07 +0900 Subject: [PATCH 1/7] Propagate MCP request ids in diagnostics (#1814) --- DEVELOPER_GUIDE.md | 8 ++ changelog.d/unreleased/1814.fixed.md | 17 +++++ src/CodeIndex/Mcp/McpServer.cs | 98 ++++++++++++++++++++++--- tests/CodeIndex.Tests/McpServerTests.cs | 16 ++++ 4 files changed, 127 insertions(+), 12 deletions(-) create mode 100644 changelog.d/unreleased/1814.fixed.md diff --git a/DEVELOPER_GUIDE.md b/DEVELOPER_GUIDE.md index 5544cb777a..9911e954b4 100644 --- a/DEVELOPER_GUIDE.md +++ b/DEVELOPER_GUIDE.md @@ -176,6 +176,14 @@ Operators can override the defaults with environment variables: After a successful `cdidx index` run, the writer refreshes SQLite planner statistics so large repositories do not rely on default selectivity estimates for `search`, `references`, `callers`, and related joins. A brand-new index database runs full `ANALYZE` once after the initial population; later successful index runs use SQLite's lighter `PRAGMA optimize`. This maintenance is best-effort and never changes the schema contract. +### MCP request correlation + +Each JSON-RPC MCP request gets a server-generated `correlation_id` in addition to the client-controlled JSON-RPC `id`. Error responses include it in `error.data.correlation_id` or tool-error `result.structuredContent.correlation_id`. The serialized JSON-RPC id is echoed as `request_id` in the same metadata when one exists. MCP stderr diagnostics are prefixed with `[rid= cid=]` when a request context exists. + +### MCP リクエスト相関 + +各 JSON-RPC MCP リクエストには、クライアント制御の JSON-RPC `id` とは別に、サーバー生成の `correlation_id` が割り当てられます。エラーレスポンスでは `error.data.correlation_id` またはツールエラーの `result.structuredContent.correlation_id` に含まれます。JSON-RPC id がある場合は、同じメタデータにシリアライズ済みの値を `request_id` として入れます。MCP stderr 診断は、リクエストコンテキストがある場合に `[rid= cid=]` で prefix されます。 + ## Database schema Persisted SHA-256 hashes are lowercase hexadecimal strings. New hash emitters diff --git a/changelog.d/unreleased/1814.fixed.md b/changelog.d/unreleased/1814.fixed.md new file mode 100644 index 0000000000..071baf5bbb --- /dev/null +++ b/changelog.d/unreleased/1814.fixed.md @@ -0,0 +1,17 @@ +--- +category: fixed +issues: + - 1814 +affected: + - src/CodeIndex/Mcp/McpServer.cs + - tests/CodeIndex.Tests/McpServerTests.cs + - DEVELOPER_GUIDE.md +--- + +## English + +- **MCP request IDs now flow into diagnostics (#1814)** — MCP stderr diagnostics and error payloads now include request/correlation metadata so operators can tie failures back to the JSON-RPC request that produced them. + +## 日本語 + +- **MCP request ID が診断情報へ伝播するようになりました (#1814)** — MCP の stderr 診断とエラーペイロードに request/correlation metadata を含め、どの JSON-RPC リクエストが失敗を発生させたか追跡できるようにしました。 diff --git a/src/CodeIndex/Mcp/McpServer.cs b/src/CodeIndex/Mcp/McpServer.cs index 4b047619d5..574d40ec21 100644 --- a/src/CodeIndex/Mcp/McpServer.cs +++ b/src/CodeIndex/Mcp/McpServer.cs @@ -61,6 +61,7 @@ public partial class McpServer : IDisposable private readonly AsyncLocal _currentRequestToken = new(); private readonly AsyncLocal?> _currentOutOfBandFrameWriter = new(); private readonly AsyncLocal?> _deferredFrameLogs = new(); + private static readonly AsyncLocal CurrentCorrelationContext = new(); private bool _running = true; // Per-session DbContext reused across MCP tool calls. Holding the connection open // avoids reopening SQLite, reapplying pragmas, and re-registering every SQL function @@ -608,7 +609,7 @@ internal async Task ProcessLineAsync(string line, TextWriter writer) } catch (Exception ex) when (ex is IOException or ObjectDisposedException or OperationCanceledException) { - Console.Error.WriteLine(BuildResponseWriteErrorLog(ex.Message)); + WriteMcpLogLine(BuildResponseWriteErrorLog(ex.Message)); FlushDeferredFrameLogs(); } } @@ -629,11 +630,11 @@ private static async Task WriteFrameSafelyAsync(IMcpTransport transport, string? } catch (OperationCanceledException) when (!cancellationToken.IsCancellationRequested) { - Console.Error.WriteLine(BuildResponseWriteErrorLog("write operation was canceled")); + WriteMcpLogLine(BuildResponseWriteErrorLog("write operation was canceled")); } catch (Exception ex) when (ex is IOException or ObjectDisposedException) { - Console.Error.WriteLine(BuildResponseWriteErrorLog(ex.Message)); + WriteMcpLogLine(BuildResponseWriteErrorLog(ex.Message)); } } @@ -731,7 +732,7 @@ private string SerializeResponseOrFallback(JsonNode response, bool hasId, JsonNo } private void DeferFrameLog(string message) - => DeferFrameLog(() => Console.Error.WriteLine(message)); + => DeferFrameLog(() => WriteMcpLogLine(message)); private void DeferFrameLog(Action writeLog) { @@ -759,6 +760,34 @@ private void FlushDeferredFrameLogs() log(); } + private static void WriteMcpLogLine(string message) + { + var line = AddCorrelationPrefix(message); + try + { + Console.Error.WriteLine(line); + } + catch (Exception ex) when (ex is IOException or ObjectDisposedException) + { + // Best-effort diagnostics: a closed redirected stderr must not break the MCP request. + } + GlobalToolLog.Info(line); + } + + private static string AddCorrelationPrefix(string message) + { + var context = CurrentCorrelationContext.Value; + if (context is null) + return message; + + var prefix = context.RequestId == null + ? $"[cid={context.CorrelationId}] " + : $"[rid={context.RequestId} cid={context.CorrelationId}] "; + return message.StartsWith("[cdidx-mcp] ", StringComparison.Ordinal) + ? "[cdidx-mcp] " + prefix + message["[cdidx-mcp] ".Length..] + : prefix + message; + } + private static void ExtractResponseId(JsonNode request, out bool hasId, out JsonNode? id) { if (request is JsonObject obj) @@ -817,13 +846,15 @@ private static string BuildMinimalInternalErrorResponse(bool hasId, JsonNode? id suggestion: "JSON-RPC 2.0 `id` must be a string, integer, or null. Booleans/objects/arrays are not allowed.", retrySafe: false); + using var correlationScope = hasId ? BeginRequestCorrelation(id) : null; + if (method == "$/cancelRequest" || method == "notifications/cancelled") { var cancelAuth = _authenticator.Authenticate(request); if (cancelAuth.IsAuthenticated) TryCancelRequest(request["params"]); else - Console.Error.WriteLine(BuildAuthFailureLog(method, cancelAuth.FailureReason)); + WriteMcpLogLine(BuildAuthFailureLog(method, cancelAuth.FailureReason)); return null; } @@ -843,7 +874,7 @@ private static string BuildMinimalInternalErrorResponse(bool hasId, JsonNode? id if (string.Equals(method, "notifications/shutdown", StringComparison.Ordinal) || string.Equals(method, "notifications/exit", StringComparison.Ordinal)) { - Console.Error.WriteLine($"[cdidx-mcp] Received {method}; draining in-flight work and shutting down."); + WriteMcpLogLine($"[cdidx-mcp] Received {method}; draining in-flight work and shutting down."); _running = false; try { @@ -861,7 +892,7 @@ private static string BuildMinimalInternalErrorResponse(bool hasId, JsonNode? id if (!hasId) { if (method != null && method.StartsWith("notifications/", StringComparison.OrdinalIgnoreCase)) - Console.Error.WriteLine(BuildUnknownNotificationLog(method)); + WriteMcpLogLine(BuildUnknownNotificationLog(method)); return null; } @@ -942,6 +973,36 @@ private JsonNode DispatchWithRequestCancellation(JsonNode? id, Func ac } } + private static IDisposable BeginRequestCorrelation(JsonNode? id) + { + var previous = CurrentCorrelationContext.Value; + CurrentCorrelationContext.Value = new RequestCorrelationContext( + SerializeRequestId(id), + Guid.NewGuid().ToString("D")); + return new CorrelationScope(previous); + } + + private sealed record RequestCorrelationContext(string? RequestId, string CorrelationId); + + private sealed class CorrelationScope : IDisposable + { + private readonly RequestCorrelationContext? _previous; + private bool _disposed; + + public CorrelationScope(RequestCorrelationContext? previous) + { + _previous = previous; + } + + public void Dispose() + { + if (_disposed) + return; + CurrentCorrelationContext.Value = _previous; + _disposed = true; + } + } + private void TryCancelRequest(JsonNode? cancelParams) { var requestId = cancelParams?["id"] ?? cancelParams?["requestId"]; @@ -1436,7 +1497,7 @@ private static JsonObject CreateUnsupportedProtocolError(JsonNode? id, string? r McpErrorEnvelope.CategoryInvalidArgument, "Reissue `initialize` with one of `data.supportedVersions` in `params.protocolVersion`, or omit the field to fall back to the server's newest supported version.", retrySafe: false, - extra); + AddCorrelationData(extra)); var error = new JsonObject { @@ -1493,7 +1554,7 @@ internal static JsonObject CreateRateLimitedErrorResponse(JsonNode? id, string t category: McpErrorEnvelope.CategoryRateLimited, suggestion: $"Back off for at least {retryAfterMs} ms before retrying this tool, or raise {RateLimiterOptions.RpsEnvVar} / {RateLimiterOptions.BurstEnvVar} on the server.", retrySafe: true, - extraData: extraData); + extraData: AddCorrelationData(extraData)); var error = new JsonObject { ["code"] = -32000, @@ -1641,7 +1702,7 @@ private JsonNode HandleToolsCall(JsonNode? id, JsonNode? callParams) // パスや索引内容が漏れる（#1530）。 DeferFrameLog(() => { - Console.Error.WriteLine(BuildToolErrorLog(toolName, ex.Message)); + WriteMcpLogLine(BuildToolErrorLog(toolName, ex.Message)); Database.DbDebug.DumpToStderr(ex); }); metricsError = ex.GetType().Name; @@ -2096,6 +2157,19 @@ private static JsonObject CreateSuccessResponse(bool hasId, JsonNode? id, JsonNo return response; } + private static JsonObject? AddCorrelationData(JsonObject? extraData) + { + var context = CurrentCorrelationContext.Value; + if (context is null) + return extraData; + + var data = extraData is null ? new JsonObject() : (JsonObject)extraData.DeepClone(); + data["correlation_id"] = context.CorrelationId; + if (context.RequestId != null) + data["request_id"] = context.RequestId; + return data; + } + private static JsonObject CreateErrorResponse(JsonNode? id, int code, string message, string category, string suggestion, bool retrySafe, JsonObject? extraData = null) => CreateErrorResponse(id is not null, id, code, message, category, suggestion, retrySafe, extraData); @@ -2117,7 +2191,7 @@ private static JsonObject CreateErrorResponse(bool hasId, JsonNode? id, int code { ["code"] = code, ["message"] = message, - ["data"] = McpErrorEnvelope.BuildData(category, suggestion, retrySafe, extraData), + ["data"] = McpErrorEnvelope.BuildData(category, suggestion, retrySafe, AddCorrelationData(extraData)), } }; if (hasId) @@ -2210,7 +2284,7 @@ private static JsonObject CreateToolErrorResponse(bool hasId, JsonNode? id, stri } }, ["isError"] = true, - ["structuredContent"] = McpErrorEnvelope.BuildData(category, suggestion, retrySafe, extraData), + ["structuredContent"] = McpErrorEnvelope.BuildData(category, suggestion, retrySafe, AddCorrelationData(extraData)), }; if (similarValues != null && similarValues.Count > 0) { diff --git a/tests/CodeIndex.Tests/McpServerTests.cs b/tests/CodeIndex.Tests/McpServerTests.cs index 1c1b40963b..aa976f02b8 100644 --- a/tests/CodeIndex.Tests/McpServerTests.cs +++ b/tests/CodeIndex.Tests/McpServerTests.cs @@ -372,6 +372,18 @@ public void CancelRequest_UnknownOrMalformedId_IsNotificationOnly() Assert.Null(_server.HandleMessage(missing)); } + [Fact] + public void ToolCall_ErrorIncludesCorrelationData() + { + var request = JsonNode.Parse("""{"jsonrpc":"2.0","id":42,"method":"tools/call","params":{"name":"search","arguments":{}}}""")!; + + var response = _server.HandleMessage(request)!; + + var structured = response["result"]!["structuredContent"]!; + Assert.Equal("42", structured["request_id"]!.GetValue()); + Assert.False(string.IsNullOrWhiteSpace(structured["correlation_id"]!.GetValue())); + } + [Theory] [InlineData("search")] [InlineData("definition")] @@ -823,6 +835,10 @@ public void TokenAuthenticator_WrongLengthToken_UniformWireResponse() var shortResp = server.HandleMessage(shortReq)!; var sameLenResp = server.HandleMessage(sameLenReq)!; + ((JsonObject)shortResp["error"]!["data"]!).Remove("correlation_id"); + ((JsonObject)sameLenResp["error"]!["data"]!).Remove("correlation_id"); + ((JsonObject)shortResp["error"]!["data"]!).Remove("request_id"); + ((JsonObject)sameLenResp["error"]!["data"]!).Remove("request_id"); Assert.Equal(shortResp.ToJsonString(), sameLenResp.ToJsonString()); Assert.Equal(-32001, shortResp["error"]!["code"]!.GetValue()); } From 5f2177913c372fe93d95f60e8ed8f71ed0feeaca Mon Sep 17 00:00:00 2001 From: Widthdom Date: Mon, 25 May 2026 05:33:43 +0900 Subject: [PATCH 2/7] Expose MCP correlation ids in responses (#1897) --- DEVELOPER_GUIDE.md | 4 ++-- changelog.d/unreleased/1897.fixed.md | 18 +++++++++++++++++ src/CodeIndex/Mcp/McpServer.cs | 25 +++++++++++++++++++++++ src/CodeIndex/Mcp/McpToolHandlers.cs | 6 ++++++ tests/CodeIndex.Tests/McpServerTests.cs | 27 +++++++++++++++++++++++++ 5 files changed, 78 insertions(+), 2 deletions(-) create mode 100644 changelog.d/unreleased/1897.fixed.md diff --git a/DEVELOPER_GUIDE.md b/DEVELOPER_GUIDE.md index 9911e954b4..1ffea37ef7 100644 --- a/DEVELOPER_GUIDE.md +++ b/DEVELOPER_GUIDE.md @@ -178,11 +178,11 @@ After a successful `cdidx index` run, the writer refreshes SQLite planner statis ### MCP request correlation -Each JSON-RPC MCP request gets a server-generated `correlation_id` in addition to the client-controlled JSON-RPC `id`. Error responses include it in `error.data.correlation_id` or tool-error `result.structuredContent.correlation_id`. The serialized JSON-RPC id is echoed as `request_id` in the same metadata when one exists. MCP stderr diagnostics are prefixed with `[rid= cid=]` when a request context exists. +Each JSON-RPC MCP request gets a server-generated `correlation_id` in addition to the client-controlled JSON-RPC `id`. Successful MCP responses include it under `result._meta.correlation_id`, and error responses include it in `error.data.correlation_id` or tool-error `result.structuredContent.correlation_id`. The serialized JSON-RPC id is echoed as `request_id` in the same metadata when one exists. `batch_query` assigns child correlation IDs to each slot by suffixing the parent value with `.1`, `.2`, and so on. MCP stderr diagnostics are prefixed with `[rid= cid=]` when a request context exists. ### MCP リクエスト相関 -各 JSON-RPC MCP リクエストには、クライアント制御の JSON-RPC `id` とは別に、サーバー生成の `correlation_id` が割り当てられます。エラーレスポンスでは `error.data.correlation_id` またはツールエラーの `result.structuredContent.correlation_id` に含まれます。JSON-RPC id がある場合は、同じメタデータにシリアライズ済みの値を `request_id` として入れます。MCP stderr 診断は、リクエストコンテキストがある場合に `[rid= cid=]` で prefix されます。 +各 JSON-RPC MCP リクエストには、クライアント制御の JSON-RPC `id` とは別に、サーバー生成の `correlation_id` が割り当てられます。成功レスポンスでは `result._meta.correlation_id`、エラーレスポンスでは `error.data.correlation_id` またはツールエラーの `result.structuredContent.correlation_id` に含まれます。JSON-RPC id がある場合は、同じメタデータにシリアライズ済みの値を `request_id` として入れます。`batch_query` は親の値に `.1`、`.2` のような suffix を付けた子 correlation ID を各スロットに割り当てます。MCP stderr 診断は、リクエストコンテキストがある場合に `[rid= cid=]` で prefix されます。 ## Database schema diff --git a/changelog.d/unreleased/1897.fixed.md b/changelog.d/unreleased/1897.fixed.md new file mode 100644 index 0000000000..2a4e7702e8 --- /dev/null +++ b/changelog.d/unreleased/1897.fixed.md @@ -0,0 +1,18 @@ +--- +category: fixed +issues: + - 1897 +affected: + - src/CodeIndex/Mcp/McpServer.cs + - src/CodeIndex/Mcp/McpToolHandlers.cs + - tests/CodeIndex.Tests/McpServerTests.cs + - DEVELOPER_GUIDE.md +--- + +## English + +- **MCP responses now expose stable correlation IDs (#1897)** — each MCP request now receives a server-generated correlation ID, successful responses echo it under `_meta`, errors include it in structured data, and `batch_query` slots get child IDs. + +## 日本語 + +- **MCP レスポンスが安定した correlation ID を返すようになりました (#1897)** — MCP リクエストごとにサーバー生成の correlation ID を割り当て、成功レスポンスは `_meta`、エラーは構造化データに含め、`batch_query` の各スロットにも子 ID を付与します。 diff --git a/src/CodeIndex/Mcp/McpServer.cs b/src/CodeIndex/Mcp/McpServer.cs index 574d40ec21..a682010c3f 100644 --- a/src/CodeIndex/Mcp/McpServer.cs +++ b/src/CodeIndex/Mcp/McpServer.cs @@ -982,6 +982,17 @@ private static IDisposable BeginRequestCorrelation(JsonNode? id) return new CorrelationScope(previous); } + private static IDisposable BeginChildCorrelation(int childIndex) + { + var previous = CurrentCorrelationContext.Value; + var requestId = previous?.RequestId; + var correlationId = previous == null + ? Guid.NewGuid().ToString("D") + : $"{previous.CorrelationId}.{childIndex.ToString(System.Globalization.CultureInfo.InvariantCulture)}"; + CurrentCorrelationContext.Value = new RequestCorrelationContext(requestId, correlationId); + return new CorrelationScope(previous); + } + private sealed record RequestCorrelationContext(string? RequestId, string CorrelationId); private sealed class CorrelationScope : IDisposable @@ -2147,6 +2158,7 @@ private static JsonObject CreateSuccessResponse(JsonNode? id, JsonNode result) private static JsonObject CreateSuccessResponse(bool hasId, JsonNode? id, JsonNode result) { + AddResponseMeta(result); var response = new JsonObject { ["jsonrpc"] = "2.0", @@ -2157,6 +2169,19 @@ private static JsonObject CreateSuccessResponse(bool hasId, JsonNode? id, JsonNo return response; } + private static void AddResponseMeta(JsonNode result) + { + var context = CurrentCorrelationContext.Value; + if (context is null || result is not JsonObject obj) + return; + + var meta = obj["_meta"] as JsonObject ?? new JsonObject(); + meta["correlation_id"] = context.CorrelationId; + if (context.RequestId != null) + meta["request_id"] = context.RequestId; + obj["_meta"] = meta; + } + private static JsonObject? AddCorrelationData(JsonObject? extraData) { var context = CurrentCorrelationContext.Value; diff --git a/src/CodeIndex/Mcp/McpToolHandlers.cs b/src/CodeIndex/Mcp/McpToolHandlers.cs index b85a640754..86c10c69e2 100644 --- a/src/CodeIndex/Mcp/McpToolHandlers.cs +++ b/src/CodeIndex/Mcp/McpToolHandlers.cs @@ -1493,6 +1493,7 @@ void AppendSlotError(string? toolName, JsonNode? toolArgs, Stopwatch slotStopwat var entry = new JsonObject { ["tool"] = toolName, + ["correlation_id"] = CurrentCorrelationContext.Value?.CorrelationId, ["args_summary"] = BuildArgsSummary(toolArgs), ["elapsed_ms"] = slotStopwatch.ElapsedMilliseconds, ["error"] = errorMessage, @@ -1537,6 +1538,7 @@ void AppendRateLimitedSlot(string? toolName, JsonNode? toolArgs, Stopwatch slotS var entry = new JsonObject { ["tool"] = toolName, + ["correlation_id"] = CurrentCorrelationContext.Value?.CorrelationId, ["args_summary"] = BuildArgsSummary(toolArgs), ["elapsed_ms"] = slotStopwatch.ElapsedMilliseconds, ["error"] = $"Rate limit exceeded for tool '{toolName}' (retry after {retryAfterMs} ms).", @@ -1550,8 +1552,11 @@ void AppendRateLimitedSlot(string? toolName, JsonNode? toolArgs, Stopwatch slotS failureCount++; } + var slotIndex = 0; foreach (var q in queries) { + slotIndex++; + using var slotCorrelation = BeginChildCorrelation(slotIndex); var toolName = q?["tool"]?.GetValue(); var toolArgs = q?["arguments"]; var slotStopwatch = Stopwatch.StartNew(); @@ -1709,6 +1714,7 @@ void AppendRateLimitedSlot(string? toolName, JsonNode? toolArgs, Stopwatch slotS var entry = new JsonObject { ["tool"] = toolName, + ["correlation_id"] = CurrentCorrelationContext.Value?.CorrelationId, ["args_summary"] = BuildArgsSummary(toolArgs), ["elapsed_ms"] = slotStopwatch.ElapsedMilliseconds, ["result"] = structured?.DeepClone(), diff --git a/tests/CodeIndex.Tests/McpServerTests.cs b/tests/CodeIndex.Tests/McpServerTests.cs index aa976f02b8..b0e2e42a87 100644 --- a/tests/CodeIndex.Tests/McpServerTests.cs +++ b/tests/CodeIndex.Tests/McpServerTests.cs @@ -384,6 +384,33 @@ public void ToolCall_ErrorIncludesCorrelationData() Assert.False(string.IsNullOrWhiteSpace(structured["correlation_id"]!.GetValue())); } + [Fact] + public void ToolCall_ResponseIncludesCorrelationMeta() + { + var request = JsonNode.Parse("""{"jsonrpc":"2.0","id":"abc","method":"tools/call","params":{"name":"ping","arguments":{}}}""")!; + + var response = _server.HandleMessage(request)!; + + var meta = response["result"]!["_meta"]!; + Assert.Equal("\"abc\"", meta["request_id"]!.GetValue()); + Assert.False(string.IsNullOrWhiteSpace(meta["correlation_id"]!.GetValue())); + } + + [Fact] + public void BatchQuery_SlotsIncludeChildCorrelationIds() + { + var request = JsonNode.Parse("""{"jsonrpc":"2.0","id":7,"method":"tools/call","params":{"name":"batch_query","arguments":{"queries":[{"tool":"ping","arguments":{}},{"tool":"languages","arguments":{}}]}}}""")!; + + var response = _server.HandleMessage(request)!; + + var results = response["result"]!["structuredContent"]!["results"]!.AsArray(); + var first = results[0]!["correlation_id"]!.GetValue(); + var second = results[1]!["correlation_id"]!.GetValue(); + Assert.EndsWith(".1", first, StringComparison.Ordinal); + Assert.EndsWith(".2", second, StringComparison.Ordinal); + Assert.NotEqual(first, second); + } + [Theory] [InlineData("search")] [InlineData("definition")] From 9073858b7ea2ab4cdcb014dfb7b80f0a7eeaaf76 Mon Sep 17 00:00:00 2001 From: Widthdom Date: Mon, 25 May 2026 05:35:54 +0900 Subject: [PATCH 3/7] Emit MCP tool invocation telemetry (#1898) --- DEVELOPER_GUIDE.md | 8 +++-- changelog.d/unreleased/1898.added.md | 17 +++++++++++ src/CodeIndex/Mcp/McpServer.cs | 29 ++++++++++++++++++ tests/CodeIndex.Tests/McpServerTests.cs | 39 +++++++++++++++++++++++++ 4 files changed, 91 insertions(+), 2 deletions(-) create mode 100644 changelog.d/unreleased/1898.added.md diff --git a/DEVELOPER_GUIDE.md b/DEVELOPER_GUIDE.md index 1ffea37ef7..3406bea4a7 100644 --- a/DEVELOPER_GUIDE.md +++ b/DEVELOPER_GUIDE.md @@ -178,11 +178,15 @@ After a successful `cdidx index` run, the writer refreshes SQLite planner statis ### MCP request correlation -Each JSON-RPC MCP request gets a server-generated `correlation_id` in addition to the client-controlled JSON-RPC `id`. Successful MCP responses include it under `result._meta.correlation_id`, and error responses include it in `error.data.correlation_id` or tool-error `result.structuredContent.correlation_id`. The serialized JSON-RPC id is echoed as `request_id` in the same metadata when one exists. `batch_query` assigns child correlation IDs to each slot by suffixing the parent value with `.1`, `.2`, and so on. MCP stderr diagnostics are prefixed with `[rid= cid=]` when a request context exists. +Each JSON-RPC MCP request gets a server-generated `correlation_id` in addition to the client-controlled JSON-RPC `id`. Successful MCP responses include it under `result._meta.correlation_id`, and error responses include it in `error.data.correlation_id` or tool-error `result.structuredContent.correlation_id`. The serialized JSON-RPC id is echoed as `request_id` in the same metadata when one exists. `batch_query` assigns child correlation IDs to each slot by suffixing the parent value with `.1`, `.2`, and so on. + +MCP stderr diagnostics are prefixed with `[rid= cid=]` when a request context exists. Every `tools/call` also emits one structured JSON line with `event: "mcp.tool.invocation"`, the tool name, elapsed milliseconds, status, result count when available, error metadata, argument keys, and argument lengths. Argument values are intentionally not logged in this telemetry line. ### MCP リクエスト相関 -各 JSON-RPC MCP リクエストには、クライアント制御の JSON-RPC `id` とは別に、サーバー生成の `correlation_id` が割り当てられます。成功レスポンスでは `result._meta.correlation_id`、エラーレスポンスでは `error.data.correlation_id` またはツールエラーの `result.structuredContent.correlation_id` に含まれます。JSON-RPC id がある場合は、同じメタデータにシリアライズ済みの値を `request_id` として入れます。`batch_query` は親の値に `.1`、`.2` のような suffix を付けた子 correlation ID を各スロットに割り当てます。MCP stderr 診断は、リクエストコンテキストがある場合に `[rid= cid=]` で prefix されます。 +各 JSON-RPC MCP リクエストには、クライアント制御の JSON-RPC `id` とは別に、サーバー生成の `correlation_id` が割り当てられます。成功レスポンスでは `result._meta.correlation_id`、エラーレスポンスでは `error.data.correlation_id` またはツールエラーの `result.structuredContent.correlation_id` に含まれます。JSON-RPC id がある場合は、同じメタデータにシリアライズ済みの値を `request_id` として入れます。`batch_query` は親の値に `.1`、`.2` のような suffix を付けた子 correlation ID を各スロットに割り当てます。 + +MCP stderr 診断は、リクエストコンテキストがある場合に `[rid= cid=]` で prefix されます。各 `tools/call` はさらに `event: "mcp.tool.invocation"` の構造化 JSON 行を 1 行出力し、tool 名、経過ミリ秒、status、取得できる場合の result count、エラーメタデータ、引数キー、引数長を含めます。この telemetry 行には引数値を記録しません。 ## Database schema diff --git a/changelog.d/unreleased/1898.added.md b/changelog.d/unreleased/1898.added.md new file mode 100644 index 0000000000..63edbbbe6e --- /dev/null +++ b/changelog.d/unreleased/1898.added.md @@ -0,0 +1,17 @@ +--- +category: added +issues: + - 1898 +affected: + - src/CodeIndex/Mcp/McpServer.cs + - tests/CodeIndex.Tests/McpServerTests.cs + - DEVELOPER_GUIDE.md +--- + +## English + +- **MCP tool invocation telemetry is emitted to stderr (#1898)** — every MCP `tools/call` now writes a structured `mcp.tool.invocation` event with timing, status, result-count, and redacted argument-shape metadata. + +## 日本語 + +- **MCP tool invocation telemetry を stderr に出力するようになりました (#1898)** — 各 MCP `tools/call` が、所要時間、status、result count、引数形状の redacted metadata を含む構造化 `mcp.tool.invocation` event を出力します。 diff --git a/src/CodeIndex/Mcp/McpServer.cs b/src/CodeIndex/Mcp/McpServer.cs index a682010c3f..eade49b9bd 100644 --- a/src/CodeIndex/Mcp/McpServer.cs +++ b/src/CodeIndex/Mcp/McpServer.cs @@ -1753,9 +1753,38 @@ private JsonNode HandleToolsCall(JsonNode? id, JsonNode? callParams) // 出力する。Stopwatch.Stop は冪等。TryEmitAudit 内部でベストエフォート化済み (#1562)。 metricsStopwatch.Stop(); TryEmitAudit(toolName, id, args, response, metricsStartedAt, metricsStopwatch.Elapsed.TotalMilliseconds, errorType: metricsError); + EmitToolInvocationTelemetry(toolName, args, response, metricsStartedAt, metricsStopwatch.Elapsed.TotalMilliseconds, metricsError); return response; } + private void EmitToolInvocationTelemetry(string toolName, JsonNode? args, JsonNode response, DateTimeOffset startedAt, double elapsedMs, string? errorType) + { + var context = CurrentCorrelationContext.Value; + var (errorCode, observedErrorType) = ExtractErrorCode(response); + var resultCount = ExtractResultCount(response); + var (argKeys, argLengths, _) = SanitizeArgs(args, includeValues: false); + var argsObject = new JsonObject(); + foreach (var pair in argLengths) + argsObject[pair.Key] = pair.Value; + + var evt = new JsonObject + { + ["event"] = "mcp.tool.invocation", + ["timestamp"] = startedAt.ToString("O", System.Globalization.CultureInfo.InvariantCulture), + ["tool"] = toolName, + ["request_id"] = context?.RequestId, + ["correlation_id"] = context?.CorrelationId, + ["elapsed_ms"] = Math.Round(elapsedMs, 3), + ["status"] = errorCode == 0 ? "success" : "error", + ["error_code"] = errorCode == 0 ? null : errorCode, + ["error_type"] = errorType ?? observedErrorType, + ["result_count"] = resultCount, + ["arg_keys"] = JsonSerializer.SerializeToNode(argKeys, _jsonOptions), + ["arg_lengths"] = argsObject, + }; + DeferFrameLog(() => WriteMcpLogLine(evt.ToJsonString(_jsonOptions))); + } + private static JsonNode? TryReadProgressToken(JsonNode? callParams) { var token = callParams?["_meta"]?["progressToken"]; diff --git a/tests/CodeIndex.Tests/McpServerTests.cs b/tests/CodeIndex.Tests/McpServerTests.cs index b0e2e42a87..bfc1d0215c 100644 --- a/tests/CodeIndex.Tests/McpServerTests.cs +++ b/tests/CodeIndex.Tests/McpServerTests.cs @@ -145,6 +145,45 @@ public async Task ProcessLineAsync_UsesLfTerminatorEvenWhenWriterNewLineIsCrLf() Assert.DoesNotContain("\r", response); } + [Fact] + public async Task ProcessLineAsync_ToolCallEmitsInvocationTelemetry() + { + using var writer = new StringWriter(); + using var error = new StringWriter(); + + Monitor.Enter(TestConsoleLock.Gate); + try + { + var previousError = Console.Error; + try + { + Console.SetError(error); + await _server.ProcessLineAsync("""{"jsonrpc":"2.0","id":123,"method":"tools/call","params":{"name":"ping","arguments":{}}}""", writer); + } + finally + { + Console.SetError(previousError); + } + } + finally + { + Monitor.Exit(TestConsoleLock.Gate); + } + + var line = error.ToString() + .Split('\n', StringSplitOptions.RemoveEmptyEntries) + .Single(l => l.Contains("\"event\":\"mcp.tool.invocation\"", StringComparison.Ordinal)); + var jsonStart = line.IndexOf('{'); + using var document = JsonDocument.Parse(line[jsonStart..]); + var root = document.RootElement; + Assert.Equal("mcp.tool.invocation", root.GetProperty("event").GetString()); + Assert.Equal("ping", root.GetProperty("tool").GetString()); + Assert.Equal("123", root.GetProperty("request_id").GetString()); + Assert.Equal("success", root.GetProperty("status").GetString()); + Assert.True(root.TryGetProperty("correlation_id", out var correlationId)); + Assert.False(string.IsNullOrWhiteSpace(correlationId.GetString())); + } + [Fact] public void Initialize_ReturnsProtocolVersion() { From 15bf561d7bb1fe8711dc37d80edef4b1605eecb9 Mon Sep 17 00:00:00 2001 From: Widthdom Date: Mon, 25 May 2026 05:42:27 +0900 Subject: [PATCH 4/7] Adjust MCP telemetry batch truncation coverage (#1898) --- tests/CodeIndex.Tests/McpServerTests.cs | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/tests/CodeIndex.Tests/McpServerTests.cs b/tests/CodeIndex.Tests/McpServerTests.cs index da6e82c72b..ec31d321cb 100644 --- a/tests/CodeIndex.Tests/McpServerTests.cs +++ b/tests/CodeIndex.Tests/McpServerTests.cs @@ -5760,7 +5760,7 @@ public void ToolsCall_RejectsOversizedPathArrays_Issue2028() public void ToolsCall_BatchQuery_TruncatesAggregateResponse_Issue1416() { var previous = Environment.GetEnvironmentVariable("CDIDX_MCP_BATCH_RESPONSE_MAX_BYTES"); - Environment.SetEnvironmentVariable("CDIDX_MCP_BATCH_RESPONSE_MAX_BYTES", "700"); + Environment.SetEnvironmentVariable("CDIDX_MCP_BATCH_RESPONSE_MAX_BYTES", "950"); try { InsertIndexedFile("src/large.cs", "csharp", "// " + new string('x', 5000)); @@ -5770,9 +5770,9 @@ public void ToolsCall_BatchQuery_TruncatesAggregateResponse_Issue1416() var structured = response["result"]!["structuredContent"]!; Assert.True(structured["truncated"]?.GetValue() ?? false, response.ToJsonString()); var actualResponseBytes = Encoding.UTF8.GetByteCount(response.ToJsonString()); - Assert.True(actualResponseBytes <= 700, $"Actual response was {actualResponseBytes} bytes."); - Assert.True(structured["metadata"]!["estimated_response_bytes"]!.GetValue() <= 700); - Assert.Equal(700, structured["metadata"]!["response_byte_limit"]!.GetValue()); + Assert.True(actualResponseBytes <= 950, $"Actual response was {actualResponseBytes} bytes."); + Assert.True(structured["metadata"]!["estimated_response_bytes"]!.GetValue() <= 950); + Assert.Equal(950, structured["metadata"]!["response_byte_limit"]!.GetValue()); Assert.Equal(2, structured["metadata"]!["submitted"]!.GetValue()); Assert.Equal(2, structured["metadata"]!["executed"]!.GetValue()); Assert.Equal(0, structured["metadata"]!["errors"]!.GetValue()); From 1aec7eefac561073f13e4b0b8644a9566fc7967f Mon Sep 17 00:00:00 2001 From: Widthdom Date: Mon, 25 May 2026 05:46:44 +0900 Subject: [PATCH 5/7] Preserve MCP correlation on deferred logs (#1814 #1898) --- src/CodeIndex/Mcp/McpServer.cs | 19 +++++++++++++++++-- tests/CodeIndex.Tests/McpServerTests.cs | 1 + 2 files changed, 18 insertions(+), 2 deletions(-) diff --git a/src/CodeIndex/Mcp/McpServer.cs b/src/CodeIndex/Mcp/McpServer.cs index a24f8b935d..ac1f03a6a0 100644 --- a/src/CodeIndex/Mcp/McpServer.cs +++ b/src/CodeIndex/Mcp/McpServer.cs @@ -736,14 +736,29 @@ private void DeferFrameLog(string message) private void DeferFrameLog(Action writeLog) { + var context = CurrentCorrelationContext.Value; var logs = _deferredFrameLogs.Value; if (logs is null) { - writeLog(); + WriteWithCorrelationContext(context, writeLog); return; } - logs.Add(writeLog); + logs.Add(() => WriteWithCorrelationContext(context, writeLog)); + } + + private static void WriteWithCorrelationContext(RequestCorrelationContext? context, Action writeLog) + { + var previous = CurrentCorrelationContext.Value; + try + { + CurrentCorrelationContext.Value = context; + writeLog(); + } + finally + { + CurrentCorrelationContext.Value = previous; + } } private void BeginDeferredFrameLogs() diff --git a/tests/CodeIndex.Tests/McpServerTests.cs b/tests/CodeIndex.Tests/McpServerTests.cs index ec31d321cb..5fb3bba6eb 100644 --- a/tests/CodeIndex.Tests/McpServerTests.cs +++ b/tests/CodeIndex.Tests/McpServerTests.cs @@ -173,6 +173,7 @@ public async Task ProcessLineAsync_ToolCallEmitsInvocationTelemetry() var line = error.ToString() .Split('\n', StringSplitOptions.RemoveEmptyEntries) .Single(l => l.Contains("\"event\":\"mcp.tool.invocation\"", StringComparison.Ordinal)); + Assert.Contains("[rid=123 cid=", line); var jsonStart = line.IndexOf('{'); using var document = JsonDocument.Parse(line[jsonStart..]); var root = document.RootElement; From 97376a16d1ea694476b3231e6b380d265a831848 Mon Sep 17 00:00:00 2001 From: Widthdom Date: Mon, 25 May 2026 05:50:22 +0900 Subject: [PATCH 6/7] Keep MCP correlation through fallback errors (#1814 #1897) --- src/CodeIndex/Mcp/McpServer.cs | 9 ++++++- tests/CodeIndex.Tests/McpServerTests.cs | 32 +++++++++++++++++++++++++ 2 files changed, 40 insertions(+), 1 deletion(-) diff --git a/src/CodeIndex/Mcp/McpServer.cs b/src/CodeIndex/Mcp/McpServer.cs index ac1f03a6a0..6a576b3748 100644 --- a/src/CodeIndex/Mcp/McpServer.cs +++ b/src/CodeIndex/Mcp/McpServer.cs @@ -678,6 +678,7 @@ internal static string BuildInvalidUtf8ErrorLog(string detail) JsonNode? request = null; var responseHasId = true; JsonNode? responseId = null; + IDisposable? frameCorrelationScope = null; try { request = JsonNode.Parse(line); @@ -685,6 +686,8 @@ internal static string BuildInvalidUtf8ErrorLog(string detail) return null; ExtractResponseId(request, out responseHasId, out responseId); + if (responseHasId && CurrentCorrelationContext.Value is null) + frameCorrelationScope = BeginRequestCorrelation(responseId); var response = HandleMessage(request); return response != null ? SerializeResponseOrFallback(response, responseHasId, responseId) : null; } @@ -716,6 +719,10 @@ internal static string BuildInvalidUtf8ErrorLog(string detail) retrySafe: classification.RetrySafe); return SerializeResponseOrFallback(errorResponse, responseHasId, responseId); } + finally + { + frameCorrelationScope?.Dispose(); + } } private string SerializeResponseOrFallback(JsonNode response, bool hasId, JsonNode? id) @@ -861,7 +868,7 @@ private static string BuildMinimalInternalErrorResponse(bool hasId, JsonNode? id suggestion: "JSON-RPC 2.0 `id` must be a string, integer, or null. Booleans/objects/arrays are not allowed.", retrySafe: false); - using var correlationScope = hasId ? BeginRequestCorrelation(id) : null; + using var correlationScope = hasId && CurrentCorrelationContext.Value is null ? BeginRequestCorrelation(id) : null; if (method == "$/cancelRequest" || method == "notifications/cancelled") { diff --git a/tests/CodeIndex.Tests/McpServerTests.cs b/tests/CodeIndex.Tests/McpServerTests.cs index 5fb3bba6eb..2b5b21678a 100644 --- a/tests/CodeIndex.Tests/McpServerTests.cs +++ b/tests/CodeIndex.Tests/McpServerTests.cs @@ -185,6 +185,38 @@ public async Task ProcessLineAsync_ToolCallEmitsInvocationTelemetry() Assert.False(string.IsNullOrWhiteSpace(correlationId.GetString())); } + [Fact] + public async Task ProcessLineAsync_FallbackErrorIncludesCorrelationData() + { + using var writer = new StringWriter(); + using var error = new StringWriter(); + + Monitor.Enter(TestConsoleLock.Gate); + try + { + var previousError = Console.Error; + try + { + Console.SetError(error); + await _server.ProcessLineAsync("""{"jsonrpc":"2.0","id":321,"method":"tools/call","params":{"name":42,"arguments":{}}}""", writer); + } + finally + { + Console.SetError(previousError); + } + } + finally + { + Monitor.Exit(TestConsoleLock.Gate); + } + + var response = JsonNode.Parse(writer.ToString())!; + var data = response["error"]!["data"]!; + Assert.Equal("321", data["request_id"]!.GetValue()); + Assert.False(string.IsNullOrWhiteSpace(data["correlation_id"]!.GetValue())); + Assert.Contains("[cdidx-mcp] [rid=321 cid=", error.ToString()); + } + [Fact] public void Initialize_ReturnsProtocolVersion() { From f904887b803c7c9d7ed130104f8f6475dead3cb1 Mon Sep 17 00:00:00 2001 From: Widthdom Date: Mon, 25 May 2026 05:53:14 +0900 Subject: [PATCH 7/7] Include correlation in serialization fallback errors (#1814 #1897) --- src/CodeIndex/Mcp/McpServer.cs | 17 +++++++++++++++++ tests/CodeIndex.Tests/McpServerTests.cs | 3 +++ 2 files changed, 20 insertions(+) diff --git a/src/CodeIndex/Mcp/McpServer.cs b/src/CodeIndex/Mcp/McpServer.cs index 6a576b3748..256c89f701 100644 --- a/src/CodeIndex/Mcp/McpServer.cs +++ b/src/CodeIndex/Mcp/McpServer.cs @@ -832,6 +832,7 @@ private static string BuildMinimalInternalErrorResponse(bool hasId, JsonNode? id var message = $"Internal error while serializing MCP response ({ex.GetType().Name}). See cdidx server stderr for details."; var builder = new StringBuilder("{\"jsonrpc\":\"2.0\",\"error\":{\"code\":-32603,\"message\":"); builder.Append(JsonSerializer.Serialize(message)); + AppendMinimalCorrelationData(builder); builder.Append('}'); if (hasId) { @@ -842,6 +843,22 @@ private static string BuildMinimalInternalErrorResponse(bool hasId, JsonNode? id return builder.ToString(); } + private static void AppendMinimalCorrelationData(StringBuilder builder) + { + var context = CurrentCorrelationContext.Value; + if (context is null) + return; + + builder.Append(",\"data\":{\"correlation_id\":"); + builder.Append(JsonSerializer.Serialize(context.CorrelationId)); + if (context.RequestId != null) + { + builder.Append(",\"request_id\":"); + builder.Append(JsonSerializer.Serialize(context.RequestId)); + } + builder.Append('}'); + } + /// /// Route a JSON-RPC message to the appropriate handler. /// JSON-RPCメッセージを適切なハンドラにルーティング。 diff --git a/tests/CodeIndex.Tests/McpServerTests.cs b/tests/CodeIndex.Tests/McpServerTests.cs index 2b5b21678a..9791385455 100644 --- a/tests/CodeIndex.Tests/McpServerTests.cs +++ b/tests/CodeIndex.Tests/McpServerTests.cs @@ -1105,6 +1105,9 @@ public void ProcessFrame_ResponseSerializationFailure_ReturnsMinimalErrorWithReq Assert.Equal(42, root.GetProperty("id").GetInt32()); Assert.Equal(-32603, root.GetProperty("error").GetProperty("code").GetInt32()); Assert.Contains("serializing MCP response", root.GetProperty("error").GetProperty("message").GetString()); + var data = root.GetProperty("error").GetProperty("data"); + Assert.Equal("42", data.GetProperty("request_id").GetString()); + Assert.False(string.IsNullOrWhiteSpace(data.GetProperty("correlation_id").GetString())); } [Fact]