Move sending logs inside outgoing filter and add logging verification tests

Move LogSendingRequest/LogSendingMessage from SendRequestAsync/SendMessageAsync
into SendToRelatedTransportAsync's inner next function. This ensures 'sending'
logs only appear when the message is actually sent through the transport, not
when an outgoing filter skips sending.

Add 4 tests verifying logging behavior when filters skip or call next:
- AddOutgoingMessageFilter_SkipNext_DoesNotLogSending
- AddOutgoingMessageFilter_CallsNext_LogsSending
- AddIncomingMessageFilter_SkipNext_DoesNotLogSendingResponse
- AddIncomingMessageFilter_CallsNext_LogsSendingResponse

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

Author: halter73

src/ModelContextProtocol.Core/McpSessionHandler.cs

@@ -576,15 +576,6 @@ public async Task<JsonRpcResponse> SendRequestAsync(JsonRpcRequest request, Canc
                 AddTags(ref tags, activity, request, method, target);
             }
 
-            if (_logger.IsEnabled(LogLevel.Trace))
-            {
-                LogSendingRequestSensitive(EndpointName, request.Method, JsonSerializer.Serialize(request, McpJsonUtilities.JsonContext.Default.JsonRpcMessage));
-            }
-            else
-            {
-                LogSendingRequest(EndpointName, request.Method);
-            }
-
             await SendToRelatedTransportAsync(request, cancellationToken).ConfigureAwait(false);
 
             // Now that the request has been sent, register for cancellation. If we registered before,
@@ -671,15 +662,6 @@ public async Task SendMessageAsync(JsonRpcMessage message, CancellationToken can
                 AddTags(ref tags, activity, message, method, target);
             }
 
-            if (_logger.IsEnabled(LogLevel.Trace))
-            {
-                LogSendingMessageSensitive(EndpointName, JsonSerializer.Serialize(message, McpJsonUtilities.JsonContext.Default.JsonRpcMessage));
-            }
-            else
-            {
-                LogSendingMessage(EndpointName);
-            }
-
             await SendToRelatedTransportAsync(message, cancellationToken).ConfigureAwait(false);
 
             // If the sent notification was a cancellation notification, cancel the pending request's await, as either the
