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

Jump to bottom
Open
Copilot wants to merge 9 commits into
base: main
Choose a base branch
from
Open

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

Copilot wants to merge 9 commits into from

Conversation

Copy link
Contributor

Copilot AI commented Feb 10, 2026 •
edited
Loading

  • Add ToolCallCompleted log message in McpServerImpl.cs that captures the tool name and IsError on tool call completion
  • Include CallToolResult.IsError as a parameter in the ToolCallCompleted log
  • Always log ToolCallCompleted when InvokeAsync doesn't throw, even with IsError=true
  • Skip ToolCallCompleted in outer handler for task-augmented calls to avoid double-logging
  • Add tests for tool logging (success, IsError, throw)
  • Add tests for task-path tool logging (success, IsError, throw)
  • Fix task-path tests to use GetTaskResultAsync instead of Task.Delay
  • Add prompt logging (GetPromptCompleted/GetPromptError) with tests
  • Add resource logging (ReadResourceCompleted/ReadResourceError) with tests
  • Update ToolCallError, GetPromptError, ReadResourceError to log for ALL exception types
  • Add tests for OperationCanceledException and McpProtocolException verifying both named error log and LogRequestHandlerException
  • Produce errored CallToolResult for OperationCanceledException when passed-in token is NOT canceled, with regression test
  • Merge three tool catch blocks into single catch (Exception e) with conditional rethrow
Original prompt

This section details on the original issue you should resolve

<issue_title>Capture tool call name in ILogger logs on success an not just failure</issue_title>
<issue_description>I was asked the following question:

[Them]: is there a way to pass a callback function to the streamablehttp handler to get the tool response (content body and IsError boolean flag)?
...
And also is there an easier way to track latency of each tool call? I know AOP can do it, but would be happy if sdk side has an easier way to achieve that.

To which I replied:

[Me]: This is probably best currently achieved with a custom ILoggerProvider. We added a test verifying you can observe this here. You don't have to new up a LoggerFactory like the test does. You can just call builder.Logging.AddProvider(myCustomProvider), and retain all your other logger providers (e.g. console, ETW). And the tool name is a parameter to structured logging, so you can reliably retrieve that from the TState which is IReadOnlyList<KeyValuePair<string, object?>>.

csharp-sdk/tests/ModelContextProtocol.Tests/Server/McpServerToolTests.cs at c560f47ee6d439beb38619222af3f97b7aa529af · modelcontextprotocol/csharp-sdk
Logging providers - .NET | Microsoft Learn

You could also listen to the "mcp.server.operation.duration" otel metric. Like the similar otel metrics for HTTP request duration, it captures a lot more than just the "duration". As you can see here, we add a lot of relevant tags.

But it turns out we don't have an ILogger log whith the tool name in the message (or LoggerMessage.LogValues struct) for successful invocations the way we do for errors since #447.

[Them]: thanks a lot for the pointer, however I can't see the real mcp tool name in the "state" param, am I missing something?

I think the problem is the sdk doesn't add the tool name in logging. https://github.com/modelcontextprotocol/csharp-sdk/blob/c560f47ee6d439beb38619222af3f97b7aa529af/src/ModelContextProtocol.Core/McpSession.cs#L315C36-L315C48, but just the endpoint name and request method(e.g. 'tools/call')

[Me]: My bad. If you're willing to go the otel route and write an ActivityListener instead, that does include the mcp.tool.name as a tag for the mcp.server.operation.duration metric, so you could use that. I filed an issue to include this in an ILogger log as well. We should be able to ship an update with that to NuGet next week.</issue_description>

<agent_instructions>Please use ClientServerTestBase.MockLoggerProvider to verify the fix. Try to find a similar test for the McpServerImpl.ToolCallError log and put the new test nearby. If it does not exist already, add a new test for the ToolCallError too.</agent_instructions>

Comments on the Issue (you are @copilot in this section)

💬 We'd love your input! Share your thoughts on Copilot coding agent in our 2 minute survey.

Copilot AI and others added 2 commits February 10, 2026 00:50
@halter73
Add ToolCallCompleted success log with tool name in McpServerImpl
ee969d2 
Add a LoggerMessage-based ToolCallCompleted log at Information level that
captures the tool name on successful tool call completion, matching the
existing ToolCallError pattern for failures.

Also add the log call to the task-augmented tool execution path.

Add test Logs_Tool_Name_On_Successful_Call to verify the new log message.

Co-authored-by: halter73 <54385+halter73@users.noreply.github.com>
@halter73
Move ToolCallCompleted log after IsError check in task path
88dc771 
Address code review: only log ToolCallCompleted when the task-augmented
tool execution result indicates success (not IsError).

Co-authored-by: halter73 <54385+halter73@users.noreply.github.com>
Copilot AI changed the title [WIP] Capture tool call name in ILogger logs on success Log tool call name on success, not just failure Feb 10, 2026
Copilot AI requested a review from halter73 February 10, 2026 00:57
@halter73 halter73 marked this pull request as ready for review February 10, 2026 02:46
@halter73 halter73 requested a review from stephentoub February 10, 2026 02:46
stephentoub
stephentoub reviewed Feb 10, 2026
View reviewed changes
stephentoub
stephentoub previously approved these changes Feb 10, 2026
View reviewed changes
halter73
halter73 reviewed Feb 10, 2026
View reviewed changes
Copy link
Contributor

@halter73 halter73 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please include CallToolResult.IsError in the log.

