Skip to content

Log tool call name on success, not just failure #1256

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
halter73 merged 9 commits into from
Feb 13, 2026
+443 −22
Merged

Log tool call name on success, not just failure #1256

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
9 commits
Select commit Hold shift + click to select a range
8e16093
Initial plan
Copilot Feb 10, 2026
ee969d2
Add ToolCallCompleted success log with tool name in McpServerImpl
Copilot Feb 10, 2026
88dc771
Move ToolCallCompleted log after IsError check in task path
Copilot Feb 10, 2026
c18f406
Include IsError in ToolCallCompleted log, add task-path tests
Copilot Feb 10, 2026
515db78
Replace Task.Delay with GetTaskResultAsync in task-path tests
Copilot Feb 10, 2026
d250e0d
Add logging for prompts and resources (success and error)
Copilot Feb 10, 2026
10a2e6d
Log ToolCallError, GetPromptError, ReadResourceError for all exceptio…
Copilot Feb 11, 2026
1fe5536
Produce errored CallToolResult for non-user-canceled OperationCancele…
Copilot Feb 11, 2026
f37777d
Merge three tool catch blocks into single catch (Exception e)
Copilot Feb 11, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
69 changes: 60 additions & 9 deletions src/ModelContextProtocol.Core/Server/McpServerImpl.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -392,7 +392,17 @@ await originalListResourceTemplatesHandler(request, cancellationToken).Configure
}
}

return await handler(request, cancellationToken).ConfigureAwait(false);
try
{
var result = await handler(request, cancellationToken).ConfigureAwait(false);
ReadResourceCompleted(request.Params?.Uri ?? string.Empty);
return result;
}
catch (Exception e)
{
ReadResourceError(request.Params?.Uri ?? string.Empty, e);
throw;
}
});
subscribeHandler = BuildFilterPipeline(subscribeHandler, options.Filters.SubscribeToResourcesFilters);
unsubscribeHandler = BuildFilterPipeline(unsubscribeHandler, options.Filters.UnsubscribeFromResourcesFilters);
Expand Down Expand Up @@ -487,7 +497,7 @@ await originalListPromptsHandler(request, cancellationToken).ConfigureAwait(fals

listPromptsHandler = BuildFilterPipeline(listPromptsHandler, options.Filters.ListPromptsFilters);
getPromptHandler = BuildFilterPipeline(getPromptHandler, options.Filters.GetPromptFilters, handler =>
(request, cancellationToken) =>
async (request, cancellationToken) =>
{
// Initial handler that sets MatchedPrimitive
if (request.Params?.Name is { } promptName && prompts is not null &&
Expand All @@ -496,7 +506,17 @@ await originalListPromptsHandler(request, cancellationToken).ConfigureAwait(fals
request.MatchedPrimitive = prompt;
}

return handler(request, cancellationToken);
try
{
var result = await handler(request, cancellationToken).ConfigureAwait(false);
GetPromptCompleted(request.Params?.Name ?? string.Empty);
return result;
}
catch (Exception e)
{
GetPromptError(request.Params?.Name ?? string.Empty, e);
throw;
}
});

ServerCapabilities.Prompts.ListChanged = listChanged;
Expand Down Expand Up @@ -610,20 +630,35 @@ await originalListToolsHandler(request, cancellationToken).ConfigureAwait(false)

try
{
return await handler(request, cancellationToken).ConfigureAwait(false);
var result = await handler(request, cancellationToken).ConfigureAwait(false);

// Don't log here for task-augmented calls; logging happens asynchronously
// in ExecuteToolAsTaskAsync when the tool actually completes.
if (result.Task is null)
{
ToolCallCompleted(request.Params?.Name ?? string.Empty, result.IsError is true);
}

return result;
}
catch (Exception e) when (e is not OperationCanceledException and not McpProtocolException)
catch (Exception e)
{
ToolCallError(request.Params?.Name ?? string.Empty, e);

string errorMessage = e is McpException ?
$"An error occurred invoking '{request.Params?.Name}': {e.Message}" :
$"An error occurred invoking '{request.Params?.Name}'.";
if ((e is OperationCanceledException && cancellationToken.IsCancellationRequested) || e is McpProtocolException)
{
throw;
}

return new()
{
IsError = true,
Content = [new TextContentBlock { Text = errorMessage }],
Content = [new TextContentBlock
{
Text = e is McpException ?
$"An error occurred invoking '{request.Params?.Name}': {e.Message}" :
$"An error occurred invoking '{request.Params?.Name}'.",
}],
};
}
});
Expand Down Expand Up @@ -944,6 +979,21 @@ internal static LoggingLevel ToLoggingLevel(LogLevel level) =>
[LoggerMessage(Level = LogLevel.Error, Message = "\"{ToolName}\" threw an unhandled exception.")]
private partial void ToolCallError(string toolName, Exception exception);

