Strange behavior of time/1 - bug?

Help!
1

I’m using SWI-Prolog 8.0.3. When benchmarking code wuth time/1, I get strange results. For demonstration purpose, I use good old naive Fibonacci.

fib(0, 1) :- !.
fib(1, 1) :- !.
fib(N, F) :-
        N > 1,
        N1 is N-1,
        N2 is N-2,
        fib(N1, F1),
        fib(N2, F2),
        F is F1+F2.

Now I try to see how long it takes.

?- time(fib(20,F)).

gives me

% 43,782 inferences, 0.000 CPU in 17170420255948800.000 seconds (0% CPU, Infinite Lips)
F = 10946.

And it sure didn’t take as long… Worse:

?- time(fib(30,F)).

gives

% 5,385,073 inferences, 0.656 CPU in -1404464184216781100.000 seconds (?% CPU, 8205826 Lips)
F = 1346269.

And that looks like an integer overflow of sorts. So, how to make sense of these numbers?

On a not entirely unrelated issue - is there space/1, too? :slight_smile:

cheers
Harald

2

What OS? An issue was found in the 32 bits windows version. Try the latest developments version of this might apply.

3

Hi Jan,

my original post referred to a W10 Home on a Dell Latitude.

I just downloaded the latest nightly build as per your suggestion (swipl-w64-2019-12-22.exe) and installed it on a Surface Go, W10 Pro.

And ta-dah, time/1 reports reasonable times.

?- time(fib(30,F)).
% 5,385,072 inferences, 1.078 CPU in 1.111 seconds (97% CPU, 4994849 Lips)
F = 1346269.

I must say, though, that ms as the unit of measurement is a bit coarse. I’d prefer an option to go down to ns, if need be, see example below.

?- time(fib(15,F)).
% 3,944 inferences, 0.000 CPU in 0.000 seconds (?% CPU, Infinite Lips)
F = 987.
?- time(fib(16,F)).
% 6,384 inferences, 0.000 CPU in 0.001 seconds (0% CPU, Infinite Lips)
F = 1597.
?- time(fib(20,F)).
% 43,781 inferences, 0.016 CPU in 0.024 seconds (66% CPU, 2801984 Lips)
F = 10946.
?- time(fib(30,F)).
% 5,385,072 inferences, 1.078 CPU in 1.111 seconds (97% CPU, 4994849 Lips)
F = 1346269.
?- time(fib(40,F)).
% 662,320,560 inferences, 126.125 CPU in 137.728 seconds (92% CPU, 5251303 Lips)
F = 165580141.

cheers
Harald

4

The ms is due to what is printed by time/1. Actual resolution of the timing functions depends on the OS. AFAIK, the Windows version uses the MinGW emulation for getimeofday(). This API is microseconds. Feel free to propose better alternatives for the low-level timing functions. You find them in src/os/pl-os.c.

It seems most OSes nowadays provide better resolution, so we could change the format specifier in time/1.