@@ -708,7 +690,32 @@ public async Task SendMessageAsync(JsonRpcMessage message, CancellationToken can
     // the HTTP response body for the POST request containing the corresponding JSON-RPC request.
     private Task SendToRelatedTransportAsync(JsonRpcMessage message, CancellationToken cancellationToken)
         => _outgoingMessageFilter((msg, ct) =>
-            (msg.Context?.RelatedTransport ?? _transport).SendMessageAsync(msg, ct))(message, cancellationToken);
+        {
+            if (msg is JsonRpcRequest request)
+            {
+                if (_logger.IsEnabled(LogLevel.Trace))
+                {
+                    LogSendingRequestSensitive(EndpointName, request.Method, JsonSerializer.Serialize(msg, McpJsonUtilities.JsonContext.Default.JsonRpcMessage));
+                }
+                else
+                {
+                    LogSendingRequest(EndpointName, request.Method);
+                }
+            }
+            else
+            {
+                if (_logger.IsEnabled(LogLevel.Trace))
+                {
+                    LogSendingMessageSensitive(EndpointName, JsonSerializer.Serialize(msg, McpJsonUtilities.JsonContext.Default.JsonRpcMessage));
+                }
+                else
+                {
+                    LogSendingMessage(EndpointName);
+                }
+            }
+
+            return (msg.Context?.RelatedTransport ?? _transport).SendMessageAsync(msg, ct);
+        })(message, cancellationToken);
 
     private static CancelledNotificationParams? GetCancelledNotificationParams(JsonNode? notificationParams)
     {

tests/ModelContextProtocol.AspNetCore.Tests/MapMcpTests.cs

@@ -328,8 +328,10 @@ await client.CallToolAsync("echo_with_user_name",
     }
 
     [Fact]
-    public async Task OutgoingFilter_SeesResponses()
+    public async Task OutgoingFilter_SeesResponsesAndRequests()
     {
+        Assert.SkipWhen(Stateless, "Server-originated requests are not supported in stateless mode.");
+
         var observedMessageTypes = new List<string>();
 
         Builder.Services.AddMcpServer()
@@ -338,6 +340,7 @@ public async Task OutgoingFilter_SeesResponses()
             {
                 var typeName = context.JsonRpcMessage switch
                 {
+                    JsonRpcRequest request => $"request:{request.Method}",
                     JsonRpcResponse r when r.Result is JsonObject obj && obj.ContainsKey("protocolVersion") => "initialize-response",
                     JsonRpcResponse r when r.Result is JsonObject obj && obj.ContainsKey("tools") => "tools-list-response",
                     JsonRpcResponse r when r.Result is JsonObject obj && obj.ContainsKey("content") => "tool-call-response",
@@ -351,42 +354,7 @@ public async Task OutgoingFilter_SeesResponses()
 
                 await next(context, cancellationToken);
             }))
-            .WithTools<ClaimsPrincipalTools>();
-
-        await using var app = Builder.Build();
-        app.MapMcp();
-        await app.StartAsync(TestContext.Current.CancellationToken);
-
-        await using var client = await ConnectAsync();
-
-        await client.ListToolsAsync(cancellationToken: TestContext.Current.CancellationToken);
-        await client.CallToolAsync("echo_claims_principal",
-            new Dictionary<string, object?> { ["message"] = "hi" },
-            cancellationToken: TestContext.Current.CancellationToken);
-
-        Assert.Contains("initialize-response", observedMessageTypes);
-        Assert.Contains("tools-list-response", observedMessageTypes);
-        Assert.Contains("tool-call-response", observedMessageTypes);
-    }
-
-    [Fact]
-    public async Task OutgoingFilter_SeesServerOriginatedRequests()
-    {
-        Assert.SkipWhen(Stateless, "Server-originated requests are not supported in stateless mode.");
-
-        var observedMethods = new List<string>();
-
-        Builder.Services.AddMcpServer()
-            .WithHttpTransport(ConfigureStateless)
-            .WithMessageFilters(filters => filters.AddOutgoingFilter((next) => async (context, cancellationToken) =>
-            {
-                if (context.JsonRpcMessage is JsonRpcRequest request)
-                {
-                    observedMethods.Add(request.Method);
-                }
-
-                await next(context, cancellationToken);
-            }))
+            .WithTools<ClaimsPrincipalTools>()
             .WithTools<SamplingRegressionTools>();
 
         await using var app = Builder.Build();
@@ -408,11 +376,18 @@ public async Task OutgoingFilter_SeesServerOriginatedRequests()
 
         await using var client = await ConnectAsync(clientOptions: clientOptions);
 
+        await client.ListToolsAsync(cancellationToken: TestContext.Current.CancellationToken);
+        await client.CallToolAsync("echo_claims_principal",
+            new Dictionary<string, object?> { ["message"] = "hi" },
+            cancellationToken: TestContext.Current.CancellationToken);
         await client.CallToolAsync("sampling-tool",
             new Dictionary<string, object?> { ["prompt"] = "Hello" },
             cancellationToken: TestContext.Current.CancellationToken);
 
-        Assert.Contains(RequestMethods.SamplingCreateMessage, observedMethods);
+        Assert.Contains("initialize-response", observedMessageTypes);
+        Assert.Contains("tools-list-response", observedMessageTypes);
+        Assert.Contains("tool-call-response", observedMessageTypes);
+        Assert.Contains($"request:{RequestMethods.SamplingCreateMessage}", observedMessageTypes);
     }
 
     [Fact]

tests/ModelContextProtocol.Tests/Configuration/McpServerBuilderExtensionsMessageFilterTests.cs

@@ -317,7 +317,7 @@ await Assert.ThrowsAnyAsync<OperationCanceledException>(async () =>
     }
 
     [Fact]
