How can we help you today? How can we help you today?

Inaccurate timings

I posted a thread in the v3 forum about innacurate timings we had in our application. I stripped it down to a small sample posted here:

http://www.red-gate.com/MessageBoard/vi ... php?t=7117

The code takes around 2.2 seconds to run (Debug build, no debugger attached). Under the profiler it took a lot longer but the v3 profiler said it took 18.8 seconds in the reports.

I was asked to try again in v4, and the results are much better, but still quite a way off. The report in v4 shows 11.5 seconds.

Here's the code I'm running:
static void Main( string[] args )
{
	List<KeyValuePair<string, int>> items = new List<KeyValuePair<string, int>>();
	Dictionary<KeyValuePair<string, int>, bool> dict = new Dictionary<KeyValuePair<string, int>, bool>();

	for ( int i = 0; i < 1000; i++ )
		items.Add( new KeyValuePair<string, int>( "MyTest", i ) );

	DateTime start = DateTime.Now;

	foreach ( var item in items )
		if ( !dict.ContainsKey( item ) )
			dict.Add( item, true );

	DateTime end = DateTime.Now;
	Console.WriteLine( end - start );
}
dannytuppeny
0

Comments

3 comments

Sort by
  • dannytuppeny
    I don't understand the difference between "Wall Clock" and "CPU", but both seem to show the same numbers.
    dannytuppeny
    0
  • StephenC
    Wall Clock is total time, CPU is time actually spent executing (excludes time spent sleeping, waiting).

    They may show the same time if the methods aren't affected by wait times etc... If it's a simple piece of code for example then this is reasonably likely depending on what it's doing of course.
    StephenC
    0
  • Andrew H
    We have changed the code in ANTS 4 that deals with working out the amount of overhead the profiler incurs: however in all of the builds we've released so far this feature is turned off, so the reported times always include the time added by the profiling code.

    This is probably something that we'll add as an option so you can switch between the times with and without compensation applied - it's a post-processing step in ANTS 4, so we can calculate the results after the fact.

    The current implementation does have a few limitations: in particular it only covers overhead added by the method-level profiling and not the line-level code. I'm going to look at improving this but there are some technical issues that make this a hard problem - the two big ones being that the instrumentation alters the behaviour of the JIT (and we can't compensate for that), and that the line-level timing code is now so short that the overhead it applies is highly dependent on the surrounding code, a result of modern processor architectures.

    There are a couple of other effects the profiler will have that we probably won't be able to compensate for: in particular because more code is being executed and more memory is being accessed, more cache misses will occur which will cause the program to run slower. I don't think we've seen anything in our tests so far for which this is hugely significant, though.
    Andrew H
    0

Add comment

Please sign in to leave a comment.