RCUG 5 RootCause Demo

From OC Systems Wiki!
Jump to: navigation, search

Next Previous Index Top

RootCause User Guide

RootCause Demo

     RCUG 5 RootCause Demo


This demonstration program, included as part of the RootCause installation, has been designed to provide an introduction and overview of the RootCause product. The program is:


It is a simple 2-file C++ program, which computes the value of Pi by iteration using multiple threads. You can find the source in the same directory as the executable file.

The goal of this demonstration is to provide an overview of the whole RootCause process, showing initial definition and tuning of the trace, then collection and viewing of more detailed data about a specific function. The demonstration pictured in this chapter was performed on Solaris. Output should be very similar on AIX and Linux.

Set Up

Before running this RootCause Demo, you must install and set up to use RootCause as described in Chapter 4, "Getting Started". This will define the APROBE environment variable which is necessary to use RootCause.

In the instructions that follow, we'll use $APROBE to refer to the path where RootCause is installed, for example /opt/aprobe.

Use a Local Disk

We recommend you set your current directory to a disk local to the machine you're running on, though this is not required.

Defined X-Windows DISPLAY

Lastly, make sure your DISPLAY environment variable is set. If you're using a Windows client that is running X emulator software such as eXceed or Reflection, we recommend you move to a Unix display for your initial evaluation. If this is impractical, see "X-emulators: (Exceed, Reflection)".

Run With RootCause

Run the following commands:


The rootcause_on command enables the automatic logging of every process that is started, and rootcause_off disables this logging. When the pi_demo program is "registered" with RootCause, it will be traced according to your specifications as well as simply being logged. The illustration below shows the set up and demo execution..

RCUG5 sol cpp run1.gif

NOTE: On AIX, the above process is slightly different than shown above. The invocation of the program must be done with the rootcause run command directly. For example, the above sequence is changed to:

rootcause run $APROBE/demo/RootCause/C++/pi_demo

See "Enabling RootCause for an AIX Application".

View the RootCause Log

Enter the following command:

rootcause open

This will open the RootCause main window, and then a view of the RootCause log. This shows the Trace Display window, the window for viewing all trace events. On the left is the Event Tree; on the upper right is the source/text window; and on the lower right is the "details" window. In the text window you will see some information about the log file.

Locate the APP_START event (in the Trace Event window) associated with the pi_demo program run earlier. To view information about this event, select the APP_START node in the event tree with a left click. This will fill in "details" about that event in the lower right window. With the APP_START pi_demo node highlighted, right-click to bring up the Trace Display Popup Menu.

Click Open Associated Workspace in the popup-menu of the pi_demo APP_START event.

RCUG5 sol cpp log1.gif

This will open a New Workspace Dialog with the program name and default workspace filled in.

This combination: selecting a node in the tree, then using the popup menu to choose an operation, is the basic way of working within RootCause.

Create a RootCause Workspace

To complete the creation of a RootCause workspace for the pi_demo application:

  1. Click Ok in the New Workspace dialog to complete the creation of the workspace.

RCUG5 sol cpp new.gif

  1. Click Yes to confirm that you want to register the pi_demo application with this workspace. This registration is how RootCause determines what applications to trace.

RCUG5 sol not reg.gif

You may close the RootCause Log window opened in a previous step.

You now see the RootCause Workspace Browser. This is described in detail in Chapter 8, "RootCause GUI Reference".

RCUG5 sol cpp wsp.gif

Define the Trace

There are several aspects to a RootCause trace:

In this part of the demo we illustrate the use of Predefined UALs and tracing function calls; then we'll return to the Trace Setup Dialog to add some probes. Custom probes are an advanced feature not presented here.

In the RootCause GUI main window, opened in the previous section:

Enable a UAL

Under the UALs node in the Workspace Tree:

  1. Check the checkbox next to predefined UAL labeled exceptions.ual, as highlighed in the figure above. Simply checking this box will report all user-defined C++ (and Ada) exceptions.