[LoggerMessage(Level = LogLevel.Information, Message = "\"{ToolName}\" completed. IsError = {IsError}.")]
private partial void ToolCallCompleted(string toolName, bool isError);

[LoggerMessage(Level = LogLevel.Error, Message = "GetPrompt \"{PromptName}\" threw an unhandled exception.")]
private partial void GetPromptError(string promptName, Exception exception);

[LoggerMessage(Level = LogLevel.Information, Message = "GetPrompt \"{PromptName}\" completed.")]
private partial void GetPromptCompleted(string promptName);

[LoggerMessage(Level = LogLevel.Error, Message = "ReadResource \"{ResourceUri}\" threw an unhandled exception.")]
private partial void ReadResourceError(string resourceUri, Exception exception);

[LoggerMessage(Level = LogLevel.Information, Message = "ReadResource \"{ResourceUri}\" completed.")]
private partial void ReadResourceCompleted(string resourceUri);

/// <summary>
/// Executes a tool call as a task and returns a CallToolTaskResult immediately.
/// </summary>
Expand Down Expand Up @@ -1004,6 +1054,7 @@ private async ValueTask<CallToolResult> ExecuteToolAsTaskAsync(

// Invoke the tool with task-specific cancellation token
var result = await tool.InvokeAsync(request, taskCancellationToken).ConfigureAwait(false);
ToolCallCompleted(request.Params?.Name ?? string.Empty, result.IsError is true);

// Determine final status based on whether there was an error
var finalStatus = result.IsError is true ? McpTaskStatus.Failed : McpTaskStatus.Completed;
Expand Down
86 changes: 82 additions & 4 deletions tests/ModelContextProtocol.Tests/Configuration/McpServerBuilderExtensionsPromptsTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
using Microsoft.Extensions.AI;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using ModelContextProtocol.Client;
using ModelContextProtocol.Protocol;
Expand Down Expand Up @@ -101,7 +102,7 @@ public async Task Can_List_And_Call_Registered_Prompts()
await using McpClient client = await CreateMcpClientForServer();

var prompts = await client.ListPromptsAsync(cancellationToken: TestContext.Current.CancellationToken);
Assert.Equal(6, prompts.Count);
Assert.Equal(8, prompts.Count);

var prompt = prompts.First(t => t.Name == "returns_chat_messages");
Assert.Equal("Returns chat messages", prompt.Description);
Expand Down Expand Up @@ -130,7 +131,7 @@ public async Task Can_Be_Notified_Of_Prompt_Changes()
await using McpClient client = await CreateMcpClientForServer();

var prompts = await client.ListPromptsAsync(cancellationToken: TestContext.Current.CancellationToken);
Assert.Equal(6, prompts.Count);
Assert.Equal(8, prompts.Count);

Channel<JsonRpcNotification> listChanged = Channel.CreateUnbounded<JsonRpcNotification>();
var notificationRead = listChanged.Reader.ReadAsync(TestContext.Current.CancellationToken);
Expand All @@ -151,7 +152,7 @@ public async Task Can_Be_Notified_Of_Prompt_Changes()
await notificationRead;

prompts = await client.ListPromptsAsync(cancellationToken: TestContext.Current.CancellationToken);
Assert.Equal(7, prompts.Count);
Assert.Equal(9, prompts.Count);
Assert.Contains(prompts, t => t.Name == "NewPrompt");

notificationRead = listChanged.Reader.ReadAsync(TestContext.Current.CancellationToken);
Expand All @@ -161,7 +162,7 @@ public async Task Can_Be_Notified_Of_Prompt_Changes()
}

prompts = await client.ListPromptsAsync(cancellationToken: TestContext.Current.CancellationToken);
Assert.Equal(6, prompts.Count);
Assert.Equal(8, prompts.Count);
Assert.DoesNotContain(prompts, t => t.Name == "NewPrompt");
}

Expand Down Expand Up @@ -195,6 +196,75 @@ await Assert.ThrowsAsync<McpProtocolException>(async () => await client.GetPromp
cancellationToken: TestContext.Current.CancellationToken));
}

[Fact]
public async Task Logs_Prompt_Name_On_Successful_Call()
{
await using McpClient client = await CreateMcpClientForServer();

var result = await client.GetPromptAsync(
"returns_chat_messages",
new Dictionary<string, object?> { ["message"] = "hello" },
cancellationToken: TestContext.Current.CancellationToken);

Assert.NotNull(result);

var infoLog = Assert.Single(MockLoggerProvider.LogMessages, m => m.Message == "GetPrompt \"returns_chat_messages\" completed.");
Assert.Equal(LogLevel.Information, infoLog.LogLevel);
}

