The Tier Interaction Profiler ( TIP )

There is a little known feature that is part of Visual Studio 2010 Premium edition that I wanted to take a second and let people know about. It is fairly straight forward in its approach, but some of the best features always are! This particular feature is especially helpful when trying to determine why your ASP.NET app isn’t performing as it should, and how requests back to the database the application is built on is helping or hurting that performance.

For this post I downloaded the infamous “NerdDinner” sample app written by ScottGu and friends. Pull that down from here, install it, make sure it runs ( if you have a version of SQL Express running, the app will just do an attach to an mdf file associated with the project. SQL Express is installed by default in all VS2010 installations, but if you don’t have an instance if SQL Express running, you’ll need to play with the connection string settings in the ConnectionStrings.config file. Refresh your memory on connection string syntax here. ). While your at it, be sure to register a user account in order to follow the steps below.

Ok, so now that you have a running web application, let’s run the profiler and see what we see.

 

Launch the Performance Wizard

Go to the Analyze top level menu in Visual Studio and select “Launch Performance Wizard…”.

image

You’ll then be presented with the following dialog:

SNAGHTML2154386c

Just take the default settings ( which should be “CPU Sampling” ) and hit the “Next” button. That’ll bring up the following:

SNAGHTML21556af1

Notice how “NerdDinner” is the only selection in this dialog, which is good, ‘cause that’s the only project we want to profile at this point! If you had many numerous projects that produced exes or web projects, they would also be shown.

Hit “Next”, which brings us to the next page in the wizard:

SNAGHTML2158ec7f

Be sure to check the “Enable Tier Interaction Profiling” check box, as that will enable the features I’m trying to point out later in this post. Feel free to read all that text for more info, or hit “Next”.

Leave the “Launch profiling after the wizard finishes” check box checked, and then hit the “Finish” button.

Visual Studio will now launch the Cassini web server with NerdDinner as the web app. SNAGHTML215cf48a

 

Run the App

At this point, Visual studio starts a performance session, loading the .vsp file in the Visual Studio doc well, and indicates to you that profiling is currently underway:

image 

Now do the following:

  1. Log On
  2. Host two Dinners
    Do this by clicking on the “Host Dinner” tab, entering in the info on the page, hit the “Save” button, and do that again.
  3. Exit the app by closing IE

After a moment, Visual Studio displays something similar to the following view:

image

 

Analyze the Results

One of the great features of the profiling toolset in VS, called the “Hot Path”,  is how quickly it points you to areas of your code that may have some performance issues. At the very least, it is making it very clear where your app is spending its time.

In the image below, you’ll see quickly that the GetMostPopularDinners method seems to be taking the majority of the time, relative to the session we just ran.

image

Go ahead and click on that link. You should see something very similar to the following:

image

A number of things going on here. Take notice of the fact that the “Current View” pull down is now set to “Function Details”. This is important, and also points out a problem in our user experience, as many of our customers don’t realize that there is a pull-down here, and miss a lot of functionality! This is one of the main reasons most folks don’t know about the Tier Interaction Profiler, as it is simply another view in the performance session.

Feel free to play around with the “big blue boxes” by clicking on them, going back and forth by clicking on the left box or the right box. This is simply drilling to more details of a profile method call, or back out.

You’ll also notice that I highlighted the line of code that was brought to our attention via the “Hot Path” feature. You’ll notice that the 42.2% timing characteristic is found in the margin to the left of the text editor, with the actual line highlighted in a default “reddish” color.

Makes sense that this is the line where the time is spent, as this is where the actual LINQ expression built prior to this call is actually executed. ( If you are unfamiliar with this concept, I highly recommend taking a look at this post ).

Taking a look at the code, it clearly looks like we are hitting the database on the backend in this method:

 

         public ActionResult GetMostPopularDinners(int? limit)
        {
            var dinners = dinnerRepository.FindUpcomingDinners();
 
            // Default the limit to 40, if not supplied.
            if (!limit.HasValue)
                limit = 40;
 
            var mostPopularDinners = from dinner in dinners
                                     orderby dinner.RSVPs.Count descending
                                     select dinner;
 
            var jsonDinners =
                mostPopularDinners.Take(limit.Value).AsEnumerable()
                .Select(item => JsonDinnerFromDinner(item));
 
            return Json(jsonDinners.ToList());
        }
  

How can I see the TSQL that we’re sending to the database? Enter the Tier Interaction Profiler.

 

Tier Interaction Profiler

You’ll notice from the image above that the line we are currently exploring is part of our SearchController. Looking more closely at this code, the GetMostPopularDinners method is actually an action on that controller, and turns out is mapped to a URL called relative to the application as /Search/GetMostPopularDinners. What’s this all about?

Well it turns out that the NerdDinner application is a sample that is showing off a number of technologies, most notably ASP.NET MVC 2. ASP.NET MVC 2 has a very rich url mapping capability that comes in handy when you want to make URLs more user friendly, more maintainable, etc. This becomes very evident as we take a look at the Tier Interaction Profiling data.

Pull down the “Current View” combo box and select “Tier Interactions”:

image

You should now see something very similar to the following image in the top pane:

image

The “Name” column contains a list of various artifacts that were requested by the client ( in this case IE running the NerdDinner web app ) to the server. You will see how many requests of that item in the “Count” column occurred, as well has how long the request took to complete.

For example, you’ll notice /Content/Production.css in the “Name” column. That css file was requested 7 times, resulting in a mere 38 millisecond retrieval. This is quite nice to get a general idea of the various requests your app is making of the server.

But at the top of this list ( and back to our running example ), you’ll notice /Search/GetMostPopularDinners as the “artifact” that took the most time. Typically, you’d see some URLs that ended in an aspx page or css doc, etc., but because this app is taking advantage of ASP.NET MVC 2 route maps, you see a more friendly URL that was posted back to the server.

But what does that have to do with database queries?

The TIP view is associating requests back to the server with the database calls associated with those requests. So if you expand the /Search/GetMostPopularDinners item, you’ll see the following:

image

A post back to the server requesting the resource found at the /Search/GetMostPopularDinners URL resulted in two database queries which together only took ~75 milliseconds to roundtrip. Not bad, but even better, in the “Database connection details” pane, you can actually see the TSQL sent to the database. Double click on that entry to see the full SQL, like so:

SNAGHTML220e4aa9

 

Summary

The Tier Interaction Profiler can make understanding requests going from your client to your database backend very easy to understand. Not only understand the actual SQL getting passed, but the performance characteristics associated with the roundtrip.

I hope that helps!

Cameron