Define Function Traces

Now we'll add traces specific to this application.

  1. Click on the Setup button in the button bar.

This will open the Trace Setup Dialog, showing the modules of the application in the Program Contents Tree. The Program Contents Tree identifies the modules, files, functions, methods, and data in the program, and allows you to specify complex actions on each function and method.

For this demo we'll first just specify a trace on the functions in the file pi_demo.cpp, then return later to add data and probes.

  1. Click on the "lever" icon next to the pi_demo module to expand it; then expand the /tmp/demo directory, so you see the nodes for the source files pi.cpp and pi_demo.cpp.
  2. Click on the pi_demo.cpp source file node, then right-click to see the Trace Setup Popup Menu.
  3. Click Trace All In pi_demo.cpp.
  4. Click the OK button at the bottom right of the dialog to record the trace and dismiss the Trace Setup dialog.

RCUG5 sol cpp setup1.gif

Trace With RootCause

As was done in the preceding section, "Run With RootCause", run the following commands:


Or, for AIX:

rootcause run $APROBE/demo/RootCause/C++/pi_demo

This time, since the program is registered with a workspace, it will be traced as specified in the workspace, and the resulting output will be recorded within the workspace. There will be some startup delay, but if you notice that the program runs slower once started, this is probably because your workspace is being accessed across the network from your machine. See "RootCause and Efficiency Concerns".

View The Data Index

We're now ready to view the data generated by running with our Trace. This is discussed in detail in "RootCause Data Management".

In the Workspace Browser window, do the following:

  1. Click the Index button. This will bring up the Trace Index Dialog for the most recently generated data.
  2. In the Trace Index Dialog, click the Select Events button.
  3. In the Select Events Dialog, check "Exceptions" to index exception events, then click Update to close the dialog and refresh the Index. You should now see something like the dialog below:

RCUG5 sol cpp index1.gif

  1. In the Trace Index Dialog, double-click on the second item in the table, the first item with an Event name of C++ EXCEPTION.

This will open a Trace Display Dialog centered at that C++ Exception event, as shown below.

RCUG5 sol cpp log2.gif

Examine and Revise the Trace

The C++ Exception trace event selected from the index should appear highlighted in the Trace Display. This was a result of checking exceptions under "Enable a UAL" above.

The ENTER and EXIT nodes are a result of the "Trace All In pi_demo.exe" action added under "Define Function Traces" above.

You can see more information about the exception in the Event Details Pane in the lower right.

If you scroll to the top of the Event Trace, you should see three threads: one for the main thread, and one for each of the threads which is started to compute Pi.

The event tree is a call tree, and can be very useful. From an ENTER or EXIT node in the tree you can use the Trace Display Popup Menu to:

  • remove the called function from the set of functions to be traced,
  • find the next reference to the same function in the trace events, or
  • go to the function in the Trace Setup Dialog to trace additional information.

As you step to each event, the Event Details Pane may show additional information about that event. See "Trace Display" for a more complete description of this window.

Take some time to explore the event tree. Then we will look at using the information available here to revise or "tune" the trace used in the next run.

Call Counts

Useful information about the functions called in your program may be obtained by looking at the call frequency as shown in the CALL_COUNTS table.

  1. Select (left-click) the SYN_CALL_COUNTS node, near the end of the event tree.
  2. Right-click (with MB3) to show the Trace Display Popup Menu on this node.
  3. Click Show Associated Table. This will open a table listing each called function and the number of times it was called.
  4. Select (left-click) the extern:"_start()" entry in the call count table.
  5. Right click to show the popup menu.
  6. Select Deselect Function In Trace Setup in the popup menu.

You can also Find Function In Trace Events to search for functions in the call tree, and remove them from there.

You can also search for functions in the call tree, and remove them from there.

