Ungenaue Leistungsprotokollierung der asynchronen Methode mit StopWatch innerhalb von PostSharp MethodInterceptionAspect

Question

Ich habe einen PostSharp-Aspekt erstellt, der die Ausführungszeit jeder Methode, auf der ich sie verwende, protokollieren soll.

Es scheint jedoch nicht zu funktionieren, wie ich erwartet hatte, mit sw.ElapsedMilliseconds immer zwischen 0 und 3 Millisekunden.

[Serializable] 
[AttributeUsage(AttributeTargets.Method)] 
public sealed class PerfLogAttribute : MethodInterceptionAspect 
{ 
    public override void OnInvoke(MethodInterceptionArgs args) 
    { 
     var sw = new Stopwatch(); 
     sw.Start(); 

     args.Proceed(); 

     sw.Stop(); 

     log.Debug(sw.ElapsedMilliseconds); 
    } 
} 

es wie folgt aus:

[PerfLog] 
public async Task<bool> DoSomethingAsync() { 
    // Adding a delay to test (or call database async) 
    await Task.Delay(5000); 
    return true; 
} 

Answer 1

Wie @ Christian.K sagt, man muss nur die Methode abfangen, die von der Asynchron-Aufgabe instanziiert wird, nicht die Asynchron Aufgabe selbst. Sie verwenden auch Method Interception, das den Job erledigt, aber es ist nicht genau das Muster, das Sie brauchen, da Sie die Methodenausführung nicht wirklich abfangen müssen. Sie müssen nur die Methode umbrechen.

Ihr Fall ist tatsächlich in der Dokumentation unter http://doc.postsharp.net/async-methods#apply-to-state-machine geschrieben.

Der Profilierungs Aspekt: ​​

[Serializable] 
public class ProfilingAttribute : OnMethodBoundaryAspect 
{ 
    public override void OnEntry(MethodExecutionArgs args) 
    { 
     Stopwatch sw = Stopwatch.StartNew(); 
     args.MethodExecutionTag = sw; 
    } 

    public override void OnExit(MethodExecutionArgs args) 
    { 
     Stopwatch sw = (Stopwatch) args.MethodExecutionTag; 
     sw.Stop(); 
     Console.WriteLine("Method {0} executed for {1}ms.", 
          args.Method.Name, sw.ElapsedMilliseconds); 
    } 
} 

Anwendung:

[Profiling(ApplyToStateMachine = true)] 
public async Task TestProfiling() 
{ 
    await Task.Delay(1000); 
    Thread.Sleep(1000); 
} 

Dies wird nicht in Arbeit Postsharp 4.2, wenn Sie es mit Express-Lizenz verwenden, aber es wird in Postsharp 4.3, die zur Verfügung steht zum Download unter https://www.postsharp.net/downloads/postsharp-4.3. Weitere Informationen zum Profiling finden Sie im PostSharp.Samples.Profiling-Beispiel unter http://samples.postsharp.net/.