Analyzing Performance Profiling Reports

Performance profiling can be applied to a user-selected set of components. The result of the performance profiling is a report on each profiled component.

A performance profiling report consists of two parts:

• A global report that provides general information about the profiling session, including clock attributes, CPU attributes, the distribution of CPU time between idle threads, user processes, non-profiled supervisor components, and each of the profiled supervisor components.

• A component-based function table that indicates the distribution of CPU time within the profiled component.

For each function, the performance profile report displays the information listed in the following sections.

Function Header

The function header contains the following fields:

• Function number. This field indicates the function number in the current report, and is provided to facilitate analysis of the report using a text editor.

• Function name. This field indicates the name of the function.

• Size. This field indicates the size of the function (in bytes).

• Time spent in function. This field indicates the flat time spent in the body of the function (the number of profiling ticks that occurred while an instruction was being executed within the function). This value is followed by the percentage of the total component time it represents. This is probably the most valuable information -- a report can be sorted by this key if desired.

• Total time spent in function. This field indicates the aggregated time spent within the function and called functions. The value is expressed as a percentage of total process time. By default, the report generator sorts the table by the total time key. This field is computed by the report generator and assumes that each call to a given routine takes the same period of time. This information is only provided in the full profiling form. In the simple form, the information is the same as the flat time information.

• Recursion indicator. This information is provided in the full profiling form only. The recursion indicator field indicates that the procedure was found in a recursive loop. Because the profiling system is not completely set up for multithreading, this indicator might be erroneously set.

Call Graph Description

The call graph description contains the following fields:

• List of callers. This field details a list of the functions calling the profiled function. For each caller, the report provides:

  • Caller's function number

  • Number of calls

  • Caller's name and call offset in the caller's body. When a function calls another function from several locations, several entries are made in the list of callers.

• List of called functions. For each called function, the report provides:

  • Callee's function number

  • Number of calls

  • Percentage of the total function time that is charged to the callee

  • Name of the function

Sample Profiling Report

The following is a sample profiling report.

overhead=2.468
  memcpy 4 K=18.834
  memcpy 16 K=51.936
  memcpy 64 K=185.579
  memcpy 256 K=801.300
  sysTime=2.576
  threadSelf=2.210
  thread switch=5.777
  threadCreate (active)=8.062
  threadCreate (active, preempt)=10.071
  threadPriority (self)=3.789
  threadPriority (self, high)=3.195
  threadResume (preempt)=6.999
  threadResume (awake)=4.014
 ...
  ipcCall (null, timeout)=35.732
  ipcSend (null, funcmode)=7.723
  ipcCall (null, funcmode)=31.762
  ipcSend (null, funcumode)=7.924
  ipcCall (null, funcumode)=31.864
  ipcSend (annex)=8.294
  ipcReceive (annex)=7.086
  ipcCall (annex)=33.708
  ipcSend (body 4b)=8.020
  ipcReceive (body 4b)=6.822
  ipcCall (body 4b)=32.558
  ipcSend (annex, body 4b)=8.684
  ipcReceive (annex, body 4b)=7.495
  ipcCall (annex, body 4b)=34.849