1

i am measuring physical time between two events like this:

#include <time.h>
#include <sys/time.h>

timeval wall_time0;
timeval wall_time1;

// start of period measurement
gettimeofday( &wall_time0 , 0);

...stuff happening 

// end of period measurement
gettimeofday( &wall_time1 , 0);

return ( ( wall_time1.tv_sec - wall_time0.tv_sec ) + (( wall_time1.tv_usec - wall_time0.tv_usec )/(double)1000000) );

But now, i need a way to measure the logical time that the thread is actually using. That is, in theory that should be the physical time, less the time spent running other threads and/or system & kernel logic.

I thought this was the way to do it:

clock_t mTime0;
clock_t mTime1;

//start of period measurement
mTime0=clock();

... stuff happening


//end of period measurement
mTime1=clock();
return (mTime1-mTime0)/(double)CLOCKS_PER_SEC;

but doing a few measurements, i noticed two problems:

1) for some measurements it is bigger than physical time, which is not right (i.e: for certain loop, physical time would be 0.2495.. and "logical" (measured with clock()) would be 0.27, for smaller measurements it would just round up to zero, which leads to the second issue...)

2) the resulting time seems to be a lot coarser than the one return by gettimeofday

is there a better way to measure local thread time in linux?

lurscher
  • 25,930
  • 29
  • 122
  • 185

3 Answers3

3

There are some higher precision options you could use -- look at sys/timex.h. Also Boost Date.Time for example has millisecond and higher precision timers.

As for 'total time > physical elapsed time', I do have seen that in multi-threaded timing. That is simply an 'accounting' thingie: all cpu 'consumption' is added and could well be more than elapsed time in multithreaded code if all threads do work, some scheduling overheads gets added and presto you have more than elapsed time.

Dirk Eddelbuettel
  • 360,940
  • 56
  • 644
  • 725
  • interesting, however the test program i'm using is single-threaded... or so i think. i'm currently linking only against unittest-cpp, so maybe the library creates a thread somewhere – lurscher Oct 25 '10 at 16:02
  • using getrusage i now get a process time which is consistently lower than physical time - the clock result definitely looks weird – lurscher Oct 26 '10 at 13:02
  • Yes, but on a multi-tasking OS some other things are happening and need to be accounted for. Couldn't that be part of the difference between 'your' time and total time? – Dirk Eddelbuettel Oct 26 '10 at 13:49
2

The tv_usec field of struct timeval is in microseconds, not in units of 1/(double)CLOCKS_PER_SEC.

Edgar Bonet
  • 3,416
  • 15
  • 18
0

Ok after a bit of researching i found out that getrusage fills both needs mentioned:

getrusage man page

so basically the required code is very similar to how i measure physical time with gettimeofday, only that now i use getrusage

#include <time.h>
#include <sys/time.h>
#include <sys/resource.h>

timeval processed_time0;
timeval processed_time1;
rusage paramStruct
// start of period measurement
int result = getrusage( &paramStruct);
processed_time0 = paramStruct.ru_utime;

...stuff happening 

// end of period measurement
int result = getrusage( &paramStruct );
processed_time1 = paramStruct.ru_utime;

return ( ( processed_time1.tv_sec - processed_time0.tv_sec ) + (( processed_time1.tv_usec - processed_time0.tv_usec )/(double)1000000) );

this way gives me both

1) current process consumed time

2) microsecond resolution

I investigated Boost Date.Time, but in the documentation there is nothing mentioning process or user versus system time, i think the library is just concerned with measuring physical time

lurscher
  • 25,930
  • 29
  • 122
  • 185
  • it seems that this solution is not complete either; apparently the result from rusage will not have a new value until a while (my guess is that it will not get a new value until the next context swap reentry). If that assumption is valid means that one has to implement a hackaround, store physical time each time logical time changes, then as long as reported logical time doesn't change one has to add the physical time delta since the last change. And probably neither this is entirely accurate since i don't know how far before last context swap. Time to take this to the linux mailing list – lurscher Oct 26 '10 at 18:31
  • i also tried with `clock_gettime`, and the result is something intermediate between the results of `getrusage` and the results of `gettimeofday`, and since we are ultimately after a reliable benchmark metric, i'm not convinced of any option being better than the other yet... http://www.guyrutenberg.com/2007/09/22/profiling-code-using-clock_gettime/ – lurscher Oct 30 '10 at 21:37