Post History

Measure ASP.NET Core 3.1 Web API action execution times

This is basically [an unanswered code review request](https://codereview.stackexchange.com/questions/235812/accurately-measure-asp-net-core-3-x-actions-execution-times-web-api-project) of mine from [CodeReview Stack Exchange](https://codereview.stackexchange.com/).

I want to be able to log as accurately as possible, the time spent by a certain Web API action in an ASP.NET Core 3.1 Web API.

I found out [this very old question][1] dealing with a similar issue in ASP.NET. The solution relies on global action filters, but in ASP.NET Core, I think middlewares are more appropriate. 

From a client's perspective I want to measure as accurately as possible the following time:

    Time to first byte - Time spent to send the request


So, using a slightly modified code from [c-sharpcorner][2] I have implemented the following:

    /// <summary>
    /// tries to measure request processing time
    /// </summary>
    public class ResponseTimeMiddleware
    {
        // Name of the Response Header, Custom Headers starts with "X-"  
        private const string ResponseHeaderResponseTime = "X-Response-Time-ms";

        // Handle to the next Middleware in the pipeline  
        private readonly RequestDelegate _next;

        ///<inheritdoc/>
        public ResponseTimeMiddleware(RequestDelegate next)
        {
            _next = next;
        }

        ///<inheritdoc/>
        public Task InvokeAsync(HttpContext context)
        {
            // skipping measurement of non-actual work like OPTIONS
            if (context.Request.Method == "OPTIONS")
                return _next(context);

            // Start the Timer using Stopwatch  
            var watch = new Stopwatch();
            watch.Start();

            context.Response.OnStarting(() => {
                // Stop the timer information and calculate the time   
                watch.Stop();
                var responseTimeForCompleteRequest = watch.ElapsedMilliseconds;
                // Add the Response time information in the Response headers.   
                context.Response.Headers[ResponseHeaderResponseTime] = responseTimeForCompleteRequest.ToString();

                var logger = context.RequestServices.GetService<ILoggingService>();
                string fullUrl = $"{context.Request.Scheme}://{context.Request.Host}{context.Request.Path}{context.Request.QueryString}";
                logger?.LogDebug($"[Performance] Request to {fullUrl} took {responseTimeForCompleteRequest} ms");

                return Task.CompletedTask;
            });

            // Call the next delegate/middleware in the pipeline   
            return _next(context);
        }
    }

**Startup.cs (plugging the middleware)**

    public void Configure(IApplicationBuilder app, IWebHostEnvironment env, ILoggerFactory loggerFactory,
        ILoggingService logger, IHostApplicationLifetime lifetime, IServiceProvider serviceProvider)
    {
        app.UseResponseCaching();

        app.UseMiddleware<ResponseTimeMiddleware>();

        // ...
    }

Is this a good approach? I am mostly interested in optimizing the following:

- time measurement accuracy 
- overhead

  [1]: https://stackoverflow.com/questions/11353155/measure-time-invoking-asp-net-mvc-controller-actions
  [2]: https://www.c-sharpcorner.com/article/measuring-and-reporting-the-response-time-of-an-asp-net-core-api/