Custom Web Api asynchronous filter implementation

Question

Following the tutorial from Filip W's blog, I've ended up creating my own implementation for a custom ActionFilter.

This logs the execution name, action, parameters and elapsed time of every ApiController in my solution.

The post is a bit old (2013), that's why I'm still thinking it must be a better/simpler way to do this, any suggestion? improvements?

public sealed class LogActionFilter : FilterAttribute, IActionFilter
{
 private readonly Stopwatch _stopwatch = new Stopwatch();
 public bool AllowMultiple => false;
 public async Task<HttpResponseMessage> ExecuteActionFilterAsync(HttpActionContext actionContext,
 CancellationToken cancellationToken, Func<Task<HttpResponseMessage>> continuation)
 {
 await InternalActionExecuting(actionContext);
 if (actionContext.Response != null)
 return actionContext.Response;
 HttpActionExecutedContext executedContext;
 try
 {
 var response = await continuation();
 executedContext = new HttpActionExecutedContext(actionContext, null)
 {
 Response = response
 };
 }
 catch (Exception exception)
 {
 executedContext = new HttpActionExecutedContext(actionContext, exception);
 }
 await InternalActionExecuted(executedContext);
 _stopwatch.Reset();
 return executedContext.Response;
 }
 private Task InternalActionExecuting(HttpActionContext actionContext)
 {
 _stopwatch.Start();
 return Log("Executing", actionContext, 0);
 }
 private Task InternalActionExecuted(HttpActionExecutedContext actionExecutedContext)
 {
 _stopwatch.Stop();
 return Log("Executed", actionExecutedContext.ActionContext, _stopwatch.ElapsedMilliseconds);
 }
 private Task Log(string action, HttpActionContext actionContext, long elapsedTime)
 {
 return Task.Run(() =>
 {
 var controllerName = actionContext.ControllerContext.ControllerDescriptor.ControllerName;
 var actionName = actionContext.ActionDescriptor.ActionName;
 var parameters = string.Join(", ", actionContext.ActionArguments.Values.Select(x => x).ToArray());
 var message = $"{action}: ctrl: {controllerName}, act: {actionName}, params: {parameters}" +
 $"{(elapsedTime > 0 ? "took (ms): " + elapsedTime : string.Empty) }";
 Trace.WriteLine(message, "Action filter log");
 });
 }
}

Answer 1

Here is couple of things that I could done;

• Implement a logger class, Logging with "Trace.WriteLine" is not usefull for everycase.
• Override allow multiple; public override bool AllowMultiple => false;

• Log the error...

  public sealed class LogActionFilter : FilterAttribute, IActionFilter
  {
   private readonly ILogManager _logManager;
   public LogActionFilter(ILogManager logManager)
   {
   _logManager = logManager;
   }
   private readonly Stopwatch _stopwatch = new Stopwatch();
   public override bool AllowMultiple => false;
   public async Task<HttpResponseMessage> ExecuteActionFilterAsync(HttpActionContext actionContext,
   CancellationToken cancellationToken,
   Func<Task<HttpResponseMessage>> continuation)
   {
   await InternalActionExecuting(actionContext);
   if (actionContext.Response != null)
   {
   return actionContext.Response;
   }
   HttpActionExecutedContext executedContext;
   try
   {
   var response = await continuation();
   executedContext = new HttpActionExecutedContext(actionContext, null)
   {
   Response = response
   };
   }
   catch (Exception exception)
   {
   executedContext = new HttpActionExecutedContext(actionContext, exception);
   _logManager.Error(exception, "LogAction recorded an error");
   }
   await InternalActionExecuted(executedContext);
   _stopwatch.Reset();
   return executedContext.Response;
   }
   private Task InternalActionExecuting(HttpActionContext actionContext)
   {
   _stopwatch.Start();
   return Log("Executing", actionContext, 0);
   }
   private Task InternalActionExecuted(HttpActionExecutedContext actionExecutedContext)
   {
   _stopwatch.Stop();
   return Log("Executed", actionExecutedContext.ActionContext, _stopwatch.ElapsedMilliseconds);
   }
   private Task Log(string action, HttpActionContext actionContext, long elapsedTime)
   {
   return Task.Run(() =>
   {
   var controllerName = actionContext.ControllerContext.ControllerDescriptor.ControllerName;
   var actionName = actionContext.ActionDescriptor.ActionName;
   var parameters = string.Join(", ", actionContext.ActionArguments.Values.Select(x => x).ToArray());
   var message = $"{action}: ctrl: {controllerName}, act: {actionName}, params: {parameters}" +
   $"{(elapsedTime > 0 ? "took (ms): " + elapsedTime : string.Empty)}";
  #if (DEBUG)
   Trace.WriteLine(message, "Action filter log");
  #elif (RELEASE)
   _logManager.Debug(null, message, "Action filter log");
  #endif
   });
   }
  }