4

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
repeat
  • 18,496
  • 4
  • 54
  • 166
Ans Piter
  • 573
  • 1
  • 5
  • 17

3 Answers3

11

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.

danielp
  • 1,179
  • 11
  • 26
  • 1
    thank you, also for `time_out` ,I know but i thought that it is possible when i put a variable it would loaded by suitable time ., regard to `statistics/2`, i add `format('go/2 took ~3d sec.~n', [Runtime]).` to obtain a nice outcome ; `| go/2 took 0.015 sec. ` Instead of `Time=15` – Ans Piter Jan 24 '16 at 10:50
5

I'd like to add two thoughts:

  1. Prolog allows for backtracking, so goals may succeed more than once.

    What's the "runtime" you are interested in?

    • Only the work for computing the previous answer?
    • Or rather the total time?

  2. Use statistics/2, but don't do it directly. Instead, use an abstraction like call_time/2.

Sample query:

?- call_time((permutation([a,b,c,d,e,f,g,h,i],Xs),Xs=[_,_,g,f,e,d,c,b,a]), T_ms).
   Xs = [h, i, g, f, e, d, c, b, a], T_ms = 304
;  Xs = [i, h, g, f, e, d, c, b, a], T_ms = 345
;  false.

Notice that call_time/2 succeeds twice and T_ms measures total runtime up to this point.

repeat
  • 18,496
  • 4
  • 54
  • 166
  • thanks, although I found only these built-in predicates in _SICStus-prolog_; `call/[1..255], callable/1, call_cleanup/2, call_residue_vars/2` – Ans Piter Jan 26 '16 at 19:07
  • `call_time` is based on `call` and `statistics`. I embedded 3 links above. Follow the white rabbit... – repeat Jan 26 '16 at 19:20
  • exactly what I do, `go(In,Out) :- statistics(runtime,[Start|_]), pred(In,Out), statistics(runtime,[Stop|_]), Runtime is Stop - Start, format('go/2 took ~3d sec.~n', [Runtime]).` – Ans Piter Jan 26 '16 at 19:37
  • @AnsPiter. Kind of, but `call_time/2` is somewhat more versatile: (1) It keeps code for time measurement and code for I/O separate. (2) And, being a [tag:meta-predicate], it can be used with arbitrary goals having any numbers of arguments. – repeat Jan 26 '16 at 20:08
  • 1
    in SWI, I had to call `use_module(library(statistics)).` at the REPL first. :) – Will Ness Jan 21 '20 at 07:42
  • @WillNess. Really? I was under the impression that `statistics/2` is in module `system`, at least it is with version 7.6.4... which version are you referring to? – repeat Jan 21 '20 at 19:40
  • @WillNess. It seems to be a 'builtin' predicate in SICStus and GNU Prolog, too... YMMV:) – repeat Jan 22 '20 at 05:36
2

Since nobody mentioned it, if you only want a time display the time/1 predicate can be also useful. It is already supported by a couple of Prolog systems such as SWI-Prolog, Jekejeke Prolog, O-Prolog, etc...:

Welcome to SWI-Prolog (threaded, 64 bits, version 7.7.19)

?- time((between(1,10000000,_), fail; true)).
% 10,000,001 inferences, 0.453 CPU in 0.468 seconds (97% CPU, 22068968 Lips)
true.

Unfortunately Prolog systems such as GNU Prolog, SICStus Prolog dont support it. But its the analog of the Unix time command, in that it is a meta predicate that takes a goal argument. Better than stone age methods.

  • This can be found in the [statistics](https://www.swi-prolog.org/pldoc/man?section=statistics) grabbag. Time should really have a version which unifies the actual data with variables. Why~~~ – David Tonhofer Jan 15 '20 at 17:36
  • You mean like ms/2 from LPA Prolog? –  Jan 16 '20 at 23:40