why in this simple test the speed of method relates to the order of triggering?

Question

I was doing other experiments until this strange behaviour caught my eye.

code is compiled in x64 release.

if key in 1, the 3rd run of List method cost 40% more time than the first 2. output is

List costs 9312
List costs 9289
Array costs 12730
List costs 11950

if key in 2, the 3rd run of Array method cost 30% more time than the first 2. output is

Array costs 8082
Array costs 8086
List costs 11937
Array costs 12698

You can see the pattern, the complete code is attached following (just compile and run): {the code presented is minimal to run the test. The actually code used to get reliable result is more complicated, I wrapped the method and tested it 100+ times after proper warmed up}

class ListArrayLoop
{
    readonly int[] myArray;
    readonly List<int> myList;
    readonly int totalSessions;

    public ListArrayLoop(int loopRange, int totalSessions)
    {
        myArray = new int[loopRange];
        for (int i = 0; i < myArray.Length; i++)
        {
            myArray[i] = i;
        }
        myList = myArray.ToList();
        this.totalSessions = totalSessions;
    }
    public  void ArraySum()
    {
        var pool = myArray;
        long sum = 0;
        for (int j = 0; j < totalSessions; j++)
        {
            sum += pool.Sum();
        }
    }
    public void ListSum()
    {
        var pool = myList;
        long sum = 0;
        for (int j = 0; j < totalSessions; j++)
        {
            sum += pool.Sum();
        }
    }

}
class Program
{
    static void Main(string[] args)
    {
        Stopwatch sw = new Stopwatch();
        ListArrayLoop test = new ListArrayLoop(10000, 100000);

        string input = Console.ReadLine();


        if (input == "1")
        {
            sw.Start();
            test.ListSum();
            sw.Stop();
            Console.WriteLine("List costs {0}",sw.ElapsedMilliseconds);
            sw.Reset();
            sw.Start();
            test.ListSum();
            sw.Stop();
            Console.WriteLine("List costs {0}", sw.ElapsedMilliseconds);
            sw.Reset();
            sw.Start();
            test.ArraySum();
            sw.Stop();
            Console.WriteLine("Array costs {0}", sw.ElapsedMilliseconds);
            sw.Reset();
            sw.Start();
            test.ListSum();
            sw.Stop();
            Console.WriteLine("List costs {0}", sw.ElapsedMilliseconds);
        }
        else
        {
            sw.Start();
            test.ArraySum();
            sw.Stop();
            Console.WriteLine("Array costs {0}", sw.ElapsedMilliseconds);
            sw.Reset();
            sw.Start();
            test.ArraySum();
            sw.Stop();
            Console.WriteLine("Array costs {0}", sw.ElapsedMilliseconds);
            sw.Reset();
            sw.Start();
            test.ListSum();
            sw.Stop();
            Console.WriteLine("List costs {0}", sw.ElapsedMilliseconds);
            sw.Reset();
            sw.Start();
            test.ArraySum();
            sw.Stop();
            Console.WriteLine("Array costs {0}", sw.ElapsedMilliseconds);
        }

        Console.ReadKey();
    }
}

Answer 1

Contrived problems give you contrived answers.

Optimization should be done after code is written and not before. Write your solution the way that is easiest to understand and maintain. Then if the program is not fast enough for your use case, then you use a profiling tool and go back and see where the actual bottleneck is, not where you "think" it is.

Most optimizations people try to do in your situation is spending 6 hours to do something that will decrease the run time by 1 second. Most small programs will not be run enough times to offset the cost you spent trying to "optimize" it.

---

That being said this is a strange edge case. I modified it a bit and am running it though a profiler but I need to downgrade my VS2010 install so I can get .NET framework source stepping back.

---

I ran though the profiler using the larger example, I can find no good reason why it would take longer.

Answer 2

Your issue is your test. When you are benchmarking code there are a couple of guiding principals you should always follow:

1. Processor Affinity: Use only a single processor, usually not #1.
2. Warmup: Always perform the test a small number of times up front.
3. Duration: Make sure your test duration is at least 500ms.
4. Average: Average together multiple runs to remove anomalies.
5. Cleanup: Force the GC to collect allocated objects between tests.
6. Cooldown: Allow the process to sleep for a short-period of time.

So using these guidelines and rewriting your tests I get the following results:

Run 1

Enter test number (1|2): 1
ListSum averages 776
ListSum averages 753
ArraySum averages 1102
ListSum averages 753
Press any key to continue . . .

Run 2

Enter test number (1|2): 2
ArraySum averages 1155
ArraySum averages 1102
ListSum averages 753
ArraySum averages 1067
Press any key to continue . . .

So here is the final test code used:

static void Main(string[] args)
{
    //We just need a single-thread for this test.
    Process.GetCurrentProcess().ProcessorAffinity = new IntPtr(2);
    System.Threading.Thread.BeginThreadAffinity();

    Console.Write("Enter test number (1|2): ");
    string input = Console.ReadLine();

    //perform the action just a few times to jit the code.
    ListArrayLoop warmup = new ListArrayLoop(10, 10);
    Console.WriteLine("Performing warmup...");
    Test(warmup.ListSum);
    Test(warmup.ArraySum);
    Console.WriteLine("Warmup complete...");
    Console.WriteLine();

    ListArrayLoop test = new ListArrayLoop(10000, 10000);

    if (input == "1")
    {
        Test(test.ListSum);
        Test(test.ListSum);
        Test(test.ArraySum);
        Test(test.ListSum);
    }
    else
    {
        Test(test.ArraySum);
        Test(test.ArraySum);
        Test(test.ListSum);
        Test(test.ArraySum);
    }
}

private static void Test(Action test)
{
    long totalElapsed = 0;
    for (int counter = 10; counter > 0; counter--)
    {
        try
        {
            var sw = Stopwatch.StartNew();
            test();
            totalElapsed += sw.ElapsedMilliseconds;
        }
        finally { }

        GC.Collect(0, GCCollectionMode.Forced);
        GC.WaitForPendingFinalizers();
        //cooldown
        for (int i = 0; i < 100; i++)
            System.Threading.Thread.Sleep(0);
    }
    Console.WriteLine("{0} averages {1}", test.Method.Name, totalElapsed / 10);
}

Note: Some people may debate about the usefulness of the cool-down; However, everyone agrees that even if it's not helpful, it is not harmful. I find that on some tests it can yield a more reliable result; however, in the example above I doubt it makes any difference.