How to measure performance using the web service performance dialog

Buck Hodges

You may have read about the Team Foundation activity log, which is a database table containing the web service requests executed by the server (turning it on, interesting queries, and more interesting queries).  You may have also seen posts about turning on tracing, both server tracing (see Patrick Carnahan’s first response) and client tracing (see my first response, or the commented-out block in tf.exe.config).  Tracing produces tons of info, and it can be really useful for solving difficult issues.

What if you just want a convenient way to see the web service calls your application (or ours) makes?  The performance dialog is a very convenient way to do it.  James Manning and I put it and the underlying infrastructure in place about a year before TFS shipped to make it easy to find and fix performance issues, particularly on the client.

The dialog is included in the Team Foundation client assemblies.  It must be registered as a trace listener in the application’s .exe.config file and uses the information available in the client-side tracing to display web service calls.  In the dialog, you’ll see how long each call takes, the number of calls made, the average time for a call, and more.

Here’s a screen shot.

The WebService column usually shows the name of the web method followed by the service being contacted.  For example, “GetMetadataEx2[Wor]” is the GetMetadataEx2 web service method being called on the Work Item Tracking service.  All times are reported in milliseconds.

The three-letter designation after the web service method name consists of the first three letters of the service name.  Here’s a list of what you’ll see.

  • Wor – work item tracking
  • Ver – version control
  • Wss – SharePoint
  • Rep – reporting
  • Ser – core Team Foundation services, including the security and team project services
  • Bui – Team Build

In some cases, you will not see the web method name, such as the case with the AsyncSharepoint call above, where the tracing mechanism couldn’t determine the name of the call (it looks for the method name at a particular point in the stack frame).  The other case where this happens is when files are uploaded and downloaded by version control.  In those cases, you’ll see Ver-Upload or Ver-Download and the name of the file involved.

The top section of the dialog shows the aggregated information.  The bottom section of the dialog shows the list of web service methods in the order in which they were called, the elapsed time in milliseconds, and the time of day when the method completed execution.  If the method has not completed, it will display “Running” for the completion time.  If you move the mouse over the entries in the bottom section, a tool tip will show you the stack trace, so you can see what part of your application made the call.

The Clear button resets all of the data in the dialog.  This can be really useful when you want to get information about one particular scenario.  For example, you may clear the dialog and check in your changes to see what gets called in Visual Studio.

For those folks who pay really close attention, you may notice that there’s a difference in the times that you see in the activity log on the server and the times that you see in the performance dialog.  The difference is due to the fact that the performance dialog is showing you the entire time it took for the client to send the request and start getting the response, whereas the server’s activity log shows the time it took for the server to execute the method once it received the request.

To get this dialog, you’ll need to add the following to the .exe.config file for your application.  If you want to see this in Visual Studio for example, you would add this to devenv.exe.config.  The XML snippet goes inside the configuration element.

     <system.diagnostics>
        <switches>
            <add name=“TeamFoundationSoapProxy” value=“4” />
            <add name=“VersionControl” value=“4” />
        </switches>
        <trace autoflush=“true” indentsize=“3”>
            <listeners>
              <add name=“perfListener” type=“Microsoft.TeamFoundation.Client.PerfTraceListener,Microsoft.TeamFoundation.Client, Version=8.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a”
               />
            </listeners>
        </trace>
    </system.diagnostics>

If you are developing an application and are concerned about performance, this is a valuable tool.

tags: , ,

0 comments

Leave a comment

Feedback usabilla icon