Add request duration to LogRequestHandlerCompleted and LogRequestHandlerException log messages (#1092)

Co-authored-by: copilot-swe-agent[bot] <198982749+Copilot@users.noreply.github.com>
Co-authored-by: stephentoub <2642209+stephentoub@users.noreply.github.com>
This commit is contained in:
Copilot 2025-12-15 09:50:52 -08:00 • committed by GitHub
commit 31fcc1eb44
No known key found for this signature in database
GPG key ID: B5690EEEBB952194

View file

@ -179,8 +179,6 @@ internal sealed partial class McpSessionHandler : IAsyncDisposable
if (!isUserCancellation && message is JsonRpcRequest request) if (!isUserCancellation && message is JsonRpcRequest request)
{ {
LogRequestHandlerException(EndpointName, request.Method, ex);
JsonRpcErrorDetail detail = ex switch JsonRpcErrorDetail detail = ex switch
{ {
UrlElicitationRequiredException urlException => new() UrlElicitationRequiredException urlException => new()
@ -282,8 +280,19 @@ internal sealed partial class McpSessionHandler : IAsyncDisposable
switch (message) switch (message)
{ {
case JsonRpcRequest request: case JsonRpcRequest request:
var result = await HandleRequest(request, cancellationToken).ConfigureAwait(false); LogRequestHandlerCalled(EndpointName, request.Method);
AddResponseTags(ref tags, activity, result, 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; break;
case JsonRpcNotification notification: case JsonRpcNotification notification:
@ -354,9 +363,7 @@ internal sealed partial class McpSessionHandler : IAsyncDisposable
throw new McpProtocolException($"Method '{request.Method}' is not available.", McpErrorCode.MethodNotFound); throw new McpProtocolException($"Method '{request.Method}' is not available.", McpErrorCode.MethodNotFound);
} }
LogRequestHandlerCalled(EndpointName, request.Method);
JsonNode? result = await handler(request, cancellationToken).ConfigureAwait(false); JsonNode? result = await handler(request, cancellationToken).ConfigureAwait(false);
LogRequestHandlerCompleted(EndpointName, request.Method);
await SendMessageAsync(new JsonRpcResponse await SendMessageAsync(new JsonRpcResponse
{ {
@ -882,11 +889,11 @@ internal sealed partial class McpSessionHandler : IAsyncDisposable
[LoggerMessage(Level = LogLevel.Information, Message = "{EndpointName} method '{Method}' request handler called.")] [LoggerMessage(Level = LogLevel.Information, Message = "{EndpointName} method '{Method}' request handler called.")]
private partial void LogRequestHandlerCalled(string endpointName, string method); private partial void LogRequestHandlerCalled(string endpointName, string method);
[LoggerMessage(Level = LogLevel.Information, Message = "{EndpointName} method '{Method}' request handler completed.")] [LoggerMessage(Level = LogLevel.Information, Message = "{EndpointName} method '{Method}' request handler completed in {ElapsedMilliseconds}ms.")]
private partial void LogRequestHandlerCompleted(string endpointName, string method); private partial void LogRequestHandlerCompleted(string endpointName, string method, double elapsedMilliseconds);
[LoggerMessage(Level = LogLevel.Warning, Message = "{EndpointName} method '{Method}' request handler failed.")] [LoggerMessage(Level = LogLevel.Warning, Message = "{EndpointName} method '{Method}' request handler failed in {ElapsedMilliseconds}ms.")]
private partial void LogRequestHandlerException(string endpointName, string method, Exception exception); 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}'.")] [LoggerMessage(Level = LogLevel.Information, Message = "{EndpointName} received request for unknown request ID '{RequestId}'.")]
private partial void LogNoRequestFoundForMessageWithId(string endpointName, RequestId requestId); private partial void LogNoRequestFoundForMessageWithId(string endpointName, RequestId requestId);