views:

384

answers:

4

I have an experimental library whose performance I'm trying to measure. To do this, I've written the following:

struct timeval begin;
gettimeofday(&begin, NULL);
{
    // Experiment!
}
struct timeval end;
gettimeofday(&end, NULL);

// Print the time it took!
std::cout << "Time: " << 100000 * (end.tv_sec - begin.tv_sec) + (end.tv_usec - begin.tv_usec) << std::endl;

Occasionally, my results include negative timings, some of which are nonsensical. For instance:

Time: 226762
Time: 220222
Time: 210883
Time: -688976

What's going on?

+5  A: 

You've got a typo. Corrected last line (note the number of 0s):

std::cout << "Time: " << 1000000 * (end.tv_sec - begin.tv_sec) + (end.tv_usec - begin.tv_usec) << std::endl;

BTW, timersub is a built in method to get the difference between two timevals.

Michael Ulm
Damn, that is embarrassing. :)
Andres Jaan Tack
+3  A: 

std::cout << "Time: " << 100000 * (end.tv_sec - begin.tv_sec) + (end.tv_usec - begin.tv_usec) << std::endl;

As noted, there are 1000000 usec in a sec, not 100000.

More generally, you may need to be aware of the instability of timing on computers. Processes such as ntpd can change clock times, leading to incorrect delta times. You might be interested in POSIX facilities such as timer_create.

ariels
And the insidious thing about ntpd is that it does it in small steps spread out over time, so it's harder to notice.
Mike DeSimone
A: 

do

$ time ./proxy-application

next time

Noone
That doesn't let me time the experiment itself. All of: memory allocator initialization, static object construction, and loading of the program are included.Also, that's only at seconds granularity.
Andres Jaan Tack
+2  A: 

The posix realtime libraries are better suited for measurement of high accuracy intervals. You really don't want to know the current time. You just want to know how long it has been between two points. That is what the monotonic clock is for.

struct timespec begin;
clock_gettime( CLOCK_MONOTONIC, &begin );
{
    // Experiment!
}
struct timespec end;
clock_gettime(CLOCK_MONOTONIC, &end );

// Print the time it took!
std::cout << "Time: " << double(end.tv_sec - begin.tv_sec) + (end.tv_nsec - begin.tv_nsec)/1000000000.0 << std::endl;

When you link you need to add -lrt.

Using the monotonic clock has several advantages. It often uses the hardware timers (Hz crystal or whatever), so it is often a faster call than gettimeofday(). Also monotonic timers are guaranteed to never go backwards even if ntpd or a user is goofing with the system time.

caspin
I forgot about that stuff! Mac OS doesn't implement the POSIX realtime libraries. You're totally right, though.
Andres Jaan Tack