Programming + Errors: Java - Profiling Or Tracing

1.0 Introduction

This document is a quick starter on how to use the profiling tools available in the Profiling and Logging perspsective. The set of profiling tools provides software developers or testers with the ability to analyze the performance of a Java program or to gain a comprehensive understanding of the overall performance of an application. Crucial data on object allocations, garbage collection cycles, object references, method time stamps, and thread or object interactions can be displayed and aid in determining which components of code are heaveily effecting the overall performance of a program.

2.0 Getting Started

The Profiling Monitor view is the primary view of the Profiling and Logging perspective. It is used to monitor Java applications from any number of hosts.
Java applications can be profiled by using the workbench to either launch a Java process or attach to a running process. Launching or attaching to a Java process can be done locally or remotely.
To be able to profile a Java application, the Hyades Data Collection Engine needs to be running on the deployment machine. The engine can be downloaded from the Hyades website http://www.eclipse.org/hyades. See the install instructions for Hyades and the Hyades Data Collection Engine for more details.

3.0 Profiling an application on a local machine

This section demonstrates how to profile an application on a local machine.

3.1 Create a Java project

A Java project will be created using the sample Java application listed below.
import java.io.BufferedReader;
import java.io.IOException;
import java.io.InputStreamReader;


public class CarModel {

    /* Required car parts: 1 Engine, 4 wheels, and 2 doors */ 
    public Engine engine = new Engine();
    public Wheel[] wheel = new Wheel[4];   
    public Door left = new Door(), right = new Door(); 



    public CarModel()
    {
      for(int i = 0; i  < 4; i++)
        wheel[i] = new Wheel();
    }
 
 
 
    /* Launcher */
    public static void main(String[] args) throws IOException
    {
        final String LINE_SEPARATOR = 
        System.getProperty("line.separator");
        final int BORDER_CHAR_LENGTH = 40;
        final int UNREF_OBJ_CREATED = 10;
        StringBuffer menu = new StringBuffer();
        CarModel car = new CarModel();
  
        /* Create the menu */
        for (int i = 0;i < BORDER_CHAR_LENGTH; i++)
          menu.append('-');
        menu.append (LINE_SEPARATOR).append("   (1) Simulate car usage");
        menu.append (LINE_SEPARATOR).append("   (2) Create unreferenced objects");
        menu.append (LINE_SEPARATOR).append("   (q) Quit");
        menu.append (LINE_SEPARATOR);
        for (int i = 0;i < BORDER_CHAR_LENGTH; i++)
          menu.append('-');
  
        /* Display the menu */
        System.out.println ("CarModel started" + LINE_SEPARATOR + "Menu:");
        System.out.println (menu.toString());
        System.out.println ("Choose an option:");
        BufferedReader in = new BufferedReader(new InputStreamReader(System.in));
        String input = in.readLine().trim();

  
        /* Accept input for the desired option */
        while (!input.equalsIgnoreCase("q"))
        {   
          /* Check for invalid entry */
          if (input == null || input.length() != 1 || !Character.isDigit(input.charAt(0)))
          {
            System.err.println ("Wrong option");
            input = in.readLine().trim();
            continue;
          }
      
          switch(Integer.valueOf(input).intValue())
          {
            case 1:
              simulateCarUsage(car);
              break;
            case 2:
              for (int i = 0; i < UNREF_OBJ_CREATED; i++)
                new CarModel();
              System.out.println (UNREF_OBJ_CREATED + " unreferenced objects of CarModel has been created");
              break;
            default:
              System.err.println ("Wrong option");    
          }
        input = in.readLine().trim();
      }
    
    }

 
    /* Simulates car usage */
    public static void simulateCarUsage(CarModel car)
    {
      car.left.window.rollup();
      car.engine.start();
      car.engine.rev();
      car.wheel[0].align();
      car.engine.stop();
    }
} 


/* Inner classes used to model car parts */
class Engine 
{ 
    public void start() 
      { System.out.println("Start the car.");}
    public void rev()   
      {System.out.println("Rev the engine.");}
    public void stop()  
      {System.out.println("Car stopped.");}
}

class Wheel 
{ 
    public void align() 
      {System.out.println("Tires aligned.");}
}

class Window 
{ 
    public void rollup() 
      {System.out.println("Rollup the window.");}
    public void rolldown() 
      {System.out.println("Rolldown the window.");}
}

class Door 
{
    public Window window = new Window();
    public void open() 
   {System.out.println("Open()");}
    public void close() 
      {System.out.println("Close()");}
}
To create a Java project:

Start an instance of Eclipse.

