## `prog::profile` -- display timing data of nested function calls

#### Introduction

`prog::profile(`stmt`)` evaluates the MuPAD statement `stmt` and displays timing data of all nested function calls.

#### Call(s)

`prog::profile(stmt)`

#### Parameters

`stmt` | - | a MuPAD statement

#### Returns

the result of `stmt`

#### Related Functions

`prog::calltree`, `prog::trace`

#### Details

- The time usage of functions can be measured and displayed with `prog::profile`. For every function called during the evaluation of `stmt`, `prog::profile` prints the time spent in this function and the number of calls.
- `prog::profile` can be helpful in finding time critical functions and unnecessary nested function calls.

#### Example 1

We define three functions `f`, `g` and `h`. `prog::profile` displays the time spent in each function and the number of calls to it:

    >> f := proc() local i; begin for i from 1 to 20000 do end_for end_proc:
       g := proc() begin f(), f() end_proc:
       h := proc() begin g(), f(), g() end_proc:
       prog::profile(h()):

          Total time: 300 ms
          ------------------
          f:100.0 % 300 ms total 5 call(s) 0 lookup(s) 60.0 ms/call
          g:  0.0 %   0 ms total 2 call(s) 0 lookup(s) 0.0 ms/call
          h:  0.0 %   0 ms total 1 call(s) 0 lookup(s) 0.0 ms/call

          <h> calls
             f : 1 time(s)
             g : 2 time(s)

          <g> calls
             f : 4 time(s)

#### Background

- The timings displayed by `prog::profile` are generated by the kernel.
- Evaluation of `stmt` inside `prog::profile` takes substantially longer than evaluating `stmt` directly. This extra time does not influence the validity of the result, i.e., if `prog::profile` reports `f` taking three times as long as `g`, then this is also the case when evaluating `stmt` directly.

#### Changes

- no changes

Do you have questions or comments?
Copyright © SciFace Software GmbH & Co. KG 2000