Tuesday, 13 August 2013

  • Abstract
  • DotTrace Performance Profiler - In Action
    • Download and Installation
    • Case Study - Profiling a Console Application
    • Case Study - Profiling an ASP.NET Web Application
    • Case Study - Profiling a Remote Application
  • Profiling Guidelines
    • Choosing the Right Profiling Mode
    • Choosing the Right Time Measurement Method
  • Studying Profiling Result
    • Threads Tree
    • Call Tree
    • Plain List
    • Hot Spots
  • Further Reading

Abstract

DotTrace Performance Profiler helps detect performance bottlenecks in a variety of .NET Framework applications.This blog describes the process of analyzing and troubleshooting application performance issues using DotTrace Performance Profiler.

DotTrace Performance Profiler - In Action

DotTrace Performance Profiler profiles the performance of applications targeting .NET Framework 1.0 to 4.5, Silverlight 4, or .NET Compact Framework 3.5. DotTrace can profile applications on your local computer or remote computer. This is used to identify inefficient areas of your application by recording the time spent in each line of code or method as you run your application.

Download and Installation

Latest DotTrace profiler can be downloaded from DotTrace Profiler Site . The trial version works for 14 days only.

Case Study - Profiling a Console Application

This case study shows how you can use DotTrace Performance Profiler to identify the most time-critical parts of a demonstration application, particularly where two different approaches to a problem are created and we need to identify the efficient approach between them. 
The example is a simple Windows Console application that moves log files to a folder and compress them to save memory in a system .Application can also move log files that are 'n' days older using configurable value in web config.
To compress the folder, we have used ZIP and RAR method to perform performance analysis:
  • In the first approach, application uses Zip method.
  • In the second approach, application uses Rar method.
For performance analysis, we are compressing 1.09 GB of log files in .txt format.
Starting Profling Session
  1. Start DotTrace Performance Profiler
  2. Click Profile on the Home tab. Click Standalone Application in the list.
  3. Type the path to the application executable file in the Application text box. Refer below screen shot.

  4. Choose Sampling mode for fast profiling.There are Multiple profiling modes. For more information, see Choosing the Right Profiling Mode.
  5. Choose  Wall time(CPU instruction) measure for execution time. We can measure execution time in several ways. For more information, see Choosing the Right Time Measurement Method.
  6. Click Run.  
Alternatively, DotTrace profiling session can also be started from Visual Studio 2010 to start the profiling session directly. Refer screen shot below:
 

Analysis of ZIP Method
Profile session result for ZIP method shows that it took 82.92 seconds. Refer below snapshot .
Analysis of RAR Method
Profile session result for RAR method shows that it took 118.3 seconds. Refer screenshot below:
Conclusion
  • ZIP method takes 82.9 seconds and compress from 1.09GB to 275 MB.
  • RAR method takes 118.3 seconds and compress from 1.09GB to 223 MB.
Zip method takes less time than Rar method, however, Zip compression takes more hard disk space for compressed file. Thus, we can choose Zip method when quick execution of compression is more important than saving more hard disk space and can choose Rar method when saving more space is important than quick execution of compression process.
The similar steps can be taken in other areas where algorithms are used. Different algorithms can be applied to implement the same solution and then can be compared to determine best suitable algorithm for requirement parameters.

Case Study - Profiling an ASP.NET Web Application

