diff --git a/src/ModelContextProtocol.Core/McpSessionHandler.cs b/src/ModelContextProtocol.Core/McpSessionHandler.cs index dd681464..0b915c9f 100644 --- a/src/ModelContextProtocol.Core/McpSessionHandler.cs +++ b/src/ModelContextProtocol.Core/McpSessionHandler.cs @@ -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() @@ -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: @@ -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 { @@ -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);