Can someone help me explain these timings?

Question

This code accepts timings for n calls of two methods that do nothing ( MyMethod1, MyMethod2) but are decorated with different attributes ( MyAspect1, MyAspect2).

MyAspect1contains no logic other than MyMethod1run ( Proceed()).

MyAspect2does the same for MyMethod2, but also creates a task that provides an anonymous delegate to run, which should equal almost zero work to the CPU (line trimming).

I would expect the timings for iterations over MyMethod1and to MyMethod2be about the same.

Actual timings below; they seem to be opposite intuitive, while MyMethod1starting much slower (in accordance with what I expect), and, ultimately, with its loss of race significantly from 10,000 iterations ahead. Can someone help me explain this?

Test results (average of 3 runs per iteration value):

No. of iterations  |          Ticks 
                      Method 1  |  Method 2
       5                 25282        6999
       100               22128        8176 
       1000              22982        23720
       10000             25995        265621
       1000000           994359       25125076

---------------------------------------------------

public class TestClass2
{ 
    public void MyTest()
    {
        const int iterations = 100;
        var stopWatch = new Stopwatch();
        stopWatch.Start();
        for (int x = 0; x < iterations; x++)
        {
            MyMethod1();
        }
        stopWatch.Stop();
        Console.WriteLine("Method1 calls duration: " + stopWatch.ElapsedTicks);            
        stopWatch.Reset();
        stopWatch.Start();
        for (int x = 0; x < iterations; x++)
        {
             MyMethod2();
        }
        stopWatch.Stop();
        Console.WriteLine("Method2 calls duration: " + stopWatch.ElapsedTicks);                        
    }

    [MyAspect1]
    private void MyMethod1() {}
    [MyAspect2]
    private void MyMethod2() {}
}

[Serializable]
public class MyAspect1 : AsynchronousMetricsAspect
{
    public override void OnInvoke(MethodInterceptionArgs args)
    {
        args.Proceed();
    }
}

//NOTE: this type is the same as MyAspect1, but adds a Task creation
[Serializable]
public class MyAspect2 : AsynchronousMetricsAspect
{
    public override void OnInvoke(MethodInterceptionArgs args)
    {
        args.Proceed();
        Task.Factory.StartNew(() => "bleh".Trim()); //invoke the logging method asynchronously           
    }
}

Additional information: Test is called from the ReSharper NUnit VS plugin, and the attributes are PostSharp MethodInterceptionAspects.

Edit: Updated figures for when the methods are pre-invoked before the tests, to ensure any JIT compilation has occurred. 

Test results (ballpark):

No. of iterations  |          Ticks 
                      Method 1  |  Method 2
       5                 22          437
       100               37          2204 
       1000              192         24476
       10000             7931        286403
       100000            115451      2862439
       1000000           695950      29049021
       10000000          8347867     275777590

Answer 1

Well, for starters, I'll try to determine whether this is generally related to PostSharp or not. I would try to call the same methods without any AOP.

Here are my suspicions:

• 25 000 ( , ) - JIT PostSharp. , . , . , , , , ..... , 100 2 , 5 .

• , , . , , , ... . , . , PFX , , ( , ) , . .

• , , , . PostSharp, , , .

• 2, . 6000 + 23 * N , 6115, 8300, 29000, 236000 23006000 - .

• , ​​ . , , GC - 2 , .

, - , :)