How do I exclude methods/classes from profile in ANTs 4.X?

troy.molsberry@entriq.com

Certain calls made by an application under profile are known to block (network calls, etc..). How do I filter these calls out on a namespace/classname level, as in versions of ANTs prior to 4.X?

StephenC

Hi Troy,

I'm afraid that this functionality doesn't exist in Ant 4.

With ANTS 4 the ability to click and drag on a region of the timeline to filter, using the filtering in the All Methods grid (Ctrl + F) and setting marker flags using the API are new ways to examine the data.

Regards,

Stephen

troy.molsberry@entriq.com

Thanks for the response on this. May I suggest that you consider re-adding that feature? Without an exclusion filter, it is impossible to profile web applications that make back-end calls, since the network time overwhelms everything else and shows up first in the "hot" list...however, this masks other potential performance issues that are not network bound.

StephenC

Hi Troy,

the new engine doesn't have the ability to do this due to the way in which we have tried to minimize overhead. Filtering out namespaces/classes is quite expensive when it comes to checking if it should be profiled or not. For this reason everything is profiled although I can see why this might cause some issues for examining your data.

Switching between wall clock and CPU time where it only shows the time spent actually executing should help with the analysis.

I'll raise the issue with the team and we can consider ways in which to help the analysis in future releases.

Regards,

Stephen

rgrenfell

I too would echo Troy here. It's not a requirement to filter during profile capture, but once we've collected the profile data and then go to evaluate the results, it would be useful at that point to exclude specific method calls.

My case is this:
* Watch a socket for incoming data - wait for data to be available using Poll()
* Read the data
* Process the data

The "Poll()" call lists as 76.8333% under "Time with Children(%)" due to the fact that technically we are spending a lot of time waiting for data to come in accross the wire to then be processed. That's time I can't improve performance on. It would be very useful after the session is done to say, Filter Out Poll() and recompute percentages and compute new hotspots.

At that point I'd have a much better picture of where processor time was really being spent in the application.

But it doesn't need to be performed during data collection if that would create a burden on the system performance. It's post processing.

Bart Read

Hi there Troy and rgrenfell,


Sorry for the delay in replying to you. I'd meant to post a couple of days back.

It is actually possible to filter by namespace in ANTS Profiler 4. What you need to do is switch to the methods grid, then click Tools > Find on the main menu, or just hit CTRL+F. Now just type your namespace name into the box. This also works for type and method names. You'll find the list should filter down as you type. You can also use the find functionality in the tree, although in this case it will drill down to the first matching node rather than filtering.

On the topic of blocking time, make sure that on the toolbar below the tree/grid/graph you select "CPU time" rather than "Wall clock time" if you wish to exclude it. CPU time includes only time your application, or a particular thread within it spends executing on the CPU, whereas wall clock time also includes blocking time for I/O, sleeping, and suchlike. Note that methods which block can obviously also use quite a lot of CPU time for actual processing; I've seen SqlCommand.ExecuteReader() do this when executing a query that returns a large result set.

I'd also recommend you only view methods with source in the tree and grid--again, you can change this on the toolbar underneath--and that you hide insignificant methods. Use the checkbox on the right hand side of this toolbar to control whether or not insignificant methods are shown--these are methods which take up less than 1% of the execution time for the selected period.

If interesting processing is only happening on particular threads, I'd recommend you select the thread of interest from the threads drop-down. This means that if your blocking is occurring on another thread it'll be completely excluded from the results.

Finally I'd echo Steve's comments about the timeline: use this as much as possible to only view data for the time period of interest. Just click and drag to select.

If that doesn't help you out please let me know.


Thanks,


Bart

Bart Read

!!STOP PRESS!!

There is a bug in our CPU/wall clock time support where, for some reason, the accept() method is not recognised as a blocking call. This will affect anyone profiling an ASP.NET application and probably the major reason you've been seeing problems. I've raised this as a matter of urgency, and it will be fixed in the 4.3 patch release, which will hopefully be available within the next couple of weeks. Ideally we'll have an early access build available including this fix within the next week.

