Skip to content

Add request duration to LogRequestHandlerCompleted and LogRequestHandlerException log messages #1092

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

Open
Copilot wants to merge 7 commits into
base: main
Choose a base branch
from
+17 −10
Open

Add request duration to LogRequestHandlerCompleted and LogRequestHandlerException log messages #1092

Changes from all commits
Commits
Show all changes
7 commits
Select commit Hold shift + click to select a range
092f328
Initial plan
Copilot Dec 12, 2025
08315a9
Add duration logging to LogRequestHandlerCompleted
Copilot Dec 12, 2025
b9c408e
Address code review feedback: use static regex and culture-invariant …
Copilot Dec 12, 2025
54dad60
Apply code review feedback: inline duration calculation and remove lo…
Copilot Dec 12, 2025
75bfca5
Add duration logging to LogRequestHandlerException and consolidate ti…
Copilot Dec 13, 2025
7b01775
Colocate LogRequestHandlerCalled with completion/failure logs in Hand…
Copilot Dec 13, 2025
46becf2
Merge branch 'main' into copilot/improve-log-request-duration
stephentoub Dec 13, 2025
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
27 changes: 17 additions & 10 deletions src/ModelContextProtocol.Core/McpSessionHandler.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -179,8 +179,6 @@ ex is OperationCanceledException &&

if (!isUserCancellation && message is JsonRpcRequest request)
{
LogRequestHandlerException(EndpointName, request.Method, ex);

JsonRpcErrorDetail detail = ex switch
{
UrlElicitationRequiredException urlException => new()
Expand Down Expand Up @@ -282,8 +280,19 @@ private async Task HandleMessageAsync(JsonRpcMessage message, CancellationToken
switch (message)
{
case JsonRpcRequest request:
var result = await HandleRequest(request, cancellationToken).ConfigureAwait(false);
AddResponseTags(ref tags, activity, result, method);
LogRequestHandlerCalled(EndpointName, request.Method);
long requestStartingTimestamp = Stopwatch.GetTimestamp();
try
{
var result = await HandleRequest(request, cancellationToken).ConfigureAwait(false);
LogRequestHandlerCompleted(EndpointName, request.Method, GetElapsed(requestStartingTimestamp).TotalMilliseconds);
AddResponseTags(ref tags, activity, result, method);
}
catch (Exception ex)
{
LogRequestHandlerException(EndpointName, request.Method, GetElapsed(requestStartingTimestamp).TotalMilliseconds, ex);
throw;
}
break;

case JsonRpcNotification notification:
Expand Down Expand Up @@ -354,9 +363,7 @@ private void HandleMessageWithId(JsonRpcMessage message, JsonRpcMessageWithId me
throw new McpProtocolException($"Method '{request.Method}' is not available.", McpErrorCode.MethodNotFound);
}

LogRequestHandlerCalled(EndpointName, request.Method);
JsonNode? result = await handler(request, cancellationToken).ConfigureAwait(false);
LogRequestHandlerCompleted(EndpointName, request.Method);

await SendMessageAsync(new JsonRpcResponse
{
Expand Down Expand Up @@ -882,11 +889,11 @@ private static McpProtocolException CreateRemoteProtocolException(JsonRpcError e
[LoggerMessage(Level = LogLevel.Information, Message = "{EndpointName} method '{Method}' request handler called.")]
private partial void LogRequestHandlerCalled(string endpointName, string method);

[LoggerMessage(Level = LogLevel.Information, Message = "{EndpointName} method '{Method}' request handler completed.")]
private partial void LogRequestHandlerCompleted(string endpointName, string method);
[LoggerMessage(Level = LogLevel.Information, Message = "{EndpointName} method '{Method}' request handler completed in {ElapsedMilliseconds}ms.")]
private partial void LogRequestHandlerCompleted(string endpointName, string method, double elapsedMilliseconds);

[LoggerMessage(Level = LogLevel.Warning, Message = "{EndpointName} method '{Method}' request handler failed.")]
private partial void LogRequestHandlerException(string endpointName, string method, Exception exception);
[LoggerMessage(Level = LogLevel.Warning, Message = "{EndpointName} method '{Method}' request handler failed in {ElapsedMilliseconds}ms.")]
private partial void LogRequestHandlerException(string endpointName, string method, double elapsedMilliseconds, Exception exception);

[LoggerMessage(Level = LogLevel.Information, Message = "{EndpointName} received request for unknown request ID '{RequestId}'.")]
private partial void LogNoRequestFoundForMessageWithId(string endpointName, RequestId requestId);
Expand Down