From the menu, select Window > Open perspective > Other.

In the Select Perspective dialog, select Java and click OK .

From the menu, select File > New.

In the New Wizard, select Java Project. Click Next.

Specify the project name as ProfilingExample.

Click Finish. Your new Java project is created in the Package Explorer view.

From the pop-up menu of the newly created project, select New > Class.

Specify profilingExample as the package name and CarModel as the class name.

Click Finish.

Open the newly created class and replace its content with the code listed in Figure 1.

Save the class. The class will be compiled automatically.

3.2 Launch the sample application
The sample application will be launched from the Profiling and Logging perspective.

Switch to the Profiling and Logging perspective by selecting Window > Open perspective > Other > Profiling and Logging.

Click on the launch profiling button and select Profile.

In the Profile configuration dialog, double-click on Java Application. A new configuration is created and the details are shown in the right pane.

Specify the project name as profilingExample.

Click on Search for the main class. The wizard should automatically detect the CarModel class.

Select the CarModel class and click OK.

3.3 Specifiying profiling filters
Profiling filters allow users to limit the amount of data that is collecting in a profiling session. Follow these steps to set up filters for the sample application:

In your profiing configuration, under the Profiling tab, select the Overview tab.

Click Add to add your own profiling set. The Add Profiling Set wizard opens.

On the Profiling Set page, specify a name and a description for your profiling set. Click Next.

On the Profiling Type page, select the Memory Analysis and the Time Analysis check boxes.

Click on Execution Time Analysis. The details of this profiling set are shown in the right pane.

Select the Show execution flow graphical details options.

Click Next.

On the Filter Set page, specify the filter set that you want applied by selecting from the Select a filter set list. You can use the Default set.

Under Contents of selected filter set, click Add.

Specify profilingExample.CarModel as the Class and main as the method.

Select EXCLUDE from the Rule list.

Click OK. The filter criterion is added to the contents list.

Click Finish.

Click Apply to save the changes.

Click Profile to start profiling your application. The Profiling Monitor will show the CarModel application started.

The console will show the following output:

By default, the hosts and monitors are hidden. To add the hosts and monitor, click on the menu button of the Profiling Monitor view and de-select Hosts. Repeat this step to add Monitors to the Profiling Monitor view.

3.4 Examining the profiling data using the profiling views
This section will demonstrate how to use the different statistics views, and a number of the graphical views to identify usage patterns and code execution.

Memory Statistics view
From the Profiling Monitor view, using the pop-up menu of the profiling agent, select Open with > Memory Statistics.

In the Memory Statistics view, expand the profilingExample package.

Select CarModel. Notice the information provided for the class:
Total instances: The total number of instances of the CarModel class.
Live instances: The number of instances that are alive (i.e. instances that were not collected by the garbage collector).
Collected: The number of instances that have been garbage collected.
Total Size (bytes): The size of an instances associated with a specific type.
Active Size (bytes): The size of an instances associated with a specific type.

From the toolbar, select Class to open the class levelinformation. Notice that all the non-filtered invoked methods of the CarModel class appear under its name. The filtered main method which has already been invoked at this point, does not appear under the class.

Select from the toolbar to open the instance level information. The number of instances associated with a specific object type are listed beneath the object.

Expand the CarModel class and note that it has only one associated instance.

In the console view, enter 2 to instantiate ten unreferenced objects of the CarModel class.

Switch back to the Memory Statistics view, right-click anywhere in the view, and select Refresh Views.

Note the changes in the instances by the . Expand the the CarModel class. There are now eleven instances of the CarModel class listed.

Execution Statistics view
From the Profiling Monitor view, using the pop-up menu of the profiling agent, select Open with > Execution Statistics.

From the toolbar, click to open the method level information. Notice that the base time, average time, cumulative, and number of method calls are shown in this view:
Base Time: The amount of time (in seconds) the method has taken to execute. Not including the execution time of any other methods called from this method.
Average base time: The average base time required to execute this method once.
Cumulative base time: The amount of time (in seconds) this method took to execute. Including the execution time of any other methods called from this method.
Calls: The number of times this method was invoked.
The elements in the views can be sorted by simply clicking on a desired column header. for example, click on the Base Time column header to sort the methods by this attribute.

Switch to the console view. If it is not open, select Window > Show view > Console to open the view.
Enter '1' in the console view to invoke a set of methods. The console will show the following output:
Rollup the window.
Start the car.
Rev the engine.
Tires aligned.
Car stopped.
In the Profiling Monitor view, click the refresh view button to refresh the views.

Switch to the Execution Statistics view with the method-level information selected. Note that there are new methods added to this view.

