vendredi 27 novembre 2015

Measuring execution time - gettimeofday versus clock() versus chrono

I have a subroutine that should be executed once every milisecond. I wanted to check that indeed that's what's happening. But I get different execution times from different functions. I've been trying to understand the differences between these functions (there are several SO questions about the subject) but I cannot get my head around the results I got. Please forget the global variables etc. This is a legacy code, written in C, ported to C++, which I'm trying to improve, so is messy.

< header stuff>
std::chrono::high_resolution_clock::time_point tchrono;
int64_t tgettime;
float tclock;

void myfunction(){

<all kinds of calculations>

  std::chrono::high_resolution_clock::time_point tmpchrono = std::chrono::high_resolution_clock::now();
  std::chrono::duration<double> time_span = std::chrono::duration_cast<std::chrono::milliseconds>(tmpchrono-tchrono);
  printf("chrono: %f (ms)\n",time_span);
  tchrono = tmpchrono;

  struct timeval tv;
  gettimeofday (&tv, NULL);
  int64_t tmpgettime = (int64_t) tv.tv_sec * 1000000 + tv.tv_usec;
  printf("gettimeofday: %lld\n",tmpgettime-tgettime);
  tgettime = tmpgettime;


  float tmpclock = 1000.0f*((float)clock())/CLOCKS_PER_SEC;
  printf("clock %f (ms)\n",tmpclock-tclock);
  tclock = tmpclock;

  <more stuff>
}

and the output is:

chrono: 0.000000 (ms)
gettimeofday: 998
clock 0.014038 (ms)
chrono: 0.000000 (ms)
gettimeofday: 999
clock 0.014954 (ms)
chrono: 0.000000 (ms)
gettimeofday: 999
clock 0.014038 (ms)
chrono: 0.000000 (ms)
gettimeofday: 999
clock 0.013977 (ms)
chrono: 0.000000 (ms)
gettimeofday: 999
clock 0.015015 (ms)
chrono: 0.000000 (ms)
gettimeofday: 999
clock 0.013977 (ms)
chrono: 0.000000 (ms)
gettimeofday: 999
clock 0.014038 (ms)
chrono: 0.000000 (ms)
gettimeofday: 999
clock 0.014954 (ms)

Why the difference? std::chrono::high_resolution_clock::now() is not even working... what am I missing?

Aucun commentaire:

Enregistrer un commentaire