跟踪方法的执行时间
本文关键字:执行时间 方法 跟踪 | 更新日期: 2023-09-27 17:50:55
我正在尝试在我的应用程序中"注入"自定义跟踪方法。
我想使它尽可能优雅,不修改太多现有的代码,并有可能容易地启用/禁用它。
我能想到的一个解决方案是创建一个自定义的Attribute
,我将它附加到我想要跟踪的方法。
基本思想:
public class MethodSnifferAttribute : Attribute
{
private Stopwatch sw = null;
public void BeforeExecution()
{
sw = new Stopwatch();
sw.Start();
}
public void ExecutionEnd()
{
sw.Stop();
LoggerManager.Logger.Log("Execution time: " + sw.ElapsedMilliseconds);
}
}
public class MyClass
{
[MethodSniffer]
public void Function()
{
// do a long task
}
}
是否有任何现有的.NET
属性,当一个方法被调用/结束时提供回调?
属性的方法不会被调用,除非你手动调用它。有一些安全属性是由CLR调用的,但这超出了这个问题的主题,而且无论如何也不会有用。
有一些技术可以在不同级别重写代码。源代码编织,IL编织等
您需要寻找一些方法来修改IL并重写它以计时执行。别担心,你不需要把这些都写下来。人们已经这么做了。例如,您可以使用PostSharp。
这里有一篇文章提供了一个例子
[Serializable]
[DebuggerStepThrough]
[AttributeUsage(AttributeTargets.Method)]
public sealed class LogExecutionTimeAttribute : OnMethodInvocationAspect
{
private static readonly ILog Log = LogManager.GetLogger(typeof(LogExecutionTimeAttribute));
// If no threshold is provided, then just log the execution time as debug
public LogExecutionTimeAttribute() : this (int.MaxValue, true)
{
}
// If a threshold is provided, then just flag warnning when threshold's exceeded
public LogExecutionTimeAttribute(int threshold) : this (threshold, false)
{
}
// Greediest constructor
public LogExecutionTimeAttribute(int threshold, bool logDebug)
{
Threshold = threshold;
LogDebug = logDebug;
}
public int Threshold { get; set; }
public bool LogDebug { get; set; }
// Record time spent executing the method
public override void OnInvocation(MethodInvocationEventArgs eventArgs)
{
var sw = Stopwatch.StartNew();
eventArgs.Proceed();
sw.Stop();
var timeSpent = sw.ElapsedMilliseconds;
if (LogDebug)
{
Log.DebugFormat(
"Method [{0}{1}] took [{2}] milliseconds to execute",
eventArgs.Method.DeclaringType.Name,
eventArgs.Method.Name,
timeSpent);
}
if (timeSpent > Threshold)
{
Log.WarnFormat(
"Method [{0}{1}] was expected to finish within [{2}] milliseconds, but took [{3}] instead!",
eventArgs.Method.DeclaringType.Name,
eventArgs.Method.Name,
Threshold,
timeSpent);
}
}
注意:我已经修改了文章中的示例,使用StopWatch
代替DateTime
,因为DateTime
不准确。
您可以使用PostSharp(作为NuGet包提供)轻松跟踪方法执行时间。自定义方法级属性的代码(从这里取的):
[Serializable]
[DebuggerStepThrough]
[AttributeUsage(AttributeTargets.Method)]
public sealed class LogExecutionTimeAttribute : OnMethodInvocationAspect
{
private static readonly ILog Log = LogManager.GetLogger(typeof(LogExecutionTimeAttribute));
// If no threshold is provided, then just log the execution time as debug
public LogExecutionTimeAttribute() : this (int.MaxValue, true)
{
}
// If a threshold is provided, then just flag warnning when threshold's exceeded
public LogExecutionTimeAttribute(int threshold) : this (threshold, false)
{
}
// Greediest constructor
public LogExecutionTimeAttribute(int threshold, bool logDebug)
{
Threshold = threshold;
LogDebug = logDebug;
}
public int Threshold { get; set; }
public bool LogDebug { get; set; }
// Record time spent executing the method
public override void OnInvocation(MethodInvocationEventArgs eventArgs)
{
var start = DateTime.Now;
eventArgs.Proceed();
var timeSpent = (DateTime.Now - start).TotalMilliseconds;
if (LogDebug)
{
Log.DebugFormat(
"Method [{0}{1}] took [{2}] milliseconds to execute",
eventArgs.Method.DeclaringType.Name,
eventArgs.Method.Name,
timeSpent);
}
if (timeSpent > Threshold)
{
Log.WarnFormat(
"Method [{0}{1}] was expected to finish within [{2}] milliseconds, but took [{3}] instead!",
eventArgs.Method.DeclaringType.Name,
eventArgs.Method.Name,
Threshold,
timeSpent);
}
}