When doing some performance testing, I used to use the DateTime and TimeSpan classes to retrieve the time elapsed - similar to this example:

public static void PerformLongOperation()

{    

    DateTime start = DateTime.Now;    

    //Long running operation    

    Thread.Sleep(1500);    

    DateTime end = DateTime.Now;    

    TimeSpan elapsedTime = end - start;    

    Console.WriteLine("Operation took {0:F2} seconds to complete.", elapsedTime.TotalSeconds);

}

Okay, so its not THAT bad is it really. So lets just check what happens when the measurement is very minute:

public static void PerformLongOperation()

{    

    for (int iteration = 100; iteration > 0; iteration-=5)    

    {        

        DateTime start = DateTime.Now;        

        //Long running operation        

        Thread.Sleep(iteration);        

        DateTime end = DateTime.Now;        

        Console.WriteLine("Iteration {0}: Time Taken = {1:F1}ms",iteration,(end-start).TotalMilliseconds);         

    }

}

Before running this, I would have guessed that the output would be something like:

.....

Here is the actual output:

Iteration 100: Time Taken = 93.6ms
Iteration 95: Time Taken = 93.6ms
Iteration 90: Time Taken = 93.6ms
Iteration 85: Time Taken = 93.6ms
Iteration 80: Time Taken = 78.0ms
Iteration 75: Time Taken = 62.4ms
Iteration 70: Time Taken = 78.0ms
Iteration 65: Time Taken = 62.4ms
Iteration 60: Time Taken = 62.4ms
Iteration 55: Time Taken = 62.4ms
Iteration 50: Time Taken = 46.8ms
Iteration 45: Time Taken = 46.8ms
Iteration 40: Time Taken = 31.2ms
Iteration 35: Time Taken = 46.8ms
Iteration 30: Time Taken = 31.2ms
Iteration 25: Time Taken = 15.6ms
Iteration 20: Time Taken = 15.6ms
Iteration 15: Time Taken = 15.6ms
Iteration 10: Time Taken = 15.6ms
Iteration 5: Time Taken = 15.6ms

Odd? Some iterations take longer even though there are less time to wait! Whats going on?

The reason is that the DateTime class isn't as accurate as there is a potential to be. But that doesn't mean that the DateTime should be updated to be incredibly accurate, it just means we have to look somewhere else for this functionality.

There isn't really much call to get the current date/time exact to nanoseconds, but what there is a call for is the time elapsed being accurate. The reason being is that when measuring some elapsed time event (for performance testing loops or measuring the time between events), the DateTime is just too heavyweight for the job, plus modern computers have a "high-resolution" counter in the processor.

By accident, I brushed passed something called the System.Diagnostics.StopWatch class. Its a high-resolution timer, that is accurate to 0.000000001 seconds (10^-9 seconds). Then all thats needed is to start/stop it.

public static void PerformLongOperation2()

{    

    Stopwatch stopWatch = new Stopwatch();    

    for (int i = 100; i > 0; i-=5)    

    {        

        stopWatch.Start();        

        //Long running operation        

        Thread.Sleep(i);        

        stopWatch.Stop();        

        Console.WriteLine("Iteration {0}: Time Taken = {1:F1}ms",iteration,stopWatch.Elapsed.TotalMilliseconds);         

        stopWatch.Reset();    

    }

}

This outputs to:

Iteration 100: Time Taken = 100.3ms
Iteration 95: Time Taken = 95.7ms
Iteration 90: Time Taken = 90.8ms
Iteration 85: Time Taken = 85.9ms
Iteration 80: Time Taken = 79.9ms
Iteration 75: Time Taken = 75.2ms
Iteration 70: Time Taken = 70.3ms
Iteration 65: Time Taken = 65.4ms
Iteration 60: Time Taken = 60.5ms
Iteration 55: Time Taken = 55.6ms
Iteration 50: Time Taken = 50.6ms
Iteration 45: Time Taken = 45.9ms
Iteration 40: Time Taken = 40.0ms
Iteration 35: Time Taken = 35.3ms
Iteration 30: Time Taken = 30.1ms
Iteration 25: Time Taken = 25.3ms
Iteration 20: Time Taken = 20.5ms
Iteration 15: Time Taken = 15.6ms
Iteration 10: Time Taken = 10.7ms
Iteration 5: Time Taken = 5.8ms

So, why is it still incorrect? The reason is that because other processes are running, the Thread.Sleep() method call cannot be absolutely perfect with timing, due to the time slicing. But it goes to show the accuracy of the counter.

This classes uses the Windows API to make this method call, so you don't need to enquire the API directly any more.