strange timing results for 'clock_gettime' and 'gettimeofday'

Question

I wanted to check the reliability of clock_gettime, using the deprecated gettimeofday as reference, but am getting strange results sometimes:

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

void clock_gettime_test()
{
    struct timespec tp;
    clock_gettime(CLOCK_MONOTONIC_RAW, &tp);
    long a = tp.tv_nsec;
    usleep(250000);
    clock_gettime(CLOCK_MONOTONIC_RAW, &tp);
    long b = tp.tv_nsec;
    printf("clock_gettime (%ld - %ld): %lf msec\n", b, a, (b - a)/1000000.0);
}

void gettimeofday_test()
{
    struct timeval tv;
    gettimeofday(&tv, NULL);
    long a = tv.tv_usec;
    usleep(250000);
    gettimeofday(&tv, NULL);
    long b = tv.tv_usec;
    printf("gettimeofday (%ld - %ld): %lf msec\n", b, a, (b - a)/1000.0);
}

int main()
{
    clock_gettime_test();
    gettimeofday_test();
    return 0;
}

Building and running, I sometimes get the right results:

$ g++ -Wall play.cpp -lrt && ./a.out
clock_gettime (392441961 - 142299879): 250.142082 msec
gettimeofday (592906 - 342644): 250.262000 msec

But sometimes, me not so lucky:

clock_gettime (155321165 - 905000848): -749.679683 msec
gettimeofday (352232 - 101938): 250.294000 msec

Or even:

clock_gettime (947857371 - 697373625): 250.483746 msec
gettimeofday (225208 - 974908): -749.700000 msec

I have tried this both on an i686 and an amd64, and get similar results. I also tried nanosleep, with the same sad results.

Answer 1

You're only comparing the tv_nsec member of struct timespec, while you should also be comparing the tv_sec member :

double msec = ((tpb.tv_sec - tpa.tv_sec) * 1000.0)
            + ((tpb.tv_nsec - tpa.tv_nsec) / 1000000.0);

Similarly, you should be comparing both the tv_sec and tv_usec members of struct timeval to get the elapsed time :

double msec = ((tvb.tv_sec - tva.tv_sec) * 1000.0)
            + ((tvb.tv_usec - tva.tv_usec) / 1000.0);

Answer 2

From Unix,C, and C++ function reference:

A timeval has two components, both ints. One (called tv_sec) is exactly the value that would be returned by time, the time in seconds since 1/1/1970. The other (called tv_usec) is the number of microseconds into that second.

So, tv_usec will be reset each second. That's why you get this result. Take into account the seconds, and you will probably have something like 1000 msec - 749.679683 msec ~ 250 msec.