Profiling Programs
There is an experimental utility for profiling programs interactively.
Two kinds of profiling are supported:
one may count the number of calls to a predicate,
or compute the time spent in a predicate.
It is important that the predicates being profiled are either consulted,
or compiled with the t option,
so that calls to the relevant predicates can be intercepted by the profiler.
To use the profiler, predicates whose calls are to be counted must be
passed to count/1, e.g.
| ?– count([p/1, q/2]), count(r/3).
will set up ``count-points'' on the predicates p/1, q/2 and r/3.
Predicates whose calls are to be timed have to be passed to time/1, e.g.
| ?– time([s/1, t/2]), time(u/3).
will set up ``time-points'' on the predicates s/1, t/2 and u/3.
It is possible to set both count-points and time-points on the same predicate.
After count-points and time-points have been set,
the program may be executed as many times as desired: the profiling system will
accumulate call counts and execution times for the appropriate predicates.
Execution profiles may be obtained using the
predicates prof_stats/0 or prof_stats/1.
Using prof_stats/0 to display the execution profile will cause the call
counts and execution times of predicates being profiled to be reset to 0
(this may be avoided by using prof_stats/1).
It should be noted that in this context, the ``execution time'' for a predicate
is an estimate of the total time spent in the subtrees below calls to that
predicate (including failed subtrees): thus, the execution time figures may
be dilated slightly if the subtree below a timed predicate contains
predicates that are being profiled, because of the time taken for updating
the call counts and execution times.
For each predicate, the execution
time is displayed as the fraction of time spent, in computation in subtrees
under calls to that predicate, relative to the time elapsed from the last
time profiling was timed on or the last time profiling statistics were
taken, whichever was more recent.
Bugs: May behave bizarrely if a predicate being profiled contains cuts.
The following summarizes the library predicates supporting profiling:
- count(L)
- count/1 (L)
Sets up a count-point on the predicates L, which causes calls to
these predicates to be counted, and turns profiling on.
L is either
a term Pred/Arity, where Pred is a predicate
symbol and Arity its arity,
or a set of such terms represented as a list.
L must be instantiated, and the predicates specified in it defined, at
the time of the call to count/1.
- time(L)
- time/1 (L)
Sets up a time-point on the predicates L, which causes execution times
for calls to these predicates to be accumulated, and turns profiling on.
L is either a term Pred/Arity, where Pred is a predicate
symbol and Arity its arity,
or a set of such terms represented as a list.
L must be instantiated, and the predicates specified in it defined, at
the time of the call to time/1.
- nocount(L)
- nocount/1 (L)
Deletes the count-point on the predicates L.
L is either a term Pred/Arity, where Pred is a predicate
symbol and Arity its arity,
or a set of such terms represented as a list.
L must be instantiated, and the predicates specified in it defined, at
the time of the call to nocount/1.
- notime(L)
- notime/1 (L)
Deletes the time-point on the predicates L.
L is either a term Pred/Arity, where Pred is a predicate
symbol and Arity its arity, or a set of such terms represented as a
list.
L must be instantiated, and the predicates specified in it defined, at
the time of the call to time/1.
- profiling
- profiling/0 (L)
Displays information about whether profile mode is on or not, and lists
predicates that have count- and time-points set on them.
- prof_reset(L)
- prof_reset/1 (L)
Resets call counts and/or execution times for the predicates L.
L is either a term Pred/Arity, where Pred is
a predicate symbol and Arity its arity, or a set of such terms
represented as a list.
L must be instantiated, and the predicates specified in it defined,
at the time of the call to prof_reset/1.
- resetcount(L)
- resetcount/1 (L)
Resets call counts for the predicates L.
L is either a term Pred/Arity, where Pred is
a predicate symbol and Arity its arity, or a set of such terms
represented as a list.
L must be instantiated, and the predicates specified in it defined,
at the time of the call to resetcount/1.
- resettime(L)
- resettime/1 (L)
Resets execution times for the predicates L.
L is either a term Pred/Arity, where Pred is
a predicate symbol and Arity its arity, or a set of such terms
represented as a list.
L must be instantiated, and the predicates specified in it defined,
at the time of the call to resettime/1.
- profile
- profile/0 (L)
Turns profiling on.
This causes subsequent execution of predicates with count- or time-points
to be profiled, and is a no-op if there are no such predicates.
The predicates count/1 and time/1 cause profiling
to be turned on automatically.
- noprofile
- noprofile/0 (L)
Turns profiling off.
This causes count- and time-points to be ignored.
- timepreds(L)
- timepreds/1 (L)
Unifies L to a list of terms P/N where the predicate P of arity N
has a time point set on it.
- countpreds(L)
- countpreds/1 (L)
Unifies L to a list of terms P/N where the predicate P of arity N
has a count point set on it.
- prof_stats
- prof_stats/0 (L)
Causes the call counts and/or execution times accumulated
since the last call to prof_stats/0 to be printed out for predicates
that are being profiled.
The execution times are given as fractions of the total
time elapsed since the last time profiling was turned on,
or the last time prof_stats was called, whichever was most recent.
This also results in the call counts and relative execution times of these
predicates being reset to 0.
Equivalent to prof_stats(1).
- prof_stats(N)
- prof_stats/1 (L)
Causes the call counts and/or execution times accumulated since
the last call to prof_stats/0 to be printed out for predicates
that are being profiled.
The execution times are given as fractions of the total time elapsed since
the last time profiling was turned on, or the last time prof_stats
was called, whichever was most recent.
If N is 1, then this also results in the call counts and execution times
of these predicates being reset to 0;
otherwise, the call counts and execution times are not reset.