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目录，所有日志文件都存放在里面

例：Logs2017-03-30InfoAll.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:点击下载