3.41 Finding Performance Bottlenecks

SWI-Prolog offers a statistical program profiler similar to Unix prof(1) for C and some other languages. A profiler is used as an aid to find performance pigs in programs. It provides information on the time spent in the various Prolog predicates.

The profiler is based on the assumption that if we monitor the functions on the execution stack on time intervals not correlated to the program's execution the number of times we find a procedure on the environment stack is a measure of the time spent in this procedure. It is implemented by calling a procedure each time slice Prolog is active. This procedure scans the local stack and either just counts the procedure on top of this stack (plain profiling) or all procedures on the stack (cumulative profiling). To get accurate results each procedure one is interested in should have a reasonable number of counts. Typically a minute runtime will suffice to get a rough overview of the most expensive procedures.

profile(+Goal, +Style, +Number)

Execute Goal just like time/1. Collect profiling statistics according to style (see profiler/2) and show the top Number procedures on the current output stream (see show_profile/1). The results are kept in the database until reset_profiler/0 or profile/3 is called and can be displayed again with show_profile/1. profile/3 is the normal way to invoke the profiler. The predicates below are low-level predicates that can be used for special cases.

show_profile(+Number)

Show the collected results of the profiler. Stops the profiler first to avoid interference from show_profile/1. It shows the top Number predicates according the percentage CPU-time used. (19)

profiler(-Old, +New)

Query or change the status of the profiler. The status is one of off, plain or cumulative. plain implies the time used by children of a predicate is not added to the time of the predicate. For status cumulative the time of children is added (except for recursive calls). Cumulative profiling implies the stack is scanned up to the top on each time slice to find all active predicates. This implies the overhead grows with the number of active frames on the stack. Cumulative profiling starts debugging mode to disable tail recursion optimisation, which would otherwise remove the necessary parent environments. Switching status from plain to cumulative resets the profiler. Switching to and from status off does not reset the collected statistics, thus allowing to suspend profiling for certain parts of the program.

reset_profiler

Switches the profiler to off and clears all collected statistics.

profile_count(+Head, -Calls, -Promilage)

Obtain profile statistics of the predicate specified by Head. Head is an atom for predicates with arity 0 or a term with the same name and arity as the predicate required (see current_predicate/2). Calls is unified with the number of `calls' and `redos' while the profiler was active. Promilage is unified with the relative number of counts the predicate was active (cumulative) or on top of the stack (plain). Promilage is an integer between 0 and 1000.