Неточное ведение журнала асинхронного метода с использованием StopWatch внутри PostSharp MethodInterceptionAspect

Question

Я создал аспект PostSharp, который должен регистрировать время выполнения любого метода, в котором я его использую.

Однако, похоже, что он работает не так, как я ожидал, с sw.ElapsedMilliseconds всегда между 0 и 3 миллисекундами.

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

Используя это следующим образом:

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

Answer 1

Как @ Christian.K говорит, вы перехватываете только метод, который инстанцирование асинхронной задачи, а не асинхронная сама задача. Вы также используете метод перехвата, который выполняет задание, но это не совсем тот шаблон, который вам нужен, поскольку вам действительно не нужно перехватывать выполнение метода. Вам просто нужно обернуть метод.

Ваше дело действительно написано в документации по адресу http://doc.postsharp.net/async-methods#apply-to-state-machine.

Профилирующая аспект:

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

Применение:

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

Это не будет работать в PostSharp 4,2, если вы используете его с экспресс-лицензии, но это будет в PostSharp 4.3, который доступен для загрузки по адресу https://www.postsharp.net/downloads/postsharp-4.3.

Подробнее о профилировании можно найти в примере PostSharp.Samples.Profiling по адресу http://samples.postsharp.net/.