Example

Program profiler example.

Source code

File: mymod.4gl

PUBLIC FUNCTION fA(s,n_a)
  DEFINE s STRING
  DEFINE n_a,i INTEGER
  FOR i=1 TO n_a
    DISPLAY "fA "||s||" n:"||i
  END FOR
END FUNCTION

File: myprog.4gl

IMPORT FGL mymod

MAIN
  DISPLAY "Profiler sample"
  CALL fB()
  CALL fC(2)
END MAIN

PRIVATE FUNCTION fB()
  CALL mymod.fA("fB",10)
  CALL fC(5)
END FUNCTION

PRIVATE FUNCTION fC(n_c)
  DEFINE n_c INTEGER
  WHILE n_c > 0
    CALL mymod.fA("fC",2)
    LET n_c=n_c-1
  END WHILE
END FUNCTION

Profiler output (stderr)

Flat profile (order by self) 
   count  %total  %child   %self  name
      25    41.8     0.0    41.8  <builtin>.rts_display
      72    20.2     0.0    20.2  <builtin>.rts_Concat
       8    66.3    52.8    13.5  mymod.fA
       1    75.2    62.8    12.4  myprog.fB
       2    38.3    31.5     6.7  myprog.fC
       1   100.0    95.7     4.3  myprog.main
       8     1.1     0.0     1.1  <builtin>.rts_forInit


Call graph (order by self)

index      %total   %self  %child  calls/of     name
            10.24   10.24    0.00      1/25       <-- myprog.main
            31.54   31.54    0.00     24/25       <-- mymod.fA
[1]         41.78   41.78    0.00        25       *** <builtin>.rts_display
-------------------
            20.22   20.22    0.00     72/72       <-- mymod.fA
[2]         20.22   20.22    0.00        72       *** <builtin>.rts_Concat
-------------------
            31.54    2.43   29.11      7/8        <-- myprog.fC
            34.77   11.05   23.72      1/8        <-- myprog.fB
[3]         66.31   13.48   52.83        8        *** mymod.fA
            31.54   31.54    0.00     24/25       --> <builtin>.rts_display
            20.22   20.22    0.00     72/72       --> <builtin>.rts_Concat
             1.08    1.08    0.00      8/8        --> <builtin>.rts_forInit
-------------------
            75.20   12.40   62.80      1/1        <-- myprog.main
[4]         75.20   12.40   62.80        1        *** myprog.fB
            34.77   11.05   23.72      1/8        --> mymod.fA
            28.03    5.66   22.37      1/2        --> myprog.fC
-------------------
            10.24    1.08    9.16      1/2        <-- myprog.main
            28.03    5.66   22.37      1/2        <-- myprog.fB
[5]         38.27    6.74   31.54        2        *** myprog.fC
            31.54    2.43   29.11      7/8        --> mymod.fA
-------------------
           100.00    4.31   95.69      1/1        <-- <top>
[6]        100.00    4.31   95.69        1        *** myprog.main
            75.20   12.40   62.80      1/1        --> myprog.fB
            10.24    1.08    9.16      1/2        --> myprog.fC
            10.24   10.24    0.00      1/25       --> <builtin>.rts_display
-------------------
             1.08    1.08    0.00      8/8        <-- mymod.fA
[7]          1.08    1.08    0.00        8        *** <builtin>.rts_forInit
-------------------

Interpretation

In the top flat profile, you can see that most of the time is spent in built-in rts_* functions:

      25    41.8     0.0    41.8  <builtin>.rts_display
      72    20.2     0.0    20.2  <builtin>.rts_Concat

This is interesting, but it's not possible for you to improve the built-in functions.

The user function that takes most of the time appears at the third position:

       8    66.3    52.8    13.5  mymod.fA

The third block in the call graph shows more details about the mymod.fA function:

       31.54    2.43   29.11      7/8        <-- myprog.fC
       34.77   11.05   23.72      1/8        <-- myprog.fB
[3]    66.31   13.48   52.83        8        *** mymod.fA
       31.54   31.54    0.00     24/25       --> <builtin>.rts_display
       20.22   20.22    0.00     72/72       --> <builtin>.rts_Concat
        1.08    1.08    0.00      8/8        --> <builtin>.rts_forInit

The mymod.fA function is where you can improve the code. For example, you can reduce the number of DISPLAY calls (rts_display), or || concatenation operator use (rts_Concat).