【问题标题】:Tracing methods execution time跟踪方法执行时间
【发布时间】:2015-08-10 13:27:35
【问题描述】:

我正在尝试在我的应用程序中“注入”自定义跟踪方法。

我想让它尽可能优雅,而不需要修改大部分现有代码,并且可以轻松启用/禁用它。

我能想到的一个解决方案是创建一个自定义 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 属性在调用/结束方法时提供回调?

【问题讨论】:

  • 我想我什么都不知道。
  • 您正在寻找的是面向方面的编程领域。有一个名为 PostSharp 的库,它完全符合您的要求。如果您正在寻找开源解决方案,请参阅 this 帖子。
  • Postsharp 会让您轻松搞定。您甚至可以通过 AssemblyInfo.cs 将方面应用于整个命名空间。查看:postsharp.net
  • ASP.NET 支持过滤器:System.Web.Http.Filters.ActionFilterAttribute。感兴趣的:OnActionExecuting 和 OnActionExecuted。
  • PostSharp 是免费的还是许可的?

标签: c# asp.net .net trace .net-trace


【解决方案1】:

您可以使用 PostSharp(作为 NuGet 包提供)轻松跟踪方法执行时间。执行此操作的自定义方法级属性的代码(取自here):

  [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);
    }
  }

【讨论】:

  • 这在 .net Core 中有效吗?你能举个例子吗? - 是否只是将其添加到方法的顶部:[LogExecutionTimeAttribute]
【解决方案2】:

除非您手动调用,否则不会调用属性的方法。 CLR 调用了一些安全属性,但这超出了这个问题的主题,无论如何它都不会有用。

有一些技术可以在不同级别重写您的代码。源码编织、IL编织等

您需要寻找一些方法来修改 IL 并重写它以计时执行。别担心,你不必写所有这些。人们已经这样做了。例如,您可以使用PostSharp。

这是一个article,它提供了一个示例

[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 不准确。

【讨论】:

  • 用Stopwatch代替DateTime做得很好
  • 由于不再支持OnMethodInvactionAspect,您可以使用OnMethodBoundaryAspect,有关如何使用它来跟踪方法的执行时间的示例,请参见docs
猜你喜欢
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
相关资源
最近更新 更多