-    public async Task AddOutgoingMessageFilter_Sees_Initialize_Progress_And_Response()
+    public async Task AddOutgoingMessageFilter_Sees_Responses_Notifications_And_Requests()
     {
         var observedMessages = new List<string>();
 
@@ -326,6 +326,9 @@ public async Task AddOutgoingMessageFilter_Sees_Initialize_Progress_And_Response
             {
                 switch (context.JsonRpcMessage)
                 {
+                    case JsonRpcRequest request:
+                        observedMessages.Add($"request:{request.Method}");
+                        break;
                     case JsonRpcResponse response when response.Result is JsonObject result:
                         if (result.ContainsKey("protocolVersion"))
                         {
@@ -343,22 +346,41 @@ public async Task AddOutgoingMessageFilter_Sees_Initialize_Progress_And_Response
 
                 await next(context, cancellationToken);
             }))
-            .WithTools<ProgressTool>();
+            .WithTools<ProgressTool>()
+            .WithTools<SamplingTool>();
 
         StartServer();
 
-        await using McpClient client = await CreateMcpClientForServer();
+        var clientOptions = new McpClientOptions
+        {
+            Capabilities = new() { Sampling = new() },
+            Handlers = new()
+            {
+                SamplingHandler = (_, _, _) => new(new CreateMessageResult
+                {
+                    Content = [new TextContentBlock { Text = "sampled" }],
+                    Model = "test-model",
+                }),
+            },
+        };
+
+        await using McpClient client = await CreateMcpClientForServer(clientOptions);
 
         IProgress<ProgressNotificationValue> progress = new Progress<ProgressNotificationValue>(_ => { });
         await client.CallToolAsync("progress-tool", progress: progress, cancellationToken: TestContext.Current.CancellationToken);
 
+        await client.CallToolAsync("sampling-tool", new Dictionary<string, object?> { ["prompt"] = "Hello" },
+            cancellationToken: TestContext.Current.CancellationToken);
+
         int initializeIndex = observedMessages.IndexOf("initialize");
         int progressIndex = observedMessages.IndexOf("progress");
         int responseIndex = observedMessages.LastIndexOf("response");
+        int requestIndex = observedMessages.IndexOf($"request:{RequestMethods.SamplingCreateMessage}");
 
         Assert.True(initializeIndex >= 0);
         Assert.True(progressIndex > initializeIndex);
         Assert.True(responseIndex > progressIndex);
+        Assert.True(requestIndex >= 0);
     }
 
     [Fact]
@@ -429,43 +451,124 @@ public async Task AddOutgoingMessageFilter_Can_Send_Additional_Messages()
     }
 
     [Fact]
