Tutorial: Analyzing profiling data

Objectives

To analyze the data collected from profiling a Java process, using the Profiling views of the Profiling perspective in the following ways:

• Identify objects and methods that consume the most time
• Identify memory-intensive classes
• Gauge program concurrency
• Locate memory leaks
• Browse every execution of a method as a function of time
• Get a wider view of execution behavior as a function of time
• Identify active threads
• Identify when threads are active
• Identify frequently called methods
• Gauge garbage collection
• Identify different phases of program execution
• Study different method invocations
• Study the caller of a method

Time required

1 hour

Before beginning

Before you start this tutorial, you need to:

1. Install the Eclipse Platform, including the Test and Performance Tools Platform (TPTP).
2. Have the sample profiling file (hcframe.jar) ready for import. The file should be in the following directory:
   TPTP_install_dir\eclipse\plugins\org.eclipse.tptp.platform.collection.framework_<version>

Description

In this tutorial, you will use the different Profiling views to analyze the sample PerformanceExample.class. The sample opens a frame containing two buttons.

You will complete the following tasks:

1. Opening the Profiling Perspective in the workbench
2. Profiling the PerformanceExample class
3. Analyzing the profiling information

To update the views while the application is being monitored, click the Refresh Views button .

Opening the Profiling Perspective in the workbench

From the Window menu, click Open Perspective > Other > Profiling.

Profiling the PerformanceExample class

To profile the PerformanceExample class, follow these steps:

1. Click on the Profile drop-down and select Profile. The Launch Profile dialog opens.
2. Double click on External Java Application to create a new configuration.
3. Switch to the Main tab.
4. Type org.eclipse.hyades.test.collection.framework.PerformanceExample into the Class name field.
5. Click Add Jar to add the jar containing this class.
6. Select TPTP_install_dir\eclipse\plugins\org.eclipse.tptp.platform.collection.framework_<version>\hcframe.jar
   
7. Click Open. The jar is added.
8. Click on the Profile Settings tab. You can specify the profiling criteria in this tab.
9. On the Profile Settings tab, expand the node labelled Java Profiling, select Memory Analysis. Check the check box beside the Java Profiling node. This will add memory related information to the list of information types that should be collected from the application.
10. Select Execution Time Analysis and check the check box beside it. With this option selected you can use the statistical views to analyze time related information. You need to collect execution graphical details to be able to use the Execution Flow and Method Invocation views. Since the purpose of this sample is to guide you through all the profiling views, including Execution Flow and Method Invocation views, while selecting Execution Time Analysis, click on Edit Options, select Show execution flow graphical details in Edit Profiling Options dialog. Click Finish.
11. Profiling Filter Set provides the ability to specify the subset of information you would like to analyze. This is useful if you wish to filter out classes or packages that are not within the bounds of what you would like to analyze.
    Back in the Profile Settings tab, select Java Profiling, and click on Edit Options, Filter set dialog is opened. Leave the default settings under Select a filter set .
12. This dialog also provides the ability to set up filters manually. Under Contents of selected filter set there are already several filter sets identified, leave those settings and click Add to add additional classes or packages to collect data for. The Add Filter dialog opens up.
13. To profile this class, type org.eclipse.hyades.test.collection.framework.* as the Class.
14. Specify the Method Name as * to include only methods related to this example.
15. Click OK. The filter criterion is added to the contents list.
16. Click Finish to close and apply the changes made.
17. Click on the Destination tab. ProfileProject and Default Monitor are the default profiling resources and they can be used to store data from this profiling session.
18. Click Profile.
19. The required profiling resources are created and the agent and process appears in the Profiling Monitor view. 
20. Enable the viewing of Monitors by selecting Distributed Layout as shown in the following screen capture. This allows you to see the monitor that groups your data as well as the machine on which you are running the workbench.
    
    

Analyzing the profiling information

View execution behavior over a period of time

