How can I periodically call statistics/2 in SWI-Prolog?

Question

I'm trying to benchmark a (SWI-)Prolog program that may take several seconds to finish. I'd like to save CPU-time and memory statistics through time to then be able to show a sort of evolution plot. Something similar to the system monitor, but just with my program.

For that I tried using alarm/4:

stat_start(Id) :-
    alarm(0.25,stat_point,Id,[remove(false),install(true)]). % 250 milliseconds

stat_stop(Id) :-
    remove_alarm(Id).

stat_point :-
    stat_cpu, % calls statistics/2 and appends values to a CSV file
    stat_mem. % calls statistics/2 and appends values to a CSV file

I simply can't get proper timing between each stat_point. The timing varies from milliseconds to seconds and I can't do anything about it. And changing alarm/4's time does't make any difference. I also tried a simple query like:

?- alarm(1, write('hello\n'), Id, [remove(false),install(true)]),
   repeat,
   fail.

And it doesn't work either. I'm just getting a single "hello". I thought that a solution might be to insert calls to stat_point within my code, but it doesn't look rather elegant, does it? Besides, the points wouldn't be equally spaced.

Is there a proper way to monitor a Prolog program in a timed-fashion? Would profile/1 provide this kind of information somehow?

Answer 1

I've come to the conclusion that an alarm can't be configured to fire a predicate periodically, or at least not automatically. Although one of the options in alarm/4 is remove(false), one has to call uninstall_alarm/1 and install_alarm/1 in order to restart the time counter. Not doing so and not calling remove_alarm/1, will produce a resource leak, which will probably be protected somehow and might eventually stop the actual timer.

This would be the proper way to use periodic calls to predicates stat_mem/0 and stat_cpu/0:

stat_start(Id,T) :-
    alarm(T,stat_point(Id,T),Id,[remove(false),install(true)]).

stat_point(Id,T) :-
    uninstall_alarm(Id),
    install_alarm(Id,T),
    stat_mem, 
    stat_cpu.

Note that in this case a call to install_alarm/2 is needed instead of /1. If we don't do that, the time is set to 0 and the alarm will fire the predicate continuously.

Now, more related to the 'determinism' issue of my initial question, I just can say that although my stat_point inserts uncertainty to my time and (less likely) memory measurements, this uncertainty is ultimately determined by the statistics/2 predicate. Since CPU time is affected by this call, the solution suggested by magus --use a "primary standard" sample to find the offset of my measurements-- might be an approach toward reducing this uncertainty.

In fact, since the memory used and execution times were already far greater than those produced by repeated calls to statistics/2 the accuracy of my measurements is "relatively" small.

Answer 2

I don't have a concrete answer, but it might be worth stating which operating system you are using, since it might be the O.S. which is the source of the underlying problem (windows by any chance ?).

If all you are doing is measuring memory and cpu, and the measurements don't need to interrogate the insides of prolog at all (which sounds the case), then it's probably best done in the O.S. eg. in linux with a shell script using a loop with the sleep command.

It's more likely to be accurate, since you don't have the interference of the O.S. with prolog in any way - either with timing issues as prolog/os interact with each other to get the cpu/memory stats, or by by your stat point predicate actually affecting the cpu/memory prolog uses, which may colour your results.

You could then run the script without prolog/your program running as a 'control', and then again with prolog, and take the difference as being the impact of prolog/your program. Not very scientific / precise, but might be a way forward.