Probing Old Faithful’s innards
Red Gate’s ANTS performance profiler helps you track down bottlenecks in your code. I’ve been using it in a very large and ‘mature’ codebase (let’s call it ‘Old Faithful’ because it’s old and slow, but it gets there eventually). Old Faithful is responsible for running a real, large e-commerce operation, including warehouses, accounts, order fulfilment and several front end web sites. We thought this would be an ideal opportunity to put the performance profiler through its paces.
I won’t be going over everything that Performance Profiler does or the many different ways to profile apps, if you want to explore more afterwards you can always get a trial download from Red Gate.
Old Faithful is a mix of many different bits of .NET, right now we have WCF, WinForms, WebForms, NT services and some funky Ajax stuff backed by WCF. There are two data layers (ADO and Entity Framework both connect to SQL) and it’s even got XSD datasets (shudder), which I’ve been surgically replacing with plain old CLR objects. But hey, at least there’s no X86 assembly in there or even worse, C++. This makes the codebase a prime candidate for profiling.
On with the gloves
The most visible parts of the system are the web sites which are database driven, so I started profiling with those in the hope of finding the low hanging fruit. A few words of caution if you intend to profile web apps under Windows Vista, you’ll need to launch Visual Studio using admin privileges by right clicking and selecting ‘Run as administrator’. If you don’t, you’ll not be able to attach to the process being debugged as it will die just after launching.
To start profiling, load up your solution and select the ‘ANTS’ Visual Studio menu (much to my disappointment no insects appeared) and then select the ‘Launch ANTS Performance Profiler’ option. Obviously the app you want to profile has to be set as the startup project for the solution. You can also choose to attach to a running process.
Generally when debugging and profiling I remove all of the cruft from the solution, in Old Faithful’s case this meant creating another solution just for a single web site, supporting logic and database access layer. You can load everything if you want but my master solution is nearly 30 projects and Visual Studio 2010 strains under the weight.
You should see something like the following pic; Note the (1) marker, I’m using the professional edition here which has SQL and I/O monitoring. If that’s not important to you then you can get away with the standard edition. If you never change anything in this screen and are happy with the defaults you can skip it next time by choosing ‘Profile Performance’ from the ANTS menu.
So click ‘Start Profiling’ and your web app should pop up in Internet Explorer. In version 6 of Performance Profiler the browser is defaulted to IE but you can change browsers once the profiling session starts.
If you are looking for specific performance issues (for example, a particular page taking aeons to load) then you’ll want to start using the site as your end users would. I haven’t tried to attach to a live system suffering from performance problems yet; although this is possible you probably won’t be able to get near it as it will normally be protected by the ‘friendly’ IT team.
Getting access to production systems for troubleshooting is always an issue, even if you can get hold of a Virtual Machine instance you’ll then be changing the hardware it runs on and this may hide or exacerbate the issue. Normally a copy of the user data on my dev box is enough to show the problem. As you’ll see from the results below though, performance is relative and ANTS will still show the areas that need work, so although your machine may be faster or different to the live system, the spikes in the graph should still be obvious in relation to the other minor code around them.
Acting like a normal user, tend to click everything in sight and not bother about waiting for pages to load and after a while I have a fairly usable amount of data. Don’t worry if you’ve got lots of fast code and only a few instances of slow methods, you’ll be able to focus on specific time ranges in the results.
Closing the browser forces the session to stop capturing (although you can leave it running and just alt-tab back to the profiler if you want to fiddle some more later).
Viewing the output of the profiler is not hard at all, it takes about a minute or two at most to find your way round the user interface.
To begin exploring the results look at the ‘Time with Children’ column which will have red graded backgrounds for the rows / methods that are consuming a lot of CPU. Each method in the result view is indented below its parent method and trivial methods (property setters etc.) are filtered out so as to avoid too much clutter. You can turn trivial methods on by unticking the box at the top although I never found the need to, ANTS does a good job of hiding the stuff I don’t need to see.
Clicking on a row highlights it and it will also show a green rectangle in the timeline above (the chart that looks like a heart monitor) for every time this method is called. You also get the source code in the bottom pane for the selected method, along with the hit count, average time and line number; which makes it pretty easy to figure out where you are.
The hit count is useful here as you can see which methods are repeatedly called and could benefit from refactoring. When you have a method selected you also get the option to generate a call graph for it by clicking on the node icon in the method row. This will show you the various callers of this method and subsequent methods too. You can export the call graph to PDF, PNG or print it out if you want to go over it with another dev (or blame them).
In my results ANTS immediately picked out the heavy CPU users and presented them in a tree view. If any methods stick out as really bad CPU abusers they’ll get marked with a ‘HOT’ icon making them even easier to spot.
If you don’t like tree views then you can go for a nice standard square grid which shows the same information without the indenting of the child method calls. Click on the matrix icon in the top left to go to this type of view.
As a general rule, if the ‘Time with Children’ column has lots of red in it, you’ll be spending less time with your children as you’ve got code to refactor! I can see from the tree view that my database layer needs some work as all the slow methods funnel down to database operations.
Focussing on specific methods
Another point is that when your method is selected in the tree view as well as seeing the source code below, you’ll see green boxes on the event timeline above which shows the other times that this particular method was called.
Selecting a different region of the timeline will focus on just that data with the tree view now showing the dominant time wasting code for just that time span.
Tracking file SQL performance
If you want to track down SQL issues further then ANTS also goes into detail on this but you will need the professional edition and a copy of the database running via SQL Express on your local system. Putting SQL Express on my dev box is a bit of a problem for me as I find it tends to grind the disk too much so I’ve not been able to look into the SQL profiling results.
If you do have SQL Express installed you can get at the profiling results by choosing the ‘SQL Server’ item on the ‘Performance Analysis’ drop down at the top left.
Tracking file I/O
Changing the performance analysis to file I/O shows which files your .Net code has been accessing, in a grid format including the binaries when it is first loaded. Selecting any of the files is much the same as the source code tree view; you can see each instance of file access in the event timeline. Re-reading of configuration files seems to feature a lot although the disk I/O is low, I might look at this in future when refactoring.
I was surprised to see how many exceptions the code was throwing; the event timeline at the top of the screen shows a red bar for each exception. Hovering over these bars shows the exception and clicking them allows you to see where the exceptions occurred. You could also use the Exception Hunter to track it down further if you need to. I can see a few WCF activation errors which means that the WCF service is not running.
On running the WinForms app through ANTS I got to see a lot more detail in the event view timeline. It looks like ANTS tracks a lot of the major .Net events such as form open, close and menu selections which gives you an overview of what’s going on although in testing it does not seem to track custom events. Running the profiler on a WinForms app is very similar to profiling web apps.
What did I find?
My first profile run showed me pretty quickly that the core problem is database access, not only that, but access to data that should be cached as it changes so rarely (such as a list of products displayed on the site). So I’ll be looking at caching the WCF and database calls.
File I/O didn’t seem excessive but I could see where a lot of configuration data was loaded on each page access, perhaps that might be better stored at the web app level rather than session.
If I wanted to profile the SQL queries further with ANTS then installing a copy of SQL Express locally would let me do this. Even without the SQL profiling though it was obvious that the majority of the code was fine in Old Faithful and I could easily focus on non database operations using the timeline selection.
Another area Old Faithful feels the pain is app startup times for WinForms, again this is down to database access so using lazy loading we can defer the fetching of this data until first use making the app snappier.
But what about PerfMon?
In theory I could use PerfMon to figure out where my code is getting all gooey and blocked up, but it’s not intuitive and after trying it a couple of times, I lost motivation. Besides, it doesn’t understand .Net and only comes out with raw figures so it won’t show you source code or usage. PerfMon is a support tool in my opinion when the code is closed and you need to see what’s going on, it’s a horrible dev tool.
Is it any good?
ANTS Performance Profiler does what it says on the tin and finds code bottlenecks very quickly, displaying them in an easy to understand format, although there were definitely no ants. Five minutes fiddling with the app and I was able confirm that I had slow database connections and eager loading issues, both of which I’ve got plans to tackle now.
As for cost, you’ll need to figure out how much your time is worth but with daily rates for a developer in excess of the price of a Pro licence (£395), it’s money well spent. Consider buying the .NET developer bundle as you’ll get a memory profiler, exception hunter and Reflector Pro as well for an extra £100.