-    public async Task AddOutgoingMessageFilter_Sees_ServerOriginatedRequests()
+    public async Task AddOutgoingMessageFilter_SkipNext_DoesNotLogSending()
     {
-        var observedMethods = new List<string>();
+        ServiceCollection.AddLogging(builder => builder.SetMinimumLevel(LogLevel.Debug));
 
         McpServerBuilder
-            .WithMessageFilters(filters => filters.AddOutgoingFilter((next) => async (context, cancellationToken) =>
+            .WithMessageFilters(filters => filters.AddOutgoingFilter((next) => (context, cancellationToken) =>
             {
-                if (context.JsonRpcMessage is JsonRpcRequest request)
+                // Skip sending tool list responses
+                if (context.JsonRpcMessage is JsonRpcResponse response && response.Result is JsonObject result && result.ContainsKey("tools"))
                 {
-                    observedMethods.Add(request.Method);
+                    return Task.CompletedTask;
                 }
 
-                await next(context, cancellationToken);
+                return next(context, cancellationToken);
             }))
-            .WithTools<SamplingTool>();
+            .WithTools<TestTool>();
 
         StartServer();
 
-        var clientOptions = new McpClientOptions
+        await using McpClient client = await CreateMcpClientForServer();
+
+        // Clear any logs from initialization
+        while (MockLoggerProvider.LogMessages.TryDequeue(out _)) { }
+
+        using var requestCts = new CancellationTokenSource(TimeSpan.FromSeconds(2));
+        await Assert.ThrowsAnyAsync<OperationCanceledException>(async () =>
         {
-            Capabilities = new() { Sampling = new() },
-            Handlers = new()
+            await client.ListToolsAsync(cancellationToken: requestCts.Token);
+        });
+
+        // Since the filter skipped next, no "sending message" log should appear for the skipped response
+        Assert.DoesNotContain(MockLoggerProvider.LogMessages, m =>
+            m.Category.Contains("McpServer") && m.Message.Contains("sending message", StringComparison.OrdinalIgnoreCase));
+    }
+
+    [Fact]
+    public async Task AddOutgoingMessageFilter_CallsNext_LogsSending()
+    {
+        ServiceCollection.AddLogging(builder => builder.SetMinimumLevel(LogLevel.Debug));
+
+        McpServerBuilder
+            .WithTools<TestTool>();
+
+        StartServer();
+
+        await using McpClient client = await CreateMcpClientForServer();
+
+        // Clear any logs from initialization
+        while (MockLoggerProvider.LogMessages.TryDequeue(out _)) { }
+
+        await client.ListToolsAsync(cancellationToken: TestContext.Current.CancellationToken);
+
+        // The response should have been sent, producing a "sending message" log from the server
+        Assert.Contains(MockLoggerProvider.LogMessages, m =>
+            m.Category.Contains("McpServer") && m.Message.Contains("sending message", StringComparison.OrdinalIgnoreCase));
+    }
+
+    [Fact]
+    public async Task AddIncomingMessageFilter_SkipNext_DoesNotLogSendingResponse()
+    {
+        ServiceCollection.AddLogging(builder => builder.SetMinimumLevel(LogLevel.Debug));
+
+        McpServerBuilder
+            .WithMessageFilters(filters => filters.AddIncomingFilter((next) => (context, cancellationToken) =>
             {
-                SamplingHandler = (_, _, _) => new(new CreateMessageResult
+                // Skip processing tools/list requests — handler never runs, no response sent
+                if (context.JsonRpcMessage is JsonRpcRequest request && request.Method == RequestMethods.ToolsList)
                 {
-                    Content = [new TextContentBlock { Text = "sampled" }],
-                    Model = "test-model",
-                }),
-            },
-        };
+                    return Task.CompletedTask;
+                }
 
-        await using McpClient client = await CreateMcpClientForServer(clientOptions);
+                return next(context, cancellationToken);
+            }))
+            .WithTools<TestTool>();
 
-        await client.CallToolAsync("sampling-tool", new Dictionary<string, object?> { ["prompt"] = "Hello" },
-            cancellationToken: TestContext.Current.CancellationToken);
+        StartServer();
+
+        await using McpClient client = await CreateMcpClientForServer();
+
+        // Clear any logs from initialization
+        while (MockLoggerProvider.LogMessages.TryDequeue(out _)) { }
+
+        using var requestCts = new CancellationTokenSource(TimeSpan.FromSeconds(2));
+        await Assert.ThrowsAnyAsync<OperationCanceledException>(async () =>
+        {
+            await client.ListToolsAsync(cancellationToken: requestCts.Token);
+        });
+
+        // Since the incoming filter skipped next, no handler ran, so no response was sent
+        Assert.DoesNotContain(MockLoggerProvider.LogMessages, m =>
+            m.Category.Contains("McpServer") && m.Message.Contains("sending message", StringComparison.OrdinalIgnoreCase));
+    }
+
+    [Fact]
+    public async Task AddIncomingMessageFilter_CallsNext_LogsSendingResponse()
+    {
+        ServiceCollection.AddLogging(builder => builder.SetMinimumLevel(LogLevel.Debug));
+
+        McpServerBuilder
+            .WithMessageFilters(filters => filters.AddIncomingFilter((next) => (context, cancellationToken) =>
+            {
+                // Pass through — handler runs, response is sent
+                return next(context, cancellationToken);
+            }))
+            .WithTools<TestTool>();
+
+        StartServer();
+
+        await using McpClient client = await CreateMcpClientForServer();
+
+        // Clear any logs from initialization
+        while (MockLoggerProvider.LogMessages.TryDequeue(out _)) { }
+
+        await client.ListToolsAsync(cancellationToken: TestContext.Current.CancellationToken);
 
-        Assert.Contains(RequestMethods.SamplingCreateMessage, observedMethods);
+        // The handler ran and sent a response, producing a "sending message" log from the server
+        Assert.Contains(MockLoggerProvider.LogMessages, m =>
+            m.Category.Contains("McpServer") && m.Message.Contains("sending message", StringComparison.OrdinalIgnoreCase));
     }
 
     [Fact]