The profiling tool can be used any time with any compiled Prolog code, it is not necessary to use a special compilation mode or set any flags. When
:- profile(Goal).is called, the profiler executes the Goal in the profiling mode, which means that every 0.01s the execution is interrupted and the profiler remembers the currently executing procedure. When the goal succeeds or fails, the profiler prints so and then it prints the statistics about the time spent in every encountered procedure:
[eclipse 5]: profile(boyer).
rewriting...
proving...
goal succeeded
PROFILING STATISTICS
--------------------
Goal: boyer
Total user time: 10.65s
Predicate Module %Time Time
-------------------------------------------------
rewrite /2 eclipse 52.3% 5.57s
garbage_collect /0 sepia_kernel 23.1% 2.46s
rewrite_args /2 eclipse 16.6% 1.77s
equal /2 eclipse 4.7% 0.50s
remainder /3 eclipse 1.5% 0.16s
..
plus /3 eclipse 0.1% 0.01s
yes.
The profiler prints the predicate name and arity, its definition module, percentage of total time spent in this predicate and the absolute time. Some of auxiliary system predicates are printed under a common name without arity, e.g. arithmetic or all_solutions. Predicates which are local to locked modules are printed together on on eline that contains only the module name. By default only predicates written in Prolog are profiled, i.e. if a Prolog predicate calls an external or built-in predicate written in C, the time will be assigned to the Prolog predicate.
The predicate profile(Goal, Flags) can be used to change the way profiling is made, Flags is a list of flags. Currently only the flag simple is accepted and it causes separate profiling of simple predicates, i.e. those written in C:
[eclipse 6]: profile(boyer, [simple]).
rewriting...
proving...
goal succeeded
PROFILING STATISTICS
--------------------
Goal: boyer
Total user time: 10.55s
Predicate Module %Time Time
-------------------------------------------------
=.. /2 sepia_kernel 31.1% 3.28s
garbage_collect /0 sepia_kernel 23.5% 2.48s
rewrite /2 eclipse 21.6% 2.28s
rewrite_args /2 eclipse 17.2% 1.82s
equal /2 eclipse 4.1% 0.43s
remainder /3 eclipse 0.9% 0.10s
..
plus /3 eclipse 0.1% 0.01s
yes.