I want to see the execution time inside goals of predicate with SICStus Prolog.
Example :
pred :-
goal1,
time,
goal2,
time.
go :-
call(pred).
time_go :-
go,
times(go).
Expected result:
?- time_go.
times_go = 1000ms ,
times_go_goal1 = 500ms,
times_go_goal2 = 500ms
How to do that ?
I tried time_out(:Goal, +Time, -Result) from library(timeout) but I got this error:
| ?- time_out(char_code(a,N), T, Res).
! Instantiation error in argument 2 of user:time_out/3
! goal: time_out(user:char_code(a,_193),_179,_181)
| ?- time_out(char_code(a,N), 1000, Res).
N = 97,
Res = success ? ; % Res=timeout in other example
You can use statistics/2 for that:
statistics(runtime,[Start|_]),
do_something,
statistics(runtime,[Stop|_]),
Runtime is Stop - Start.
Alternatively, you can use total_runtime instead of runtime if you want to include time for garbage collection. Start and Stop are measured in milliseconds, but the last time I used it with SICStus it returned only multiple of 10. In a project we used calls to a custom external C library to retrieve a finer resolution.
A remark to time_out/3: It is used to limit the runtime of a goal, not to measure its runtime. If the goal finishes in time, the result is success, if it needs more time the execution is aborted (internally a timeout exception is thrown) and the result is timeout.