@halter73
Include IsError in ToolCallCompleted log, add task-path tests
c18f406 
Address reviewer feedback:
- Include CallToolResult.IsError as a parameter in the ToolCallCompleted
  log message (@halter73)
- Always log ToolCallCompleted when InvokeAsync doesn't throw, including
  when IsError=true (@halter73)
- Skip ToolCallCompleted in outer handler for task-augmented calls to
  avoid double-logging; the async ExecuteToolAsTaskAsync logs separately
- Add ReturnIsError tool for testing IsError=true without throwing
- Add Logs_Tool_Name_With_IsError_When_Tool_Returns_Error test
- Add TaskPath_Logs_Tool_Name_On_Successful_Call test
- Add TaskPath_Logs_Tool_Name_With_IsError_When_Tool_Returns_Error test
- Add TaskPath_Logs_Error_When_Tool_Throws test
- Update tool count assertions for new ReturnIsError tool

Co-authored-by: halter73 <54385+halter73@users.noreply.github.com>
Copy link
Contributor Author

Copilot AI commented Feb 10, 2026

Please include CallToolResult.IsError in the log.

Done in c18f406. The log message is now "\"{ToolName}\" completed. IsError = {IsError}." with isError as a bool parameter.

Copilot AI requested a review from halter73 February 10, 2026 03:10
halter73
halter73 reviewed Feb 10, 2026
View reviewed changes
@halter73
Copy link
Contributor

halter73 commented Feb 10, 2026

@copilot Please address my comment about using GetTaskResultAsync to avoid Task.Delay in the new tests. Also, in a separate commit add similar logging and tests for prompts and resources for both when they succeed and throw.

Copilot AI and others added 2 commits February 10, 2026 03:44
@halter73
Replace Task.Delay with GetTaskResultAsync in task-path tests
515db78 
Use GetTaskResultAsync to wait for task completion instead of arbitrary
Task.Delay(500) calls, making tests deterministic and faster.

Co-authored-by: halter73 <54385+halter73@users.noreply.github.com>
@halter73
Add logging for prompts and resources (success and error)
d250e0d 
Add GetPromptCompleted/GetPromptError and ReadResourceCompleted/
ReadResourceError LoggerMessage methods, symmetric with the existing
tool logging. Wrap prompt and resource filter pipelines with try/catch
to log when handlers succeed or throw unhandled exceptions.

Add tests:
- Logs_Prompt_Name_On_Successful_Call
- Logs_Prompt_Name_When_Prompt_Throws
- Logs_Resource_Uri_On_Successful_Read
- Logs_Resource_Uri_When_Resource_Throws

Co-authored-by: halter73 <54385+halter73@users.noreply.github.com>
Copy link
Contributor Author

Copilot AI commented Feb 10, 2026

@copilot Please address my comment about using GetTaskResultAsync to avoid Task.Delay in the new tests. Also, in a separate commit add similar logging and tests for prompts and resources for both ...

Both addressed:

  • GetTaskResultAsync replaces Task.Delay in 515db78
  • Prompt and resource logging with tests in d250e0d

Copilot AI requested a review from halter73 February 10, 2026 03:57
stephentoub
stephentoub previously approved these changes Feb 10, 2026
View reviewed changes
halter73
halter73 requested changes Feb 11, 2026
View reviewed changes
@halter73
Log ToolCallError, GetPromptError, ReadResourceError for all exceptio…
10a2e6d 
…n types

Remove the exception type filter (when clause) from the error logging
catch blocks for prompts and resources, and add a second catch block
for tools, so that OperationCanceledException and McpProtocolException
are also logged with tool/prompt/resource names. Behavior is unchanged:
tools still produce IsError results for non-cancel/non-protocol
exceptions, and prompts/resources still rethrow all exceptions.

Add tests verifying error logging and LogRequestHandlerException for
OperationCanceledException and McpProtocolException in all three
handler types.

Co-authored-by: halter73 <54385+halter73@users.noreply.github.com>
@halter73
Produce errored CallToolResult for non-user-canceled OperationCancele…
1fe5536 
…dException

When a tool throws OperationCanceledException but the passed-in
cancellation token is not canceled, produce an errored CallToolResult
(IsError=true) instead of rethrowing. This prevents non-user-initiated
cancellations from propagating as protocol errors.

User-initiated cancellations (where cancellationToken.IsCancellationRequested
is true) still rethrow as before.

Co-authored-by: halter73 <54385+halter73@users.noreply.github.com>
Copilot AI requested a review from halter73 February 11, 2026 19:43
halter73
halter73 reviewed Feb 11, 2026
View reviewed changes
@halter73
Merge three tool catch blocks into single catch (Exception e)
f37777d 
Consolidate the OperationCanceledException, general exception, and
fallback catch blocks into a single catch (Exception e) with:
- One call to ToolCallError
- Conditional rethrow for user-initiated cancellation or McpProtocolException
- One return of errored CallToolResult for everything else

Co-authored-by: halter73 <54385+halter73@users.noreply.github.com>
Copilot AI requested a review from halter73 February 11, 2026 19:49
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@stephentoub stephentoub stephentoub approved these changes

+1 more reviewer

@halter73 halter73 halter73 approved these changes

Reviewers whose approvals may not affect merge requirements

Assignees

@halter73 halter73

Copilot code review Copilot

Labels

None yet

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

Capture tool call name in ILogger logs on success an not just failure

3 participants

@halter73 @stephentoub