Asp.Net Mvc记录接口耗时的方法

网站维护阶段，我们往往需要统计网站所有接口的执行时间。以便于从统计分析的角度，定位出最耗时的接口，从而找出性能瓶颈，优化网站性能。耗时接口的记录可以用过滤器来实现。

本文参考文章：asp.net mvc 记录Action耗时 感谢博主哈。但我在网站维护过程中发现文中的方法存在一个缺陷：它并不是线程安全的，访问量大时会一直抛异常，导致cpu跑满。现在此基础上稍作如下改动，特此记录。

新建过滤器

在您的项目添加过滤器。

using System;
using System.Collections.Concurrent;
using System.Web.Mvc;
using NLog;

namespace YourNameSpace.Uitl.Filters
{
    public class ThreadInfoModel
    {
        public DateTime StartTime { get; set; }
        public string Url { get; set; }
    }

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

        public override void OnActionExecuting(ActionExecutingContext filterContext)
        {
            //过滤掉ChildAction, 因为ChildAction实际上不是一个单独的页面
            if (filterContext.IsChildAction) return;
            var currentThreadId = System.Threading.Thread.CurrentThread.ManagedThreadId;
            try
            {
                var model = new ThreadInfoModel
                {
                    StartTime = DateTime.Now,
                    Url = filterContext.HttpContext.Request.Url == null ? string.Empty : filterContext.HttpContext.Request.Url.AbsoluteUri
                };
                _threadInfo.TryAdd(currentThreadId, model);
            }
            catch (Exception ex)
            {
                Log.Error(ex.ToString());
            }
        }

        public override void OnResultExecuted(ResultExecutedContext filterContext)
        {
            var currentThreadId = System.Threading.Thread.CurrentThread.ManagedThreadId;
            try
            {
                ThreadInfoModel model;
                bool isFind = _threadInfo.TryGetValue(currentThreadId, out model);
                if(!isFind ||  model == null)
                {
                    return;
                }
                //计算出当前请求访问耗时
                var timeSpan = (DateTime.Now - model.StartTime).TotalMilliseconds;
                if (timeSpan > 500)
                {
                    if(timeSpan > 2000)
                    {
                        //如果耗时超过2秒，就直接打印输出Error文件夹下，进行重点关注
                        Log.Error($"运行时间超过2秒，共花费{timeSpan}毫秒.  URL: {model.Url}, ThreadId: {currentThreadId}");
                    }
                    //如果耗时超过500毫秒，就是用log打印出来，具体是哪个页面访问超过了500豪秒，具体使用了多长时间。
                    Log.Info($"运行时间超过500毫秒，共花费{timeSpan}毫秒.  URL: {model.Url}, ThreadId: {currentThreadId}");
                }
            }
            catch (Exception ex)
            {
                Log.Error(ex.ToString());
            }
            finally
            {
                ThreadInfoModel model;
                _threadInfo.TryRemove(currentThreadId, out model);
            }
        }
    }
}

关于NLog的配置和使用，本文不再赘述。可自行百度进行配置。

注册全局过滤器

在【您的web项目】->【App_Start】->【FilterConfig.cs】中引用过滤器，并注册耗时日志全局过滤器。

using System.Web.Mvc;
using YourNameSpace.Uitl.Filters;

namespace YourNameSpace.Web
{
    public class FilterConfig
    {
        public static void RegisterGlobalFilters(GlobalFilterCollection filters)
        {
            //注册全局过滤器
            filters.Add(new HandleErrorAttribute());
            //注册耗时日志全局过滤器
            filters.Add(new TimingActionFilter());
        }
    }
}

耗时日志打印结果