why my test performance class gives me inconsistent results even after proper warm-up?

Question

i made a class which helps me measure time for any methods in Ticks.

Basically, it runs testing method 100x, and force GC, then it records time taken for another 100x method runs. x64 release ctrl+f5 VS2012/VS2010

the results are following:

2,914    2,909    2,913    2,909    2,908
2,907    2,909    2,998    2,976    2,855
2,446    2,415    2,435    2,401    2,402
2,402    2,399    2,401    2,401    2,400
2,399    2,400    2,404    2,402    2,401
2,399    2,400    2,402    2,404    2,403
2,401    2,403    2,401    2,400    2,399
2,414    2,405    2,401    2,407    2,399
2,401    2,402    2,401    2,404    2,401
2,404    2,405    2,368    1,577    1,579
1,626    1,578    1,576    1,578    1,577
1,577    1,576    1,578    1,576    1,578
1,577    1,578    1,576    1,578    1,577
1,579    1,585    1,576    1,579    1,577
1,579    1,578    1,579    1,577    1,578
1,577    1,578    1,576    1,578    1,577
1,578    1,599    1,579    1,578    1,582
1,576    1,578    1,576    1,579    1,577
1,578    1,577    1,591    1,577    1,578
1,578    1,576    1,578    1,576    1,578

As you can see there are 3 phases, first is ~2,900, second is ~2,400, then ~1,550

What might be the reason to cause it?

Update

I am now strongly suspecting that as I used intel I5, it is the cpu turbo boost that interferes with the results. However, even if i disabled turbo boost it's still not stable. Meanwhile the Core 2 Quad produces stable benchmark

the test performance class code follows:

    public static void RunTests(Func<long> myTest)
    {
        const int numTrials = 100;
        Stopwatch sw = new Stopwatch();
        double[] sample = new double[numTrials];

        Console.WriteLine("Checksum is {0:N0}", myTest());

        sw.Start();
        myTest();
        sw.Stop();

        Console.WriteLine("Estimated time per test is {0:N0} ticks\n", sw.ElapsedTicks);


        for (int i = 0; i < numTrials; i++)
        {
            myTest();
        }
        GC.Collect();
        string testName = myTest.Method.Name;
        Console.WriteLine("----> Starting benchmark {0}\n", myTest.Method.Name);
        for (int i = 0; i < numTrials; i++)
        {
            sw.Restart();
            myTest();
            sw.Stop();
            sample[i] = sw.ElapsedTicks;
        }
        double testResult = DataSetAnalysis.Report(sample);

        for (int j = 0; j < numTrials; j = j + 5)
            Console.WriteLine("{0,8:N0} {1,8:N0} {2,8:N0} {3,8:N0} {4,8:N0}", sample[j], sample[j + 1], sample[j + 2], sample[j + 3], sample[j + 4]);
        Console.WriteLine("\n----> End of benchmark");
    }

Answer 1

It seems to be the speedstep ? The speed starts at 1/2x and when it is fully warmed up it runs full speed.

When I run TMonitor at the same time the benchmark becomes stable and doesn't even need warm up

Answer 2

I think each tick is around 1000 clock cycles, so 1000-2000 ticks is not that tiny. Although it's still better to do:

myTest();
myTest();
myTest();
myTest();
myTest();

myTest();
myTest();
myTest();
myTest();
myTest();

That's calling the same method 10 times without using the loop to avoid looping cost; then divide result by 10.

As for the difference, it's possible if your myTest code does any memory allocation, uses any sort of caching, or uses weak reference. I recently found out that calling .Net reflection API can have strange perf results on low-end machine.

Answer 3

If I read your post right, it only executes a method 100 times, that is an extremely tiny sample pool. When doing off the cuff stopwatching I've tended to run millions of the operation depending on how complex the operation is.

For your general case wrapper you might want to have another thread start the stopwatch, send an eventwaithandle signal to the performance piece to run, and have your stopwatch thread checking every 200ms until it hits 2 minutes, send a signal and have your performance piece checking that signal every iteration to stop.

See how many iterations completed in those 2 minutes.

Try this, run it 10 times and see what the % variance is in counts, the total number may be different by many thousands but the total percent difference should be much smaller.

Just off the top of my head..

public class PerfTester
{
    private EventWaitHandle _running = new EventWaitHandle(false, EventResetMode.ManualReset, "awesome_Woo");
    private int _count;

    public Run(Action actionToRun)
    {
        ParameterizedThreadStart runner = new ParameterizedThreadStart((state) =>
        {
            Action action = state as Action;
            EventWaitHandle run = = new EventWaitHandle(false, EventResetMode.ManualReset, "awesome_Woo", false);
            while(true)
            {
                run.WaitOne();
                action();
                _count++;
            }
        });

        Thread runnerThread = new Thread(runner);
        runnerThread.Start(actionToRun);

        StopWatch timer = new StopWatch();
        timer.Start();
        _running.Set();
        while(timer.ElapsedSeconds < 120) Thread.Sleep(500);
        _running.Reset();

        Console.WriteLine(_count);
    }
}

Or maybe just use a boolean instead of a wait handle, I've just gotten in the habit of using them for communication across boundaries..