The time() function runs slow in Microsoft C++

Question

I discovered by accident that the C++ time() function runs slowly in programs compiled with Microsoft C++. Consider this example:

#include <iostream>
#include <ctime>

long long unsigned Fib(unsigned n)
{
  if (n <= 2)
    return 1;
  else
    return Fib(n-1) + Fib(n-2);
}

int main(int argc, char* argv[])
{
  time_t start_time = time(NULL);

  // Calculate the first 50 Fibonnaci numbers
  for (unsigned i = 1; i <= 50; i++)
    std::cout << i << "\t" << Fib(i) << "\t" << difftime(time(NULL), start_time) << std::endl;

// This takes 105 seconds to run, but the last line printed is:
// 50      12586269025     65

  return 0;
}

This prints:

1       1       0
2       1       0
...
49      7778742049      40
50      12586269025     65

so difftime(time(NULL), start_time) is telling me it takes 65 seconds to run, but when I time it with a stopwatch I find it actually takes 105 seconds.

The problem is that the time() function returns times that run slow. If I print time(NULL) directly instead of calling difftime() I can see that the times being printed are lagging behind the actual time. For example if I print time() instead of difftime() then when the program finishes I immediately rerun it I find the time jumps forward when I run the program again:

49      7778742049      1611148562
50      12586269025     1611148587

D:\rhs\c>test
1       1       1611148627
2       1       1611148627

Note how the value returned by time() jumped forward 40 seconds even though it took me only a second to rerun the program.

So my question is why does this happen and how do I fix it (apart from using a different compiler - I have no choice but to use MS C++)? I'm using Visual Studio 2019 so the version of the C++ compiler is Microsoft (R) C/C++ Optimizing Compiler Version 19.28.29335 for x86.

Ah, how embarrassing, it is indeed just order of evaluation in the cout statement. If I change the loop to:

  for (unsigned i = 1; i <= 50; i++)
  {
    long long unsigned u = Fib(i);
    double run_time = difftime(time(NULL), start_time);
    std::cout << i << "\t" << u << "\t" << run_time << std::endl;
  }

Then it prints the correct elapsed time. Thanks to all who commented. This can be closed as a duplicate.

Depending on whichever version of C++ one uses, the compiler could simply be generating the code to call `time()` ***before*** calling `Fib()`. — Sam Varshavchik, Jan 20 '21 at 13:23
While there's [standards - Order of evaluation in C++ function parameters - Stack Overflow](https://stackoverflow.com/questions/2934904/order-of-evaluation-in-c-function-parameters) , but it isn't an exact duplicate. — user202729, Jan 20 '21 at 13:25
[Order of evaluation of arguments using std::cout](https://stackoverflow.com/questions/7718508/order-of-evaluation-of-arguments-using-stdcout)? — Algirdas Preidžius, Jan 20 '21 at 13:25
if you want two things happen one after the other, why do you squeeze it in a single line? Just don't do that, it not only hurts readability — 463035818_is_not_an_ai, Jan 20 '21 at 13:25
@largest_prime_is_463035818 Actually, in this case not repeating `std::cout<<` is easier. Conclusion: don't use std::cout<< with side-effect-ful functions. — user202729, Jan 20 '21 at 13:27
Does this answer your question? [Order of evaluation of arguments using std::cout](https://stackoverflow.com/questions/7718508/order-of-evaluation-of-arguments-using-stdcout) — user202729, Jan 20 '21 at 13:28
Aha! It had not occurred to me it could simply be the order of evaluation. Give me a moment and I'll check it ... — John Rennie, Jan 20 '21 at 13:29

The time() function runs slow in Microsoft C++

0 Answers0