asp.net mvc 記錄Action耗時

可能有些時候需要記錄Action的執行時間來優化系統功能，這時可以用過濾器來實現。

新建項目

項目名稱隨便取

身份驗證：不進行身份驗證

安裝Nlog

這里使用NLog來輸出日志，具體使用說明請看：https://github.com/nlog/NLog/wiki（相比log4net文檔說明會好很多）

解決方案中右鍵，選擇管理NuGet包

在瀏覽中輸入:"nlog",我使用是VS2015，其它版本類似

選擇Nlog.Config的目的是順便把配置文件也下載了

選擇確定

安裝時會輸出相關信息，沒有任何錯誤就說明成功了

修改配置文件

在ActionTime項目下應該可以看到NLog.config文件，配置文件內容如下：

<?xml version="1.0" encoding="utf-8" ?>
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
  <!-- shortdate:2017-3-30 level:Error、Info...-->
  <variable name="logDirectory" value="${basedir}/Logs/${shortdate}/${level}"/>
  <targets>
    <target xsi:type="File" name="AllFile" fileName="${logDirectory}/All.log"
            layout="${longdate}        ■${level}${newline}    ▲${stacktrace}${newline}    ◇${callsite:className=True:fileName=True:includeSourcePath=True:methodName=True}${newline}    ◆${message}${newline}${newline}***************************************************************************"
            archiveFileName="${logDirectory}/archives/All_${shortdate}.{#####}.log"
            archiveAboveSize="1024000"
            archiveNumbering="Sequence"
            concurrentWrites="true"
            keepFileOpen="false"/>
  </targets>
  <rules>
    <logger name="*" minlevel="Trace" writeTo="AllFile" />
  </rules>
</nlog>

此配置會在項目下新建Logs目錄，所有日志文件都存放在里面

例：Logs\2017-03-30\Info\All.Log

新建過濾器類

接着在ActimTime項目中新建一個目錄Filters，此目錄用來存放自定義過濾器類

在Filters目錄下新建一個類TimingActionFilter

public class TimingActionFilter : ActionFilterAttribute
    {
        
        private static readonly Logger Log = LogManager.GetCurrentClassLogger(typeof(TimingActionFilter));

        //創建字典來記錄開始時間，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 timeSpan = (DateTime.Now - _start[currentThreadId]).TotalMilliseconds;
                if (timeSpan > 500)//如果耗時超過500毫秒，就是用log4net打印出，具體是哪個頁面訪問超過了500豪秒，具體使用了多長時間。
                {
                    Log.Info(string.Format("運行時間超過500毫秒，共花費{1}毫秒.  URL: {0}", _url[currentThreadId], timeSpan));
                }
            }
            catch (Exception ex)
            {
                Log.Error(ex.ToString());
            }
            finally
            {
                _start.Remove(currentThreadId);
                _url.Remove(currentThreadId);
            }
        }
    }

 修改控制器

打開HomeController，修改Index為如下：

public ActionResult Index()
        {
            Thread.Sleep(1000);//添加延時
            return View();
        }

 修改FilterConfig

再打開FilterConfig文件，修改代碼如下：

public static void RegisterGlobalFilters(GlobalFilterCollection filters)
        {
            filters.Add(new HandleErrorAttribute());
            filters.Add(new TimingActionFilter());//自己定義的過濾器
        }

 啟動

現在基本工作已經完成，按F5啟動項目，可以看到在項目目錄下有個Logs目錄

查看

打開日志文件內容為如下，一般這種情況把日志寫入數據庫會比較好分析

 

Demo:點擊下載