Repeat step 8 and 9. Notice that the number of calls to the start() method has increased from 1 to 2. The changes in the column values are indicated by a delta icon with an up arrow or a down arrow to indicate an increase or a decrease. Refreshing the views is similar to taking snapshots of the running program. The views in the Profiling and Logging perspective provide the ability to compare views and to identify the difference between the snapshots.

Right-click on simulateCarUsage() and select Open source. Notice that the workbench automatically changes the perspective and the cursor is moved to the beginning of the simulateCarUsage() in the Java editor. This option is useful for pinpointing overheads in specific portions of a Java program.
Garbage collection
In the Profiling and Logging perspective, create un-referenced objects by entering 2 in the console view. See step 12 in the previous section.

In the Profiling Monitor view, press the garbage collection button to run garbage collection. Verify that the live instances of CarModel has decreased. A good JVM will collect all ten unreferenced objects of CarModel, decreasing the value of the live instances to only 1. Forcing garbage collection in the middle of a program helps to identify memory leaks and the number of unnecessary objects created.

UML2 sequence diagrams
In the console view, enter q to quit the application.

The application can be re-launched by selecting the profiling button in the toolbar.

In the Profiling Monitor view, use the pop-up menu of the monitored profiling agent and select Open with > UML2 Class Interactions.

The sequence diagram should be similar to the one below.

The time compression bar along the left edge of the diagram indicates the time elapsed between consecutive events. This bar indicates which part of a method consumes the most time, helping to identify hot spots in the program being monitored. In this example, the creation of the Door object is identified as a hot spot.
Moving the cursor over any of the blocks will display the name of the invoked method of the class. The thread and object interaction views are two other similar sequence diagrams available in the Profiling and Logging perspective.

Execution flow diagram and table
In the Profiling and Logging perspective, select the toolbar button to open the Execution flow view diagram.

This view indicates the general flow of the Java application, and can help in identifying repetitive coding in a given Java application. Stripes cascade to the right as one method calls another method, whose responding method in turn calls another method, and so on. Stripes are grouped in columns by thread. A thin, black vertical line separates one column from another. The name of each thread appears at the top of its column.

To open the Execution table, right-click anywhere in the Execution Flow diagram view and select Show Execution Table. The execution table shows the same information in a tabulated format.

Object references table
In the Profiling Monitor view, right-click the monitoring agent and select Collect object references.

From the toolbar, click on the Object References button to open the Object references table.
Expand the CarModel class to show all the references made in this class.

Note that there is only one instance of this type that has been instantiated. This type refers to an array of Wheel, Door, and Engine objects. Reviewing the declared instance variables of the CarModel verifies this:
public Engine engine = new Engine();
    public Wheel[] wheel = new Wheel[4];   
    public Door left = new Door(), right = new Door(); 
To end the process, from the toolbar of the Profiling Monitor view, click the terminate button .
3.5 Attaching to a local Java application
Being able to attach to a running Java process allows users to run applications without any interruptions from the Java profiling agent. The Profiling and Logging perspective can then be used to attach to a running process for determining the reason why the application takes an unusual amount of time or memory to perform a specific task.
The workbench and the Hyades plug-ins will be used to demonstrate how to attach to a Java application for monitoring. For this part of the guide, a different Eclipse workspace will be used.
Switch to the home directory of the Eclipse platform (e.g. D:\Eclipse).
Use the following command to start the eclipse workbench with profile as the workspace name:
eclipse -data profile
This workbench will be used to profile a second workbench.
The Java Profiling Agent is invoked by specifying the JVM argument - XrunpiAgent:server=enabled on the java command to start the application to be profiled. For example:
java -XrunpiAgent:server=enabled javaApp
. In this case we want to profile an instance of the Eclipse workbench and we will use the eclipse program to start the workbench.
Navigate to the home directory of the Eclipse workbench and run the following command to start a second workbench with the default workspace:
eclipse -vmargs -XrunpiAgent:server=enabled
where

-vmargs

is how to specify JVM arguments to the JVM used to run Eclipse

-XrunpiAgent

invokes the Java Profiling Agent

:server=enabled

Specifies the mode of the Java profiling agent. Enabled mode will allow the Java application to run normally with the Java profiling agent running in the background. If the mode is changed to controlled, then the application will be locked (i.e. not executed) until it is attached to.

For more details on the -XrunpiAgent argument, type java -XrunpiAgent:help in a console window. Note: This command is case-sensitive on most platforms. The profiling agent is installed as part of the Hyades Data Collection Engine. Ensure that the bin directory of the Hyades Data Collection Engine is in the PATH environment variable on Windows systems and the lib directory is in the LD_LIBRARY_PATH environment variable on Linux systems.
Switch to the Profiling and Logging perspective in the workbench launched with the profile workspace.