[Fact]
public async Task Logs_Prompt_Name_When_Prompt_Throws()
{
await using McpClient client = await CreateMcpClientForServer();

await Assert.ThrowsAsync<McpProtocolException>(async () => await client.GetPromptAsync(
"throws_exception",
new Dictionary<string, object?> { ["message"] = "test" },
cancellationToken: TestContext.Current.CancellationToken));

var errorLog = Assert.Single(MockLoggerProvider.LogMessages, m => m.LogLevel == LogLevel.Error);
Assert.Equal("GetPrompt \"throws_exception\" threw an unhandled exception.", errorLog.Message);
Assert.IsType<FormatException>(errorLog.Exception);
}

[Fact]
public async Task Logs_Prompt_Error_When_Prompt_Throws_OperationCanceledException()
{
await using McpClient client = await CreateMcpClientForServer();

await Assert.ThrowsAsync<McpProtocolException>(async () => await client.GetPromptAsync(
"throws_operation_canceled_exception",
cancellationToken: TestContext.Current.CancellationToken));

Assert.Contains(MockLoggerProvider.LogMessages, m =>
m.LogLevel == LogLevel.Error &&
m.Message == "GetPrompt \"throws_operation_canceled_exception\" threw an unhandled exception." &&
m.Exception is OperationCanceledException);

Assert.Contains(MockLoggerProvider.LogMessages, m =>
m.LogLevel == LogLevel.Warning &&
m.Message.Contains("request handler failed"));
}

[Fact]
public async Task Logs_Prompt_Error_When_Prompt_Throws_McpProtocolException()
{
await using McpClient client = await CreateMcpClientForServer();

await Assert.ThrowsAsync<McpProtocolException>(async () => await client.GetPromptAsync(
"throws_mcp_protocol_exception",
cancellationToken: TestContext.Current.CancellationToken));

Assert.Contains(MockLoggerProvider.LogMessages, m =>
m.LogLevel == LogLevel.Error &&
m.Message == "GetPrompt \"throws_mcp_protocol_exception\" threw an unhandled exception." &&
m.Exception is McpProtocolException);

Assert.Contains(MockLoggerProvider.LogMessages, m =>
m.LogLevel == LogLevel.Warning &&
m.Message.Contains("request handler failed"));
}

[Fact]
public async Task Throws_Exception_On_Unknown_Prompt()
{
Expand Down Expand Up @@ -335,6 +405,14 @@ public static ChatMessage[] ReturnsChatMessages([Description("The first paramete
public static ChatMessage[] ThrowsException([Description("The first parameter")] string message) =>
throw new FormatException("uh oh");

[McpServerPrompt, Description("Throws OperationCanceledException")]
public static ChatMessage[] ThrowsOperationCanceledException() =>
throw new OperationCanceledException("Prompt was canceled");

[McpServerPrompt, Description("Throws McpProtocolException")]
public static ChatMessage[] ThrowsMcpProtocolException() =>
throw new McpProtocolException("Prompt protocol error", McpErrorCode.InvalidParams);

[McpServerPrompt(Title = "This is a title", IconSource = "https://example.com/prompt-icon.svg"), Description("Returns chat messages")]
public string ReturnsString([Description("The first parameter")] string message) =>
$"The prompt is: {message}. The id is {id}.";
Expand Down
82 changes: 78 additions & 4 deletions tests/ModelContextProtocol.Tests/Configuration/McpServerBuilderExtensionsResourcesTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
using Microsoft.Extensions.AI;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using ModelContextProtocol.Client;
using ModelContextProtocol.Protocol;
Expand Down Expand Up @@ -130,7 +131,7 @@ public async Task Can_List_And_Call_Registered_Resources()
Assert.NotNull(client.ServerCapabilities.Resources);

var resources = await client.ListResourcesAsync(cancellationToken: TestContext.Current.CancellationToken);
Assert.Equal(5, resources.Count);
Assert.Equal(7, resources.Count);

var resource = resources.First(t => t.Name == "some_neat_direct_resource");
Assert.Equal("Some neat direct resource", resource.Description);
Expand Down Expand Up @@ -164,7 +165,7 @@ public async Task Can_Be_Notified_Of_Resource_Changes()
await using McpClient client = await CreateMcpClientForServer();

var resources = await client.ListResourcesAsync(cancellationToken: TestContext.Current.CancellationToken);
Assert.Equal(5, resources.Count);
Assert.Equal(7, resources.Count);

Channel<JsonRpcNotification> listChanged = Channel.CreateUnbounded<JsonRpcNotification>();
var notificationRead = listChanged.Reader.ReadAsync(TestContext.Current.CancellationToken);
Expand All @@ -185,7 +186,7 @@ public async Task Can_Be_Notified_Of_Resource_Changes()
await notificationRead;

resources = await client.ListResourcesAsync(cancellationToken: TestContext.Current.CancellationToken);
Assert.Equal(6, resources.Count);
Assert.Equal(8, resources.Count);
Assert.Contains(resources, t => t.Name == "NewResource");

notificationRead = listChanged.Reader.ReadAsync(TestContext.Current.CancellationToken);
Expand All @@ -195,7 +196,7 @@ public async Task Can_Be_Notified_Of_Resource_Changes()
}

resources = await client.ListResourcesAsync(cancellationToken: TestContext.Current.CancellationToken);
Assert.Equal(5, resources.Count);
Assert.Equal(7, resources.Count);
Assert.DoesNotContain(resources, t => t.Name == "NewResource");
}

Expand Down Expand Up @@ -239,6 +240,73 @@ await Assert.ThrowsAsync<McpProtocolException>(async () => await client.ReadReso
cancellationToken: TestContext.Current.CancellationToken));
}

