Czas wykonywania metod śledzenia

Question

Próbuję "wstrzyknąć" niestandardowe metody śledzenia w mojej aplikacji.

Chcę, aby było tak elegancko, jak to możliwe, bez modyfikowania dużej części istniejącego kodu, i mieć możliwość łatwego włączania/wyłączania go.

Jednym z rozwiązań, które mógłbym wymyślić, byłoby stworzenie niestandardowego Attribute, który dołączę do metod, które chcę śledzić.

podstawowa idea:

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 
    } 
} 

Czy są jakieś istniejące .NET atrybuty, które zapewnia wywołania zwrotne, gdy metoda nazywa/skończyło?

Answer 1

Metoda atrybutu nie jest wywoływana, chyba że wywołasz ją ręcznie. Istnieją atrybuty bezpieczeństwa, które są wywoływane przez CLR, ale to jest poza tematem tego pytania i i tak i tak nie będzie użyteczne.

Istnieją techniki przepisywania kodu na innym poziomie. Tkanie kodu źródłowego, tkanie IL itd.

Musisz spojrzeć na jakiś sposób, aby zmodyfikować IL i przepisać go na czas wykonania. Nie martw się, nie musisz tego pisać. Ludzie już to zrobili. Na przykład możesz użyć PostSharp.

Oto article który stanowi przykład

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

Uwaga: Mam zmodyfikowany przykład z artykułu używać StopWatch zamiast DateTimeDateTime ponieważ nie jest dokładna.

Answer 2

Możesz łatwo prześledzić czas wykonania metody za pomocą PostSharp (dostępny jako pakiet NuGet). Kod niestandardowego atrybutu poziomu metody, który robi właśnie to (wzięty z 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); 
    } 
    }