使用Filter跟蹤ASP.NET MVC頁面載入時間

最近，客戶一直反饋系統使用慢，有時候能夠指出具體是哪個頁面，有時候又只是籠統地反饋慢。這種問題就像是幽靈一樣，非常不好處理。因為導致這種問題的因素非常之多，而且在開發工程中，很難模擬出實際執行是的環境。理論上，對於所有的頁面做壓力測試是個解決方案，但是這種方式的成本太高，又沒有辦法很快地定位和解決客戶的問題。

最後，考慮通過建立Filter來在訪問Action之前記錄一個時間，在頁面Render完成之後，再記錄一下時間。通過比較這2個時間的差值來跟蹤每個頁面的載入效能。如果對於MVC中的Filter還不太熟悉，可以看這裡Asp.net MVC使用Filter解除Session, Cookie等依賴，文章有對於Filter的介紹和使用。

言歸正傳，直接上程式碼。通過繼承ActionFilterAttribute, 分別重寫OnActionExecuting和OnResultExecuted方法。

public class TrackPageLoadPerformanceAttribute : ActionFilterAttribute
   {

      //這裡使用log4net來列印出結果
       private static readonly ILog Log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType);

      //建立字典來記錄開始時間，key是訪問的執行緒Id.
       private readonly Dictionary<int, DateTime> _start = new Dictionary<int, DateTime>();

      //建立字典來記錄當前訪問的頁面Url.
       private readonly Dictionary<int, string > _url = new Dictionary<int, string>();

       public override void OnActionExecuting(ActionExecutingContext filterContext)
       {
           //過濾掉ChildAction, 因為ChildAction實際上不是一個單獨的頁面
           if(filterContext.IsChildAction) return;

           var currentThreadId = System.Threading.Thread.CurrentThread.ManagedThreadId;

           try
           {
               _start.Add(currentThreadId, DateTime.Now);
               _url.Add(currentThreadId, filterContext.HttpContext.Request.Url == null
                   ? string.Empty
                   : filterContext.HttpContext.Request.Url.AbsoluteUri);
           }
           catch (Exception ex)
           {
               Log.Error(ex.ToString());
           }
       }

       public override void OnResultExecuted(ResultExecutedContext filterContext)
       {
           var currentThreadId = System.Threading.Thread.CurrentThread.ManagedThreadId;
           if (!_start.ContainsKey(currentThreadId)) return;

           try
           {

                //計算出當前頁面訪問耗時
               var costSeconds = (DateTime.Now - _start[currentThreadId]).TotalSeconds;
               if (costSeconds > 2)//如果耗時超過2秒，就是用log4net列印出，具體是哪個頁面訪問超過了2秒，具體使用了多長時間。
               {
                   Log.Info(string.Format("Access the action more than 2 seconds. cost seconds {1}.  URL: {0}", _url[currentThreadId], costSeconds));
               }
           }
           catch (Exception ex)
           {
               Log.Error(ex.ToString());
           }
           finally
           {
               _start.Remove(currentThreadId);
               _url.Remove(currentThreadId);
           }
       }
   }

最後，將該Filter註冊成Global Filter，這樣，就能監控系統中所有頁面的載入時間了.

如果你也遇到和我類似的效能問題，不妨試試，加上這個Filter, online系統中哪個頁面慢，就能夠一目瞭然了。