views:

1153

answers:

11

I'm doing some real quick and dirty benchmarking on a single line of C# code using DateTime:

long lStart = DateTime.Now.Ticks;
// do something
long lFinish = DateTime.Now.Ticks;

The problem is in the results:

Start Time [633679466564559902]
Finish Time [633679466564559902]

Start Time [633679466564569917]
Finish Time [633679466564569917]

Start Time [633679466564579932]
Finish Time [633679466564579932]

...and so on.

Given that the start and finish times are identical, Ticks is obviously not granular enough.

So, how can I better measure performance?

+10  A: 

Execute your code repeatedly. The problem seems to be that your code executes a lot faster than the granularity of your measuring instrument. The simplest solution to this is to execute your code many, many times (thousands, maybe millions) and then calculate the average execution time.

Edit: Also, due to the nature of current optimizing compilers (and Virtual Machines such as the CLR and the JVM) it can be very misleading to measure the execution speed of single lines of code, since the measurement can influence the speed quite a lot. A much better approach would be to profile the entire system (or at least larger blocks) and check where the bottlenecks are.

Joachim Sauer
+3  A: 

Use a real profiler such as dotTrace.

Otávio Décio
A: 

Obviously, your code is performant enough. Just kidding :-)

You could run your code repeatedly (e.g 100 or 10000 times) and then divide the resulting duration by that amount.

Sebastian Dietz
+14  A: 

The Stopwatch class, available since .NET 2.0, is the best way to go for this. It is a very high performance counter accurate to fractions of a millisecond. Take a look at the MSDN documentation, which is pretty clear.

EDIT: As previously suggested, it is also advisable to run your code a number of times in order to get a reasonable average time.

Noldorin
+3  A: 

You can also try and use the StopWatch assuming your using .net2.0.

System.Diagnostics.Stopwatch.StartNew();

The stopwatch also has a property they will let you know if the stopwatch is based on a high resolution timer. If its not (and I'm not sure what it takes for it to be based on one. there are some API calls but I figure if the stopwatch doesn't use a high res then the api is probally not there.)

JoshBerke
Property: IsHighResolution
James Skemp
+2  A: 

See the answer to Is DateTime.Now the best way to measure a function’s performance? for an explanation or read my blog post about high performance measurement

The problem is that DateTime has a resolution of about 15ms, it can't be more precise than that. Stopwatch, however, can.

Markus Olsson
+3  A: 

Here's a nice write up at the MSDN on how to Implement a Continuously Updating, High-Resolution Time Provider for Windows

Here's the sample source code for the article (C++).

Patrick Cuff
interesting read. thanks.
scottmarlowe
That was a very useful link.
Kevin Gale
A: 

Sometimes it may be best to look at why you need to time the operation? Is it running slow? Or are you just curious? First rule of optimization is "Don't do it". So, depending on what you're actually measuring, could change the opinion on what tool is best suited for the task.

This is not something that will go into production code, of course. Just something I need to benchmark before implementing the "real" code in production.
scottmarlowe
+3  A: 

Just to add to what others have already said about using Stopwatch and measuring averages.

Make sure you call your method before measuring. Otherwise you will measure the time needed to JIT compile the code as well. That may skew your numbers significantly.

Also, make sure you measure release mode code as optimizations are turned off by default for debug builds. Tuning debug code is sort of pointless imho.

And make sure you're measuring what you actually want to measure. When optimizations kick in, the compiler/JIT compiler may rearrange code or remove it entirely, so you may end up measuring something a little different than intended. At least take a look at the IL to make sure code has not been stripped.

Depending on what you're trying to measure keep in mind, that a real system will stress the runtime differently than a typical test application. Some performance problems are related to e.g. how objects are garbage collected. These problems will typically not show up in a simple test application.

Actually, the best advise is to measure real systems with real data as sandbox tests may turn out to be highly inaccurate.

Brian Rasmussen
+4  A: 

I find these useful

http://accelero.codeplex.com/SourceControl/changeset/view/22633#290971 http://accelero.codeplex.com/SourceControl/changeset/view/22633#290973 http://accelero.codeplex.com/SourceControl/changeset/view/22633#290972

TickTimer is a cut down copy of Stopwatch that starts when constructed and does not support restarting. It will also notify you if the current hardware does not support high resolution timing (Stopwatch swallows this problem)

So this

var tickTimer = new TickTimer();
//call a method that takes some time
DoStuff();
tickTimer.Stop();
Debug.WriteLine("Elapsed HighResElapsedTicks " + tickTimer.HighResElapsedTicks);
Debug.WriteLine("Elapsed DateTimeElapsedTicks " + tickTimer.DateTimeElapsedTicks);
Debug.WriteLine("Elapsed ElapsedMilliseconds " + tickTimer.ElapsedMilliseconds);
Debug.WriteLine("Start Time " + new DateTime(tickTimer.DateTimeUtcStartTicks).ToLocalTime().ToLongTimeString());

will output this

Elapsed HighResElapsedTicks 10022886
Elapsed DateTimeElapsedTicks 41896
Elapsed ElapsedMilliseconds 4.18966178849554
Start Time 11:44:58

DebugTimer is a wrapper for TickTimer that will write the result to Debug. (note: it supports the Disposable pattern)

So this

using (new DebugTimer("DoStuff"))
{
    //call a method that takes some time
    DoStuff();
}

will output this to the debug window

DoStuff: Total 3.6299 ms

IterationDebugTimer is for timing how long it takes to run an operation multiple times and write the result to Debug. It will also perform an initial run that is not included so as to ignore startup time. (note: it supports the Disposable pattern)

So this

int x;
using (var iterationDebugTimer = new IterationDebugTimer("Add", 100000))
{
    iterationDebugTimer.Run(() =>
    {
        x = 1+4;
    });
}

Will output this

Add: Iterations 100000 
Total 1.198540 ms 
Single 0.000012 ms
Simon
+1  A: 

This code project article shows how to use the high performance timer to measure execution speed of your code:

http://www.codeproject.com/KB/cs/highperformancetimercshar.aspx

Here you can find a number of open source C# profilers:

http://csharp-source.net/open-source/profilers

Ashley Davis