Apologies for the inconvenience.


Many thanks,


Bart

rgrenfell

Bart,

Thank you for the update. This does sound like it would be a major piece of the problem that we were experiencing. In response to your other points in your last post, the other approaches unfortunately don't work under the situation I'm in at least. The Threads which I'm most interested in profiling are once that perform these blocking operations.

Do you know if the accept() routine is triggered as part of a socket.Poll() call? If so, what I was seeing would indeed be addressed by such a fix. If not, double check that the routines below Poll() are caught.

Also, unfortunately, it sounds like the filter that you have is an inclusion filter, not an exclusion filter. Although being able to say "I only want to profile this namespace" can be critical in certain situations, when trying to determine a global application hotspot that's not what you are looking to do. However, once you've determined that a specific hotspot either 1) can't be reduced, or 2) in our case, the hotspot is artificial, being able to "exclude" that particular data would be critical in recomputing the next level of hotspots.

Lastly, I specifically included routines for which source code was not available in order to be able to see where time was spent that was not necessarily specific to my code. e.g. utilization of a specific OS call significantly degraded performance, and therefore might warrant modification to another approach.

I really appreciate your having taken a serious look at this so that you've determined that there was a problem that could be resolved. I look forward to taking a look at the data again once your people have had a chance to put out a hotfix.

Bart Read

rgrenfell wrote:

Do you know if the accept() routine is triggered as part of a socket.Poll() call? If so, what I was seeing would indeed be addressed by such a fix. If not, double check that the routines below Poll() are caught.

No problem at all. Wish we'd spotted it sooner.

With regard to the above, I'm honestly not sure, although you could use the find function to first find a call to Poll() and then to see if Accept() is called beneath that, which *should* give you the answer. You can also analyse Poll() in detail with the call graph: select the row and then click the little icon that appears to the right of the method name, or choose the option from the right-click menu.

I'll also add an enhancement request for some more sophisticated filtering.

Finally, I'll post here as soon as we have a build available that includes the fix.


Thanks,


Bart

rgrenfell

Bart,

I double checked the session data I had captured, and "Accept()" is no in the recorded call stack from what I can see. What I have recorded is:

System.Net.Sockets.Socket.Poll( int microSeconds, SelectMode mode)
---Transition to unmanaged code...

---

System.Net.UnsafeNclNativeMethods+OSSOCK.select(int ignoredParameter, IntPtr[] readfds, IntPtr[] writefds, IntPtr[] exceptfds, TimeValue timeout)

---

(Thread blocked)

The select() call reads 76.538 Time With Children (%) while the Thread blocked reads <0.001

To the best of my knowledge, the call to select() is simply performing a blocking wait for data to come through, if this is not the case, then maybe this call is MUCH more expensive than I ever understood it to be.

Hopefully this just has a similar problem to the Accept() call you mentioned.

Bart Read

Chaps,


Sorry it's been a bit quiet on this topic lately. I'm expecting an ANTS Profiler 4.3 release to go out, fixing this problem, within the next 24 hours. I'll post an announcement once it's gone live.


Thanks,


Bart

Bart Read

This should be fixed in the 4.3 release. To exclude all the blocking methods just select "CPU time" from the dropdown on the toolbar (it works now!). This should give you some much more relevant results.

Download details are here:

http://www.red-gate.com/messageboard/vi ... php?t=8569

Hope that helps, and sorry it's taken a while to get there.


Thanks,


Bart

rgrenfell

I just wanted to state for any that read this thread in the future that indeed this did resolve the issue I'd been seeing. The data when drilled into now provides accurate information on where the time was spent.

I'd like to thank the team here for having given this issue the attention it received and for following up on it to closure.

Bart Read

Thanks for getting in touch to let us know! Glad we were able to fix the problems you were having!