You can examine the execution of the application using the Execution Flow view and table. The execution of the entire program is represented in this view graphically and in a tabular format. In the Execution Flow view, the time is shown on the vertical axis. The Execution Flow table is opened beneath the Execution Flow view and it lists each thread and the methods called by each thread.

1. In the Profiling Monitor view, select your monitor, right-click and select Open With > Execution Flow to open the Execution Flow view. The Execution Flow view opens.
2. To examine a particular method, click on the method to select it. All its called methods are then highlighted in yellow. The vertical length of the highlighted area is an indication of the base time for the method. The exact value for the base time is displayed in the status line.
   
   
   

   Moving your cursor over any object in the view will show detailed information in the status bar at the button of the window.

3. Use the Zoom In tool  to enable the cursor, then point and click to enlarge an area. 

To update the views while the application is being monitored, click the Refresh Views button .

Identifying active threads

In the Execution Flow view, each thread contains periods of activity, which are identified by a profusion of method calls. In symbolic representation, the first called method is a stripe, and methods that it subsequently calls appear as other stripes to its right. The sequence of method calls progresses from left to right; the active parts of the thread are identified by this left-to-right progression.

When you select the whole section outlining the sequence of method calls, the base time spent executing that sequence is displayed in the status line. To see the base time for which the thread is active, find the difference between the following times:

1. Point to the top horizontal line of the selected yellow area to display the corresponding base time in the status line.
2. Similarly, point to the bottom edge of the yellow selected area (which covers the period of execution when the method sequence is in action), and view the base time at that point.

Tips

• If the graph is too crowded and difficult to read, zoom in to the crowded area.
• When you select a method all its called methods are highlighted in yellow.
• You can drag and drop the views on the workbench, arranging them simultaneously if needed. 
• Wherever you point the cursor the corresponding base time is indicated in the status bar. 
• To reset the display of the view, click the Home button.

Identifying frequently called methods

To identify frequently called methods:

1. Use the Zoom tool to enlarge a sequence of method calls.
2. Look for stripes of the same color within the selected area. These stripes identify methods from the same class instance that have been called multiple times.
3. Check the length of the stripes of different color (each of which represents a method). The longer the stripe, the longer the execution time of that method.
   

Gauging garbage collection

Normally, it is impossible to tell that garbage collection has occurred for an object by inspecting stripes in a user thread in this view.

Follow these steps:

1. The garbage collection thread is hidden by default. Enable it by selecting Threads > GC under the Context menu for the view.
2. Check the column furthest to the left in this view. This column is reserved for the garbage collection thread, and is called the GC thread column.
3. Check if there is a single, thin rectangle in the GC thread column. The rectangle will probably be located well down from most method calls on the object. This rectangle appears in the GC thread column whenever garbage collection has occurred for an object.

Analyzing methods using the Method Invocation view

1. From the Profiling Monitor, select either a monitor or an agent. Right click, then select Open With > Execution Flow. The Execution Flow view appears.
2. Select the method to study, right-click, then select Show Method Invocation.
3. Use the Zoom In tool to enlarge a section of the display.  The stripes are color-coded by class and are connected by horizontal lines that represent method calls.
4. Select a method by clicking on its name. 
5. Click the Refresh Views button to ensure that you are viewing current information.
6. Note the status line displaying the method name and numbers 1/1:
   
   This line displays the name of the method, followed by n/m, where n is the invocation currently displayed out of a total of its m invocations.
7. Click Previous and Next to browse all invocations of the selected method (or each message to the selected object). The fraction on the toolbar changes to indicate which invocation you are viewing.

Finding the caller of a method

To find what is calling a method, following these steps, continuing on in the Method Invocation view:

1. To view the caller of the method, click the Show Caller button . The method is displayed along with its caller to the left of it.
2. To view more details about the caller of the method for each new invocation that you view, positioning the cursor over the stripe that represents the caller in the view. The status line displays the caller's information.
3. To see the method that a selected method calls, click the Show Called Method button .