title: How to use ActionFilterAttribute to log running times?
body: <p>I created an action filter for measuring running times of every action in an Web API v2.</p>
  
  <pre><code>public class RunningTimeAttribute : ActionFilterAttribute
      {
          private readonly ILogFactory _logFactory;
          private readonly ITimerFactory _timerFactory;
          private ITimer _timer;
          private ILogger _logger;
  
          public RunningTimeAttribute(ILogFactory logFactory, ITimerFactory timerFactory) {
              if(logFactory == null)
                  throw new ArgumentNullException("logFactory");
              if(timerFactory == null)
                  throw new ArgumentNullException("timerFactory");
  
              _logFactory = logFactory;
              _timerFactory = timerFactory;
          }
  
          public override void OnActionExecuting(HttpActionContext actionContext) {
              base.OnActionExecuting(actionContext);
              OnBeforeAction(actionContext);
          }
  
          public override void OnActionExecuted(HttpActionExecutedContext actionExecutedContext) {
              OnAfterAction(actionExecutedContext);
              base.OnActionExecuted(actionExecutedContext);
          }
  
          private void OnBeforeAction(HttpActionContext actionContext) {
              var controllerName = actionContext.ControllerContext.Controller.GetType().FullName;
              var actionName = actionContext.ActionDescriptor.ActionName;
  
              _logger = _logFactory.Create(controllerName);
              _logger.Trace("Action \"{0}\" begins execution", actionName);
  
              _timer = _timerFactory.Create();
              _timer.Start();
          }
  
          private void OnAfterAction(HttpActionExecutedContext actionExecutedContext) {
              var actionName = actionExecutedContext.ActionContext.ActionDescriptor.ActionName;
  
              _timer.Stop();
              _logger.Trace("Time elapsed for action \"{0}\": {1} msec", actionName, _timer.ElapsedMilliseconds);
          }
  
  }
  </code></pre>
  
  <p>However, action filters act as singletons, so when <code>OnActionExecuted</code> runs, I cannot be sure that the <code>_logger</code> and <code>_timer</code> correspond to the ones created for the <em>same action <code>OnActionExecuting</code></em>.</p>
  
  <p>Eg. </p>
  
  <ol>
  <li>Action Foo1 begins execution. <code>_logger = "logger1"</code>, <code>_timer = "timer1"</code>.</li>
  <li>Action Foo2 begins execution. <code>_logger = "logger2"</code>, <code>_timer = "timer2"</code> (they get overriden)</li>
  <li>Action Foo1 ends execution. It stops timer and logs elapsed time which is nonsense (end1-start2).</li>
  </ol>
  
  <p><strong>Question</strong>: Is there a way I can know in <code>OnActionExecuted</code> to which <code>OnActionExecuting</code> it corresponds? If there was some unique identifier for actions, I could use it as a key to a Dictionary to store any action-related objects such as loggers and timers. Is there any? Or some other solution?</p>