From a15163d8620deaad3993d8d124ed59adf32af691 Mon Sep 17 00:00:00 2001 From: Theo Jiang Date: Wed, 9 Jul 2025 17:03:25 -0700 Subject: [PATCH 1/4] add debug log for McpSession --- src/ModelContextProtocol.Core/McpSession.cs | 16 ++++++++++++++-- 1 file changed, 14 insertions(+), 2 deletions(-) diff --git a/src/ModelContextProtocol.Core/McpSession.cs b/src/ModelContextProtocol.Core/McpSession.cs index 47c4d212..2adb5381 100644 --- a/src/ModelContextProtocol.Core/McpSession.cs +++ b/src/ModelContextProtocol.Core/McpSession.cs @@ -95,6 +95,7 @@ public McpSession( _requestHandlers = requestHandlers; _notificationHandlers = notificationHandlers; _logger = logger ?? NullLogger.Instance; + LogSessionCreated(EndpointName, _sessionId, _transportKind); } /// @@ -108,6 +109,7 @@ public McpSession( /// public async Task ProcessMessagesAsync(CancellationToken cancellationToken) { + LogSessionConnected(EndpointName, _sessionId, _transportKind); try { await foreach (var message in _transport.MessageReader.ReadAllAsync(cancellationToken).ConfigureAwait(false)) @@ -609,9 +611,9 @@ private static void AddExceptionTags(ref TagList tags, Activity? activity, Excep e = ae.InnerException; } - int? intErrorCode = + int? intErrorCode = (int?)((e as McpException)?.ErrorCode) is int errorCode ? errorCode : - e is JsonException ? (int)McpErrorCode.ParseError : + e is JsonException ? (int)McpErrorCode.ParseError : null; string? errorType = intErrorCode?.ToString() ?? e.GetType().FullName; @@ -692,6 +694,7 @@ public void Dispose() } _pendingRequests.Clear(); + LogSessionDisposed(EndpointName, _sessionId, _transportKind); } #if !NET @@ -774,4 +777,13 @@ private static TimeSpan GetElapsed(long startingTimestamp) => [LoggerMessage(Level = LogLevel.Trace, Message = "{EndpointName} sending message. Message: '{Message}'.")] private partial void LogSendingMessageSensitive(string endpointName, string message); + + [LoggerMessage(Level = LogLevel.Debug, Message = "{EndpointName} session {SessionId} created with transport {TransportKind}")] + private partial void LogSessionCreated(string endpointName, string sessionId, string transportKind); + + [LoggerMessage(Level = LogLevel.Debug, Message = "{EndpointName} session {SessionId} connected and processing messages with transport {TransportKind}")] + private partial void LogSessionConnected(string endpointName, string sessionId, string transportKind); + + [LoggerMessage(Level = LogLevel.Debug, Message = "{EndpointName} session {SessionId} disposed with transport {TransportKind}")] + private partial void LogSessionDisposed(string endpointName, string sessionId, string transportKind); } From 64761d0225710567f97e5131f822e89dd23a9f0e Mon Sep 17 00:00:00 2001 From: Theo Jiang Date: Wed, 9 Jul 2025 17:52:03 -0700 Subject: [PATCH 2/4] add request header logging at trace level --- .../StreamableHttpHandler.cs | 46 ++++++++++++++++++- 1 file changed, 45 insertions(+), 1 deletion(-) diff --git a/src/ModelContextProtocol.AspNetCore/StreamableHttpHandler.cs b/src/ModelContextProtocol.AspNetCore/StreamableHttpHandler.cs index aeac38bf..cf2ef4fb 100644 --- a/src/ModelContextProtocol.AspNetCore/StreamableHttpHandler.cs +++ b/src/ModelContextProtocol.AspNetCore/StreamableHttpHandler.cs @@ -18,7 +18,7 @@ namespace ModelContextProtocol.AspNetCore; -internal sealed class StreamableHttpHandler( +internal sealed partial class StreamableHttpHandler( IOptions mcpServerOptionsSnapshot, IOptionsFactory mcpServerOptionsFactory, IOptions httpServerTransportOptions, @@ -28,6 +28,20 @@ internal sealed class StreamableHttpHandler( { private const string McpSessionIdHeaderName = "Mcp-Session-Id"; private static readonly JsonTypeInfo s_errorTypeInfo = GetRequiredJsonTypeInfo(); + + private readonly ILogger _logger = loggerFactory.CreateLogger(); + + // Headers that are safe and relevant to log for MCP over HTTP + private static readonly HashSet SafeHeadersToLog = new(StringComparer.OrdinalIgnoreCase) + { + "Accept", + "Content-Type", + "Content-Length", + "User-Agent", + McpSessionIdHeaderName, + "X-Request-ID", + "X-Correlation-ID" + }; public ConcurrentDictionary> Sessions { get; } = new(StringComparer.Ordinal); @@ -37,6 +51,9 @@ internal sealed class StreamableHttpHandler( public async Task HandlePostRequestAsync(HttpContext context) { + // Log request headers for debugging + LogHttpRequestHeadersIfEnabled(context); + // The Streamable HTTP spec mandates the client MUST accept both application/json and text/event-stream. // ASP.NET Core Minimal APIs mostly try to stay out of the business of response content negotiation, // so we have to do this manually. The spec doesn't mandate that servers MUST reject these requests, @@ -83,6 +100,9 @@ await WriteJsonRpcErrorAsync(context, public async Task HandleGetRequestAsync(HttpContext context) { + // Log request headers for debugging + LogHttpRequestHeadersIfEnabled(context); + if (!context.Request.GetTypedHeaders().Accept.Any(MatchesTextEventStreamMediaType)) { await WriteJsonRpcErrorAsync(context, @@ -118,6 +138,9 @@ await WriteJsonRpcErrorAsync(context, public async Task HandleDeleteRequestAsync(HttpContext context) { + // Log request headers for debugging + LogHttpRequestHeadersIfEnabled(context); + var sessionId = context.Request.Headers[McpSessionIdHeaderName].ToString(); if (Sessions.TryRemove(sessionId, out var session)) { @@ -336,6 +359,27 @@ private static bool MatchesApplicationJsonMediaType(MediaTypeHeaderValue acceptH private static bool MatchesTextEventStreamMediaType(MediaTypeHeaderValue acceptHeaderValue) => acceptHeaderValue.MatchesMediaType("text/event-stream"); + private void LogHttpRequestHeadersIfEnabled(HttpContext context) + { + if (_logger.IsEnabled(LogLevel.Trace)) + { + var safeHeaders = new Dictionary(); + + foreach (var header in context.Request.Headers) + { + if (SafeHeadersToLog.Contains(header.Key)) + { + safeHeaders[header.Key] = header.Value.ToString(); + } + } + + LogHttpRequestHeaders(context.Request.Method, context.Request.Path, safeHeaders); + } + } + + [LoggerMessage(Level = LogLevel.Trace, Message = "HTTP {Method} {Path} - Headers: {Headers}")] + private partial void LogHttpRequestHeaders(string method, string path, Dictionary headers); + private sealed class HttpDuplexPipe(HttpContext context) : IDuplexPipe { public PipeReader Input => context.Request.BodyReader; From c5d7009f919c7f1bcd25fc9e5bfbb76a39bf33d3 Mon Sep 17 00:00:00 2001 From: Theo Jiang Date: Thu, 10 Jul 2025 15:24:38 -0700 Subject: [PATCH 3/4] Revert "add request header logging at trace level" This reverts commit 64761d0225710567f97e5131f822e89dd23a9f0e. --- .../StreamableHttpHandler.cs | 46 +------------------ 1 file changed, 1 insertion(+), 45 deletions(-) diff --git a/src/ModelContextProtocol.AspNetCore/StreamableHttpHandler.cs b/src/ModelContextProtocol.AspNetCore/StreamableHttpHandler.cs index cf2ef4fb..aeac38bf 100644 --- a/src/ModelContextProtocol.AspNetCore/StreamableHttpHandler.cs +++ b/src/ModelContextProtocol.AspNetCore/StreamableHttpHandler.cs @@ -18,7 +18,7 @@ namespace ModelContextProtocol.AspNetCore; -internal sealed partial class StreamableHttpHandler( +internal sealed class StreamableHttpHandler( IOptions mcpServerOptionsSnapshot, IOptionsFactory mcpServerOptionsFactory, IOptions httpServerTransportOptions, @@ -28,20 +28,6 @@ internal sealed partial class StreamableHttpHandler( { private const string McpSessionIdHeaderName = "Mcp-Session-Id"; private static readonly JsonTypeInfo s_errorTypeInfo = GetRequiredJsonTypeInfo(); - - private readonly ILogger _logger = loggerFactory.CreateLogger(); - - // Headers that are safe and relevant to log for MCP over HTTP - private static readonly HashSet SafeHeadersToLog = new(StringComparer.OrdinalIgnoreCase) - { - "Accept", - "Content-Type", - "Content-Length", - "User-Agent", - McpSessionIdHeaderName, - "X-Request-ID", - "X-Correlation-ID" - }; public ConcurrentDictionary> Sessions { get; } = new(StringComparer.Ordinal); @@ -51,9 +37,6 @@ internal sealed partial class StreamableHttpHandler( public async Task HandlePostRequestAsync(HttpContext context) { - // Log request headers for debugging - LogHttpRequestHeadersIfEnabled(context); - // The Streamable HTTP spec mandates the client MUST accept both application/json and text/event-stream. // ASP.NET Core Minimal APIs mostly try to stay out of the business of response content negotiation, // so we have to do this manually. The spec doesn't mandate that servers MUST reject these requests, @@ -100,9 +83,6 @@ await WriteJsonRpcErrorAsync(context, public async Task HandleGetRequestAsync(HttpContext context) { - // Log request headers for debugging - LogHttpRequestHeadersIfEnabled(context); - if (!context.Request.GetTypedHeaders().Accept.Any(MatchesTextEventStreamMediaType)) { await WriteJsonRpcErrorAsync(context, @@ -138,9 +118,6 @@ await WriteJsonRpcErrorAsync(context, public async Task HandleDeleteRequestAsync(HttpContext context) { - // Log request headers for debugging - LogHttpRequestHeadersIfEnabled(context); - var sessionId = context.Request.Headers[McpSessionIdHeaderName].ToString(); if (Sessions.TryRemove(sessionId, out var session)) { @@ -359,27 +336,6 @@ private static bool MatchesApplicationJsonMediaType(MediaTypeHeaderValue acceptH private static bool MatchesTextEventStreamMediaType(MediaTypeHeaderValue acceptHeaderValue) => acceptHeaderValue.MatchesMediaType("text/event-stream"); - private void LogHttpRequestHeadersIfEnabled(HttpContext context) - { - if (_logger.IsEnabled(LogLevel.Trace)) - { - var safeHeaders = new Dictionary(); - - foreach (var header in context.Request.Headers) - { - if (SafeHeadersToLog.Contains(header.Key)) - { - safeHeaders[header.Key] = header.Value.ToString(); - } - } - - LogHttpRequestHeaders(context.Request.Method, context.Request.Path, safeHeaders); - } - } - - [LoggerMessage(Level = LogLevel.Trace, Message = "HTTP {Method} {Path} - Headers: {Headers}")] - private partial void LogHttpRequestHeaders(string method, string path, Dictionary headers); - private sealed class HttpDuplexPipe(HttpContext context) : IDuplexPipe { public PipeReader Input => context.Request.BodyReader; From adbec9abbca9b80642dd542d0b4135b61e3ca12b Mon Sep 17 00:00:00 2001 From: Theo Jiang Date: Thu, 10 Jul 2025 15:26:19 -0700 Subject: [PATCH 4/4] remove session connected log and move to trace level --- src/ModelContextProtocol.Core/McpSession.cs | 8 ++------ 1 file changed, 2 insertions(+), 6 deletions(-) diff --git a/src/ModelContextProtocol.Core/McpSession.cs b/src/ModelContextProtocol.Core/McpSession.cs index 2adb5381..c4756287 100644 --- a/src/ModelContextProtocol.Core/McpSession.cs +++ b/src/ModelContextProtocol.Core/McpSession.cs @@ -109,7 +109,6 @@ public McpSession( /// public async Task ProcessMessagesAsync(CancellationToken cancellationToken) { - LogSessionConnected(EndpointName, _sessionId, _transportKind); try { await foreach (var message in _transport.MessageReader.ReadAllAsync(cancellationToken).ConfigureAwait(false)) @@ -778,12 +777,9 @@ private static TimeSpan GetElapsed(long startingTimestamp) => [LoggerMessage(Level = LogLevel.Trace, Message = "{EndpointName} sending message. Message: '{Message}'.")] private partial void LogSendingMessageSensitive(string endpointName, string message); - [LoggerMessage(Level = LogLevel.Debug, Message = "{EndpointName} session {SessionId} created with transport {TransportKind}")] + [LoggerMessage(Level = LogLevel.Trace, Message = "{EndpointName} session {SessionId} created with transport {TransportKind}")] private partial void LogSessionCreated(string endpointName, string sessionId, string transportKind); - [LoggerMessage(Level = LogLevel.Debug, Message = "{EndpointName} session {SessionId} connected and processing messages with transport {TransportKind}")] - private partial void LogSessionConnected(string endpointName, string sessionId, string transportKind); - - [LoggerMessage(Level = LogLevel.Debug, Message = "{EndpointName} session {SessionId} disposed with transport {TransportKind}")] + [LoggerMessage(Level = LogLevel.Trace, Message = "{EndpointName} session {SessionId} disposed with transport {TransportKind}")] private partial void LogSessionDisposed(string endpointName, string sessionId, string transportKind); }