In the toolbar, click the profile button and select Profile.

In the Profile configuration dialog, double-click on Attach - Java Process. A new configuration is created and the details are shown in the right pane.

Under the Agents tab, select the Java Profiling Agent on the left side and use the right arrow to include the selected agent.

Under the Profiling tab, select the Overview tab.

Click Add to add a profiling set called "Hyades plug-ins".

Select the newly created profiling set and click Edit. The Edit Profiling Set dialog opens.

Select the Memory Analysis and the Time Analysis check boxes.

Click on Execution Time Analysis. The details of this profiling set are shown in the right pane.

Select the Show execution flow graphical details option.

Click Next.

On the Edit Filters page, under Contents of selected filter set, use the Remove button to remove all existing filters.
Click Add and add the following two filters:
Package or class:  org.eclipse.hyades*
Method name: *
Rule: Include  

Package or class: *
Method name: *
Rule: Exclude
These filters will ensure that everything but the Hyades packages will be excluded in the profiling session.
Click Finish.

Click Apply to save the changes.

Click Profile to begin profiling. You may be prompted with a message about how the agent should be started. Click OK to close the dialog box if you are prompted with this message.

The initial state of the attached agent will be in an attached mode.

Right-click on the agent and select Start Monitoring to start tracing the second workbench. The agent will now be monitored.

In the second workbench, switch to the Profiling and Logging perspective. This action will be enough to trigger some data to be collected in the first workbench.
Note: The 'Pause Monitoring' button at the top of the Profiling Monitor view can be used to pause monitoring of the attached agent at any time. To completely stop monitoring the attached application, use the pop-up menu of the agent and select Detach from Agent.

Exit the second workbench. The status of the profiling agent in the first workbench should eventually change to terminated

Open the package statistics view to verify that some data has been collected from the Hyades plug-ins.
4.0 Profiling a remote Java application
This section discusses how to profile remotely deployed applications.
Prerequisite:
You will need the to have the Hyades Data Collection Engine installed and running on the remote machine in order to be able to remotely launch and profile Java applications. See the Getting started guide for installing the Data Collection Engine.

4.1 Launching a Java application remotely
1.2 Launching a Java Application Remotely To launch a Java application on a remote machine:
Launch the Eclipse workbench.

Switch to the Profiling and Logging perspective.

In the toolbar, click the profile button and select Profile.

In the Profile configuration dialog, double-click on External Java Application. A new configuration is created and the details are shown in the right pane.

Under the Hosts tab, enter the name of the desired host and the port number of the data collection engine. By default the port number is 10002.

Click on Add to add the host to the Default Hosts list.

Click on Test Connection to verify that the workbench can communicate with the running engine on the remote machine.
Under the main tab, enter the class name and the class path of the Java application on the remote machine. For example, to launch the Java class under D:\Test\ProfileClass.class, enter ProfileClass for the class name and enter D:\Test for the path of the class. Additional JAR files can be added by separating each path by a semicolon on windows or colon on UNIX platforms, for example:
Windows:
D:\Test;D:\Test\mylib.jar
UNIX platforms:
/home/user/Test:/home/user/Test/mylib.jar
Click Next.

Specify the profiling filters. See section 3.3 for details.

After the profiling filters are specified, click Profile to begin profiling the remote application.

Open a number of profiling views to ensure that data is being collected for the remote application.
4.2 Attaching to a remote Java process
To attach to an application running on a remote machine, the Java Profiling Agent can be used to launch the process on the remote machine.
On the remote host, use same command mentioned in section 1.1 to start the desired application:
java -XrunpiAgent:server=enabled ProfileClass
where ProfileClass is the name of the class that is intended to be started.
On your local machine, launch the Eclipse workbench.

Switch to the Profiling and Logging perspective.

In the toolbar, click the profile button and select Profile.

In the Profile configuration dialog, double-click on Attach - Java Process. A new configuration is created and the details are shown in the right pane.

Under the Hosts tab, enter the name of the desired host and the port number of the data collection engine. By default the port number is 10002.

Click on Add to add the host to the Default Hosts list.

Under the Agents tab, select the profiling agent that is running on the remote host and add it to the Selected agents list.

Under the Profiling tab, specify the profiling filters. See section 3.3 for details.

Click Profile to begin profiling your application.

Open a number of views to ensure that data is being collected on the remote application.
http://blog.zvikico.com/2007/12/tracing-java-ex.html