# Strange behavior of time/1 - bug?

**URL:** <https://swi-prolog.discourse.group/t/strange-behavior-of-time-1-bug/1642>\
**Category:** Help!\
**Created:** [December 20, 2019, 6:46pm UTC](https://swi-prolog.discourse.group/t/strange-behavior-of-time-1-bug/1642 "2019-12-20T18:46:17Z")\
**Posts on this page:** 4\
**Page:** 1

<div class="post-metadata">

**Author:** ![HSTO](https://avatars.discourse-cdn.com/v4/letter/h/ed8c4c/32.png) [@HSTO](https://swi-prolog.discourse.group/u/HSTO)\
**Post date:** [December 20, 2019, 6:46pm UTC](https://swi-prolog.discourse.group/t/strange-behavior-of-time-1-bug/1642/1 "2019-12-20T18:46:17Z")

</div>

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.

```prolog
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.

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

```

gives me

```prolog
% 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:

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

```

gives

```prolog
% 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? 🙂

cheers  
Harald

---

<div class="post-metadata">

**Author:** ![jan](https://yyz2.discourse-cdn.com/free1/user_avatar/swi-prolog.discourse.group/jan/32/4_2.png) [@jan](https://swi-prolog.discourse.group/u/jan)\
**Post date:** [December 20, 2019, 8:33pm UTC](https://swi-prolog.discourse.group/t/strange-behavior-of-time-1-bug/1642/2 "2019-12-20T20:33:51Z")

</div>

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

---

<div class="post-metadata">

**Author:** ![HSTO](https://avatars.discourse-cdn.com/v4/letter/h/ed8c4c/32.png) [@HSTO](https://swi-prolog.discourse.group/u/HSTO)\
**Post date:** [December 22, 2019, 11:41am UTC](https://swi-prolog.discourse.group/t/strange-behavior-of-time-1-bug/1642/3 "2019-12-22T11:41:01Z")

</div>

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.

```prolog
?- 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.

```prolog
?- 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

---

<div class="post-metadata">

**Author:** ![jan](https://yyz2.discourse-cdn.com/free1/user_avatar/swi-prolog.discourse.group/jan/32/4_2.png) [@jan](https://swi-prolog.discourse.group/u/jan)\
**Post date:** [December 23, 2019, 4:43pm UTC](https://swi-prolog.discourse.group/t/strange-behavior-of-time-1-bug/1642/4 "2019-12-23T16:43:11Z")

</div>

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.