[Fact]
public async Task Logs_Resource_Uri_On_Successful_Read()
{
await using McpClient client = await CreateMcpClientForServer();

var result = await client.ReadResourceAsync(
"resource://mcp/some_neat_direct_resource",
cancellationToken: TestContext.Current.CancellationToken);

Assert.NotNull(result);

var infoLog = Assert.Single(MockLoggerProvider.LogMessages, m => m.Message == "ReadResource \"resource://mcp/some_neat_direct_resource\" completed.");
Assert.Equal(LogLevel.Information, infoLog.LogLevel);
}

[Fact]
public async Task Logs_Resource_Uri_When_Resource_Throws()
{
await using McpClient client = await CreateMcpClientForServer();

await Assert.ThrowsAsync<McpProtocolException>(async () => await client.ReadResourceAsync(
"resource://mcp/throws_exception",
cancellationToken: TestContext.Current.CancellationToken));

var errorLog = Assert.Single(MockLoggerProvider.LogMessages, m => m.LogLevel == LogLevel.Error);
Assert.Equal("ReadResource \"resource://mcp/throws_exception\" threw an unhandled exception.", errorLog.Message);
Assert.IsType<InvalidOperationException>(errorLog.Exception);
}

[Fact]
public async Task Logs_Resource_Error_When_Resource_Throws_OperationCanceledException()
{
await using McpClient client = await CreateMcpClientForServer();

await Assert.ThrowsAsync<McpProtocolException>(async () => await client.ReadResourceAsync(
"resource://mcp/throws_operation_canceled_exception",
cancellationToken: TestContext.Current.CancellationToken));

Assert.Contains(MockLoggerProvider.LogMessages, m =>
m.LogLevel == LogLevel.Error &&
m.Message == "ReadResource \"resource://mcp/throws_operation_canceled_exception\" threw an unhandled exception." &&
m.Exception is OperationCanceledException);

Assert.Contains(MockLoggerProvider.LogMessages, m =>
m.LogLevel == LogLevel.Warning &&
m.Message.Contains("request handler failed"));
}

[Fact]
public async Task Logs_Resource_Error_When_Resource_Throws_McpProtocolException()
{
await using McpClient client = await CreateMcpClientForServer();

await Assert.ThrowsAsync<McpProtocolException>(async () => await client.ReadResourceAsync(
"resource://mcp/throws_mcp_protocol_exception",
cancellationToken: TestContext.Current.CancellationToken));

Assert.Contains(MockLoggerProvider.LogMessages, m =>
m.LogLevel == LogLevel.Error &&
m.Message == "ReadResource \"resource://mcp/throws_mcp_protocol_exception\" threw an unhandled exception." &&
m.Exception is McpProtocolException);

Assert.Contains(MockLoggerProvider.LogMessages, m =>
m.LogLevel == LogLevel.Warning &&
m.Message.Contains("request handler failed"));
}

[Fact]
public async Task Throws_Exception_On_Unknown_Resource()
{
Expand Down Expand Up @@ -361,6 +429,12 @@ public sealed class SimpleResources

[McpServerResource]
public static string ThrowsException() => throw new InvalidOperationException("uh oh");

[McpServerResource]
public static string ThrowsOperationCanceledException() => throw new OperationCanceledException("Resource was canceled");

[McpServerResource]
public static string ThrowsMcpProtocolException() => throw new McpProtocolException("Resource protocol error", McpErrorCode.InvalidParams);
}

[McpServerResourceType]
Expand Down
Loading