Missing Method Timing

Code profiling for .NET Developers

Missing Method Timing

Postby joefeser » Wed Aug 05, 2009 3:00 pm

I have a project that is missing calls to specific methods in my classes.

I know the pdb's exist because I am getting visit counts from NCover.

This is a WPF application that raises an event back to a controller.

The controller then calls a property on my object, which then calls many other methods that perform sorts with ObservableCollection<T>.

Other properties in the same source file have visit counts so I know the pdb's are correct.

The numbers also don't add up to 100%, v5.1 is stating 89% of my time is spent in files without source code.

This worked in v4.

Thanks

Joe
joefeser
 
Posts: 11
Joined: Mon Nov 03, 2008 3:56 pm
Location: Greenville, SC

Postby StephenC » Wed Aug 05, 2009 4:58 pm

There could be a number of reasons -

- The most likely is that 'Hide insignificant methods' is on and they are simply being hidden (see checkbox on main UI)
- Have you switched from viewing CPU time to Wall Clock time perhaps as this will show the time data differently.
- the methods have been simplified (see Tools > Options); although unchecking this could have a serious impact on performance.

Stephen
StephenC
 
Posts: 306
Joined: Mon Oct 15, 2007 9:18 am
Location: Cambridge

Postby joefeser » Wed Aug 05, 2009 6:20 pm

Stephen,

I always uncheck that checkbox for hide insignificant methods.
I did not change to wall clock because this would not make methods show timing when there is no timing to show.
I did change the checkbox for simplify stack trace to unchecked and I finally obtained timing data.

I rechecked the checkbox and my timing went away. Does that mean I need to run without that option?

I have had these issues in the past but never knew what caused it.

Thanks

Joe Feser
joefeser
 
Posts: 11
Joined: Mon Nov 03, 2008 3:56 pm
Location: Greenville, SC

Postby StephenC » Wed Aug 05, 2009 6:34 pm

Hi Joe,

I can't remember the exact numbers but essentially what's happening is that if a method that is more than a certain depth in the stacktrace and appears more than in a 1,000 different stacks it's simplified because of the impact this has on profiling and memory. Anything called by that method in that stack is not recorded as part of the attempt to minimize memory usage during profiling.

One potential work-around is that we actually have a new profiling mode in V5.x which is sort of like a turbo mode. In the setup dialog if you choose the Line-Level & method level timings (only methods with source) mode you might get around it this way.

If you aren't noticing a massive impact on the profiling with the option turned off i probably wouldn't worry about it.

Stephen
StephenC
 
Posts: 306
Joined: Mon Oct 15, 2007 9:18 am
Location: Cambridge

Postby joefeser » Wed Aug 05, 2009 6:41 pm

Stephen,

Everything in that part of the system is an interface and all of the classes inherit from that interface.

The interface has a Children property used to bind to the treeview control and when the sort type is changed in the dropdown, an event is raised and a method on the interface and all the classes is called (ViewSortStyleChanged). It is then recursively called on all the children in the tree.

Does that help?

Joe Feser
joefeser
 
Posts: 11
Joined: Mon Nov 03, 2008 3:56 pm
Location: Greenville, SC

Postby StephenC » Wed Aug 05, 2009 6:50 pm

Hi Joe,

I'm not sure I understand - does it help in which way? It could be that if it's a generic method and happening recursively further down the stack that could be the reason.

I guess I should ask if the info I provided has helped you? :D

Are you noticing any real profiling hit with the setting on/off? Or has that answered all your questions?

Cheers,

Stephen :)
StephenC
 
Posts: 306
Joined: Mon Oct 15, 2007 9:18 am
Location: Cambridge

Postby joefeser » Wed Aug 05, 2009 6:53 pm

I have to run the app in both modes to see if there is impact.

Not having data is more of an impact than it running slow.

Joe Feser
joefeser
 
Posts: 11
Joined: Mon Nov 03, 2008 3:56 pm
Location: Greenville, SC

Postby Chris.Allen » Fri Aug 14, 2009 11:30 am

I have seen this effect too sometimes- usualy selecting "line level timings" helps here.
Chris.Allen
 
Posts: 594
Joined: Thu Mar 12, 2009 4:17 pm


Return to ANTS Performance Profiler 5

Who is online

Users browsing this forum: No registered users and 0 guests