Search code examples
linuxc++11timing

Difference between Linux time and Performance clocks in code


I was running a simple test for timing of some C++ code, and I ran across an artifact that I am not 100% positive about.

Setup

My code uses C++11 high_resolution_clock to measure elapsed time. I also wrap the execution of my program using Linux's time command (/usr/bin/time). For my program, the high_resolution_clock reports ~2s while time reports ~7s (~6.5s user and ~.5s system). Also using the verbose option on time shows that my program used 100% of the CPU with 1 voluntary context switch and 10 involuntary context switches (/usr/bin/time -v).

Question

My question is what causes such a dramatic difference between OS time measurements and performance time measurements?

My initial thoughts

Through my knowledge of operating systems, I am assuming these differences are solely caused by context switches with other programs (as noted by time -v).

Is this the only reason for this difference? And should I trust the time reported by my program or the system when looking at code performance?

Again, my assumption is to trust the computed time from my program over Linux's time, because it times more than just my program's CPU usage.

Caveats

  • I am not posting code, as it isn't really relevant to the issue at hand. If you wish to know it is a simple test that times 100,000,000 random floating point arithmetic operations.

  • I know other clocks in my C++ code might be more or less appropriate for difference circumstances (this stack overflow question). High_resolution_clock is just an example.

Edit: Code as requested

#include <chrono>
#include <cstdlib>
#include <iostream>
#include <vector>

using namespace std;
using namespace std::chrono;

int main() {
  size_t n = 100000000;

  double d = 1;

  auto start_hrc = high_resolution_clock::now();

  for(size_t i = 0; i < n; ++i) {
    switch(rand() % 4) {
      case 0: d += 0.0001; break;
      case 1: d -= 0.0001; break;
      case 2: d *= 0.0001; break;
      case 3: d /= 0.0001; break;
    }
  }

  auto end_hrc = high_resolution_clock::now();
  duration<double> diff_hrc = end_hrc - start_hrc;
  cout << d << endl << endl;
  cout << "Time-HRC: " << diff_hrc.count() << " s" << endl;
}

Solution

  • My question is what causes such a dramatic difference between OS time measurements and performance time measurements?

    It looks like your system takes a while to start your application. Probably a resource issue: not enough free memory (swapping) or oversubscribed CPU.

    No dramatic difference is observed on my desktop:

    Time-HRC: 1.39005 s
    real    0m1.391s
    user    0m1.387s
    sys     0m0.004s