Calculate execution time for your ASP.NET WEB API controller actions using Autofac action filter

Requirement

• Calculate execution time of ASP.NET WEB API actions
• Create a common code that can calculate and log the details
• Project uses Autofac for Dependency Injection.

If you've integrated Azure Application Insights to your WEB API, automatically it'll log/capture the execution time of each request. If you need it as additional logging or in place where Application Insights not associated, this will be helpful. Let us get into the code directly.

Approach 

1. We will be using ActionFilter to write the logic for calculating the execution time.
2. In case of WEB API that uses Autofac as dependency resolver, we can utilize the IAutofacActionFilter to achieve the same.
3. Register the respective action filter globally to execute for all controllers and actions, so that you don't need to worry when you add new controllers/actions.
4. In the below example I provided the sample snippet related to Autofac based solution. Ignore the Custom logger in the below example as it is just for portraying the sample.

Snippet1: (Action Filter that calculates the execution time and logs)

using System;

using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Web;
using System.Web.Http.Controllers;
using System.Web.Http.Filters;
using Autofac.Integration.WebApi;

namespace TestWebAPI1.Utils
{
    public class ExecutionTimeActionFilterAttribute : IAutofacActionFilter
    {
        private const string StopwatchInstanceKey = "StopwatchInstance";

        private readonly ICustomLogger1 logger;

        public ExecutionTimeActionFilterAttribute(ICustomLogger1 loggerParam)
        {
            this.logger = loggerParam;
        }


        public void OnActionExecuting(HttpActionContext actionContext)
        {
            Stopwatch stopwatchInstance = new Stopwatch();
            actionContext.Request.Properties[StopwatchInstanceKey] = stopwatchInstance;
            stopwatchInstance.Start();
        }

        public void OnActionExecuted(HttpActionExecutedContext actionExecutedContext)
        {
            if (!actionExecutedContext.Request.Properties.ContainsKey(StopwatchInstanceKey))
            {
                return;
            }

            Stopwatch stopwatchInstance = actionExecutedContext.Request.Properties[StopwatchInstanceKey] as Stopwatch;
            if (stopwatchInstance == null)
            {
                return;
            }

            stopwatchInstance.Stop();
            string actionName = actionExecutedContext.ActionContext.ActionDescriptor.ActionName;

            this.logger.WriteLine($"Execution time of action : {actionName} in controller : {actionExecutedContext.ActionContext.ControllerContext.ControllerDescriptor.ControllerName} is {stopwatchInstance.ElapsedMilliseconds} milliseconds");
        }
    }
}

Snippet 2: (Autofac registration in WebApiConfig)

namespace TestWebAPI1
{
    public static class WebApiConfig
    {
        public static void Register(HttpConfiguration config)
        {
            // Web API configuration and services
            // Configure Web API to use only bearer token authentication.
            config.SuppressDefaultHostAuthentication();
            config.Filters.Add(new HostAuthenticationFilter(OAuthDefaults.AuthenticationType));

            // Web API routes
            config.MapHttpAttributeRoutes();

            config.Routes.MapHttpRoute(
                name: "DefaultApi",
                routeTemplate: "api/{controller}/{id}",
                defaults: new { id = RouteParameter.Optional }
            );

            var builder = new ContainerBuilder();
            
            builder.RegisterType<CustomLogger1>().As<ICustomLogger1>().InstancePerDependency();
            
            builder.RegisterApiControllers(Assembly.GetExecutingAssembly());
            
            builder.RegisterWebApiFilterProvider(config);
            builder.Register(c => new ExecutionTimeActionFilterAttribute(c.Resolve<ICustomLogger1>()))
                .AsWebApiActionFilterFor<ApiController>()
                .InstancePerRequest();

            var container = builder.Build();
            config.DependencyResolver = new AutofacWebApiDependencyResolver(container);
        }
    }
}

References

The concept has been taken based on the suggestions by some blogs and stackoverflow forums (unable to recall exact article).