使用Filter跟踪Asp.net MVC页面加载时间

昵称10504424 2014-10-28

展开全文

最近，客户一直反馈系统使用慢，有时候能够指出具体是哪个页面，有时候又只是笼统地反馈慢。这种问题就像是幽灵一样，非常不好处理。因为导致这种问题的因素非常之多，而且在开发工程中，很难模拟出实际运行是的环境。理论上，对于所有的页面做压力测试是个解决方案，但是这种方式的成本太高，又没有办法很快地定位和解决客户的问题。

最后，考虑通过创建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);
}
}
}