This case study shows how you can use DotTrace Performance Profiler to identify the most time-critical parts in ASP.NET web application. The ASP.NET web application is profiled to obtain bottleneck areas which can be tuned further to improve performance.
Starting Profiling Session
  1. Click Profile on the Home tab. 
  2. Click IIS Application  from the list of application types.
  3. Select the Run browser check box.
  4. Type the application URL(http://secure.corp.com) in the Url text box. Refer below screen shot.

  5. Choose Line-by-Line mode for more detailed information. There are Multiple profiling modes. For more information, see Choosing the Right Profiling Mode.
  6. Choose  Wall time(CPU instruction) measure for execution time. We can measure execution time in several ways. For more information, see Choosing the Right Time Measurement Method..
  7. Click Run in the Profiler Configuration dialog box to open DotTrace Performance Controller window. Refer below screen shot.
    Performance_Profiling__Control_Profiling__Getting_Snapshot
     Performed the below use cases in the application to profile for performance:
  • Navigated to Dashboard section and select a dashboard to view report.
  • Navigated to Email section and Search for an Email.
When all information we need has been collected during profiling, click Get Snapshot using the DotTrace Performance Controller window.
After a snapshot is created, we can stop profiling by click on  Kill Process.

Analysis of View Reports on Dashboard Operation
While navigating to Hot Spots View, We can easily find out the hot spot areas that takes more execution time. In this profiling resultGetAppTodayItemsNewReportFilter function takes 6 second to execute a SQL Procedure. 
Conclusion 
 So we can now improve the SQL Procedure usp_GetAppTodayItemsNewReportFilter to enhance the performance of application.

Analysis of Search Operation
We can also view result in Plain List that shows list of all functions called in your application during the profiling process, while navigating to Plain List View results we can easily find out the functions that take more execution time, for example GetEndingTextOfBuffer takes 16 second that can be a critical time duration.
Conclusion 
 So we can modify the regular expression  to improve the performance of application.
Note: It can be easily identified that DotTrace profiler mark areas which requires performance tuning in various ways,Using these mechanisms, bottleneck areas in application can be quickly identified using DotTrace profiling session result.

Case Study - Profiling a Remote Application

To profile on a remote computer
Step 1: Copy the DotTrace Remote Agent to the remote server
First we need some way for DotTrace to connect to the remote machine. This is done using the DotTrace Remote Agent. It can be found in:
C:\Program Files (x86)\JetBrains\dotTrace\v5.5\Bin\Remote

Step 2: Run the DotTrace Remote Agent on the remote server
Step 3: Attach to the DotTrace Remote Agent from DotTrace on your local machine
Once the Remote Agent is running on the remote computer, you can connect to it from DotTrace running on your local machine using the Attach To Process button in DotTrace.
  Click on the Profile on remote computer link to bring up the Add Host dialog. 
Profile App
Add Host
Step 4: Profile the application
After the remote computer is selected, a list of .NET 4.0 and above processes will be displayed. Due to limitations of the .NET Profiler API, it is only possible to attach to processes running .NET 4.0 and above.
Profile App with Connection to Remote Server
Choose start profiling immediately and click Run. The usual DotTrace profiling control dialog will appear.
dotTrace profiling control dialog
Step 5: Click Get Snapshot. The performance snapshot will automatically be downloaded to DotTrace and opened - ready for analysis.
Conclusion
After analyzing the result of Hot Spot view, we find that GetEndingTextOfBuffer function take more execution time so we can modify the function to  improve the performance of application.
Note: We can analyze the snapshot data just as if we had recorded . After determining the root cause and deploying a fix, we can repeat the process to collect another snapshot and verify that we have resolved the performance problem.

Profiling Guidelines

Choosing the Right Profiling Mode

An application can be profiled in several ways. In DotTrace you can choose between:
  • Sampling is the fastest and the least precise mode. This is a way of profiling when DotTrace basically grabs current call stacks on all threads once in a while. Accuracy cannot be more than the sampling frequency which is several hundred hertz.
  • Tracing is slower, but more precise than Sampling. This is a way of profiling when profiler gets notifications from CLR when a method is entered and left . The time between these two notifications is taken as the execution time of the method.
  • Line-by-line is the slowest and the most precise mode. This is a way of profiling when DotTrace collects timing information for every statement in methods. This way of profiling lets you collect the most detailed information on methods that perform significant work. 

Choosing the Right Time Measurement Method

Time is a valuable resource. If your application seems to be a bit sleepy and slow, it is a good reason to make time measurements and find a weak point.
Using DotTrace Performance you can measure execution time in several ways:
  • Wall time (CPU instruction) also called real-world time or wall-clock time, is time elapsed between method entry and method exit. This approach makes no difference between the cases when a method consumes CPU and does some meaningful work and when a method is in a sleep, wait or join. DotTrace Performance measures time in both cases. So it reads values of processor on method entry and on method exit, then calculates the difference.
  • Wall time (performance counter) Performance counters is part of the Windows API and it allows taking time samples in a hardware-independent way. DotTrace Performance uses API to retrieve and use performance counter data from operating system, network and devices for measuring time.

  • Thread time is the time measured by a thread-specific timer which is paused when its thread is paused (waiting for processor or sleeping). This kind of measurement is supported only for sampling profiling and has lower resolution than other methods (about 10 ms).
  • Thread cycle time is the time measured by a thread-specific timer which is paused when its thread is paused (waiting for processor or sleeping). It is a bit more accurate way to time your application code. Actually, Thread cycle time is similar to Wall time (CPU instruction), it also uses CPU instruction to calculate the time, but does not take into account the time when thread does not do real work. 
Difference between wall time and thread time, consider the following example. Some function executes for 10 seconds. It is waiting for some data from the network for 8 seconds. And it is processing the data without sleeping or waiting for the remaining 2 seconds. Wall time for this function is 10 seconds. Thread time for this function is 2 seconds.  

Studying Profiling Result

DotTrace Performance provides several views to facilitate your analysis and research efforts. We can choose one of the views depending on your goals and preferences.

Threads Tree

The Threads Tree view lists all threads in your application. They are sorted by their execution time. Each thread is identified by a name or ID. The main thread is marked with the Main_Thread icon.
Reference__Snapshot_Views__Threads_Tree__All_Threads
You can expand a thread node and search the call stack for expensive functions.
Reference__Snapshot_Views__Threads_Tree
Each node in the Thread Tree view contains the following information:
Reference__Snapshot_Views__Threads_Tree__Line
  1. The percentage of time spent in this call related to time spent executing the thread.
  2. Short name of the function being called.
  3. Total time spent in this function and its subtree.
  4. Number of calls made in this call stack.
  5. Full name of the called function.

Call Tree

The Call Tree view is a representation of all function calls in all threads. Each top-level node represents a top-level function which was executed by a certain thread. 
Reference__Snapshot_Views__Call_Tree
Each node of the Call Tree view contains the following information:
Reference__Snapshot_Views__Call_Tree__Line
  1. The percentage of time spent in this call relative to time spent in the root function in the current tab.
  2. Short name of the called function.
  3. Total time spent in this function and its subtree.
  4. Number of calls made in this call stack.
  5. Full name of the called function.

Plain List

The Plain List view shows list of all functions called in your application during the profiling process.

Hot Spots

The Hot Spots view lists functions with highest own time in the profiled application code.
Reference__Snapshot_Views__Hot_Spots
Each node of the Hot Spots view contains the following information:
Reference__Snapshot_Views__Hot_Spots__Line
  1. Percentage of time spent by the top-level function in current call stack relative to time spent in all calls in the current tab.
  2. Short name of the called function.
  3. Sum of top-level function's own times or the contribution of the top-level function to the sum of times in this call stack.
  4. Sum of top-level function's calls or the contribution of the top-level function to the sum of calls in this call stack.
  5. Full name of the called function.

Further Reading

We have only brushed the surface of the capabilities of the tool, so you can check out the features and tutorials available at JetBrains DotTrace Performance profiler site.

2 comments: