Users Guide
Tracing and Profiling Applications

The call graph model that you create with the BuildModel function contains all the routines in the trace file and can take a long time to build. If you want to monitor the progress of the build or you want to be able to interrupt it while the model is being built, you can pass optional arguments to BuildModel.

BuildModel arguments

BuildModel takes three arguments: the name of an object of type PowerObject, the name of a user event, and a long value representing how often the user event should be triggered as a percentage of the build completed.

The user event returns a boolean value and has two arguments: the number of the current activity, and the total number of activities in the trace file.

Destroying existing models

Before you call BuildModel, you can call DestroyModel to clean up any objects remaining from an existing model.

Example: building a call graph model

In the following example, the user event argument to BuildModel is called ue_progress and is triggered each time five percent of the activities have been processed. The progress of the build is shown in a window called w_progress that has a cancel button.

Profiling lpro_model
lpro_model = CREATE Profiling
ib_cancel = FALSE
lpro_model.SetTraceFileName(is_fileName )

open(w_progress)
// call the of_init window function to initialize
// the w_progress window
w_progress.of_init(lpro_model.numberofactivities, &
   'Building Model', this, 'ue_cancel')

// Build the call graph model
lpro_model.BuildModel(this, 'ue_progress', 5)

// clicking the cancel button in w_progress
// sets ib_cancel to TRUE and
// returns FALSE to ue_progress
IF ib_cancel THEN &
   close(w_progress)
   RETURN -1
END IF

After you have built a call graph model of the application, you can extract detailed information from it.

For routines and lines, you can extract the timing information shown in the following table from the ProfileRoutine and ProfileLine objects.

Example: extracting information from a call graph model

The following function extracts information from a call graph model about the routines called from a specific routine. You would use similar functions to extract information about the routines that called the given routine and about the routine itself.

The function takes a ProfileCall object and an index as arguments and returns a structure containing the number of times the called routine was executed and execution times for the called routine.

str_func_detail lstr_result
ProfileClass lproclass_class
ProfileRoutine lprort_routine

// get the name of the called routine
// from the calledroutine property of
// the ProfileCall object passed to the function
lprort_routine = a_pcall.Calledroutine
lstr_result.Name = ""
lproclass_class = a_pcall.Class
IF isValid(lproclass_class) THEN &
   lstr_result.Name += lproclass_class.Name + "."
lstr_result.name += a_pcall.Name

lstr_result.hits = a_pcall.HitCount
lstr_result.selfTime = a_pcall. &
   AbsoluteSelfTime * timeScale
lstr_result.totalTime = a_pcall. &
   AbsoluteTotalTime * timeScale
lstr_result.percentSelf = a_pcall.PercentSelfTime
lstr_result.percentTotal= a_pcall.PercentTotalTime
lstr_result.index = al_index

RETURN lstr_result

You use the same approach to building a trace tree model as you do to building a call graph model, except that you build a model of type TraceTree instead of type Profiling.

For example:

TraceTree ltct_treemodel
ltct_treemodel = CREATE TraceTree
ltct_treeModel.SetTraceFileName( is_fileName )
ltct_treeModel.BuildModel(this, 'ue_progress', 1)

For more about using BuildModel, see Using the BuildModel function to build a call graph model.

To extract information from a tree model, you can use the EntryList function to create a list of top-level entries in the model and then loop through the list, extracting information about each node. For each node, determine its activity type using the TraceActivity enumerated datatype, and then use the appropriate TraceTree object to extract information.

Example: trace tree model

The following simple example extracts information from an existing trace tree model and stores it in a structure:

TraceTreeNode ltctn_list[], ltctn_node
long ll_index, ll_limit
string ls_line 
str_node lstr_node

ltct_treemodel.EntryList(ltctn_list)
ll_limit = UpperBound(ltctn_list)
FOR ll_index = 1 to ll_limit   
   ltctn_node = ltctn_list[ll_index]
   of_dumpnode(ltctn_node, lstr_node)
   // insert code to handle display of
   // the information in the structure here
   …
NEXT

The of_dumpnode function takes a TraceTreeNode object and a structure as arguments and populates the structure with information about each node. The following code shows part of the function:

string ls_exit, ls_label, ls_routinename
long ll_node_cnt
TraceTreeNode ltctn_list[]
errorreturn l_err

astr_node.Children = FALSE
astr_node.Label = ''
IF NOT isvalid(atctn_node) THEN RETURN
CHOOSE CASE atctn_node.ActivityType
   CASE ActRoutine!
     TraceTreeRoutine ltctrt_routin   
     ltctrt_routine = atctn_node
     IF ltctrt_routine.Classname = '' THEN &
        ls_routinename = ltctrt_routine.ClassName + "."
     END IF   
     ls_routinename += ltctrt_routine.Name
     ltctrt_routine.GetChildrenList(ltctn_list)
     ll_node_cnt = UpperBound(ltctn_list)

     ls_label = "Execute " + ls_routinename + ' :' + &
         space(ii_offset) + String(l_timescale * &
         (ltctrt_routine.ExitTimerValue - &
         ltctrt_routine.EnterTimerValue), '0.000000')
     astr_node.Children = (ll_node_cnt > 0)
     astr_node.Label = ls_label
     astr_node.Time = ltctrt_routine.EnterTimerValue
     RETURN
   CASE ActLine!
     TraceTreeLine tctln_treeLine   
     tctln_treeLine = atctn_node   
     ls_label = LINEPREFIX + &
        String(tctln_treeLine.LineNumber )
     astr_node.time = tctln_treeLine.Timervalue
     ...
     // CASE statements omitted
     ...
   CASE ELSE
     ls_label = "INVALID NODE"
   END CHOOSE

   astr_node.label = ls_label
   RETURN

To access the data in the trace file directly, you create a TraceFile object, open a trace file, and then use the NextActivity function to access each activity in the trace file sequentially. For each node, determine what activity type it is by examining the TraceActivity enumerated datatype, and then use the appropriate trace object to extract information.

Example: direct access to trace data

The following example creates a TraceFile object, opens a trace file called ltcf_file, and then uses a function called of_dumpActivityNode to report the appropriate information for each activity depending on its activity type.

string ls_fileName
TraceFile ltcf_file
TraceActivityNode ltcan_node
string ls_line

ls_fileName = sle_filename.Text
ltcf_file = CREATE TraceFile
ltcf_file.Open(ls_fileName)
ls_line = "CollectionTime = " + &
   String(Truncate(ltcf_file.CollectionTime, 6)) &
   + "~r~n" + "Number of Activities = " + &
   String(ltcf_file.NumberOfActivities) + "~r~n" + &
   "Time Stamp " + "Activity" + "~r~n"

mle_output.text = ls_line

ltcan_node = ltcf_file.NextActivity()
DO WHILE IsValid(ltcan_node)
   ls_line += of_dumpActivityNode(ltcan_node)
   ltcan_node = ltcf_file.NextActivity()
LOOP

mle_output.text = ls_line
ltcf_file.Close()

The following code shows part of of_dumpActivityNode:

string lstr_result

lstr_result = String(Truncate(atcan_node. &
   TimerValue, 6)) + " "
CHOOSE CASE atcan_node.ActivityType
   CASE ActRoutine!
      TraceRoutine ltcrt_routine
      ltcrt_routine = atcan_node
      IF ltcrt_routine.IsEvent THEN
        lstr_result += "Event: "
      ELSE
        lstr_result += "Function: "
      END IF
      lstr_result += ltcrt_routine.ClassName + "." + &
         ltcrt_routine.name + "(" + &
         ltcrt_routine.LibraryName + ") " &
         + String(ltcrt_routine.ObjectId) + "~r~n"
   CASE ActLine!
      TraceLine ltcln_line
      ltcln_line = atcan_node
      lstr_result += "Line: " +     &
         String(ltcln_line.LineNumber) + "~r~n"
   CASE ActESQL!   
      TraceESQL ltcSQL_eSQL
      ltcSQL_eSQL = atcan_node
      lstr_result += "ESQL: " + ltcSQL_eSQL.Name &
          + "~r~n"

   // CASE statements and code omitted
   ...
   CASE ActBegin!
      IF atcan_node.Category = TraceIn! THEN
         lstr_result += "Begin Tracing~r~n"
      ELSE
         lstr_result += "End Tracing~r~n"
      END IF
   CASE ActGarbageCollect!
      lstr_result += "Garbage Collection~r~n"
   CASE else
      lstr_result += "Unknown Activity~r~n"
END CHOOSE

RETURN lstr_result