RCUG5 sol cpp calls.gif

  1. When you've finished making changes to the trace, click the Dismiss button at the bottom of the SYN_CALL_COUNTS table window, and then
  2. Click the Build button in the main window.
  3. Notice the effects of removing these calls in the next trace we generate.

NOTE: In most "real" programs, high-overhead functions selected for tracing are automatically identified and disabled via load shedding, and are listed in the LOAD_SHED Table associated with the LOAD_SHED node at the end of the event tree. This demo doesn't run long enough for the load shedding heuristics to apply. See "RootCause Overhead Management" for a general discussion of load shedding.

Tracing The Details

So far we have seen how the RootCause process works by:

  • enabling a predefined UAL (exceptions);
  • defining a simple trace from the Trace Setup Dialog;
  • running the application under RootCause;
  • choosing an event in the Trace Index Dialog;
  • viewing events in the Trace Display; and
  • modifying the trace by selecting functions from the call counts table.

RootCause allows you to record much more than the entry and exit of functions and threads. You can record data values and insert probes as well.

Open Trace Setup

  1. Click the Setup button in the Workspace Browser to return to the Trace Setup Dialog.

    This is just as in "Define the Trace" above, but this time we'll record some details about a specific function, ::ataninvint.

Select A Single Function

  1. Click the "lever" to expand the M pi_demo node to see the Source Files in the module.
  2. Expand the pi.cpp node to see the methods.
  3. Select the ataninvint method. This will bring up the source code for this method in the Source Pane, and show a tree of data to log in ataninvint in the Variables Pane.

Log Parameters

  1. Check the box for variable X in the Visible On Entry subtree, and for the return value in the Visible On Exit subtree.

RCUG5 sol cpp vars.gif

Add a Snapshot Probe

  1. In that same lower-right area, click on the Probes tab to show the Probes Pane. Probes in this context are special RCUG5 sol probes.gif

    We've now requested that the parameter X be logged (recorded) on entry to method ataninvint, and also that a data snapshot be taken at this point and marked with the Event Name "My Snapshot".

    Note: A snapshot causes data which might otherwise be deleted do to "data wraparound" to be preserved. In this small demo, a snapshot is not really necessary since it doesn't generate enough data to wrap around and cause old data to be lost. See "Data Snapshots" for more information.

    Save and Build the Trace

    1. Click the OK button at the bottom right of the dialog to save and build the trace and dismiss the Trace Setup dialog. Note that this will take a bit longer this time because we've created Probe actions that require compilation of an APC file.

    Run With RootCause

    1. Again, check that rootcause is enabled with either the rootcause_on or rootcause status command. Then run the application by running the pi_demo program, as described in "Trace With RootCause".

    Index the New Trace

    1. Click the Index button in the Workspace Browser window.
    2. In the Trace Index Dialog that comes up, double-click on the SNAP entry labeled "My Snapshot" to go right to where our new probes were added.
    3. Select the "ENTER ataninvint" node immediately preceding the Snapshot node to see the value of x on entry.
    4. Select the corresponding "EXIT ataninvint" node following the Snapshot to see the return value on exit.

    Find the Calls Of Interest

    The Trace Display window opened from the Trace Index Dialog operation will contain many events, including other calls to ataninvint.

    1. With the "ENTER ataninvint" node selected, right-click to show the Trace Display Popup Menu and choose Find Function In Trace Events.
    2. This will bring up the Find Text in Trace Events Dialog with the current function name filled in. Click Next, and the next occurrence of this string will be selected. Thereafter you can continue clicking Next, or enter any other string to search for. You can use Find Text in Trace Events from any the popup or Edit menu to search for any string in the current Trace Display.

    RCUG5 sol cpp log3.gif

    Where To From Here?

    This chapter should have given you a good overview of the process of developing a trace and gathering data for a program. Now you're ready to try it on your own application. The application you use should be a "debug build" so Trace Setup has the information it needs. See "Selected Topics".

    Copyright 2006-2017 OC Systems, Inc.

    Next Previous Index Top