timer - C, clock_gettime, returned incorrect nanosecond value?

Question

I'm writing a simple program, which checks if elapsed time is more than 1 seconds. I take start time with a clock_gettime(), then I call sleep(5), take new time and I check if the difference is bigger than 1; I sleep 5 seconds, then it should be greater than 5, but my program prints a strange result.

this is the code:

#include <stdio.h>
#include <stdlib.h>
#include <time.h>
#include <unistd.h>

int main()
{
    struct timespec tv1,tv3,expected;
    struct timespec nano1;

    tv1.tv_nsec = 0;
    tv3.tv_nsec = 0;

    expected.tv_nsec = 400000;

    if(clock_gettime(CLOCK_MONOTONIC,&tv3) == -1){
        perror(NULL);
    }

    sleep(5);

    if(clock_gettime(CLOCK_MONOTONIC,&tv1) == -1){
        perror(NULL);
    }


    long nsec = tv1.tv_nsec - tv3.tv_nsec;

    if(nsec>expected.tv_nsec){
        printf("nsec runned: %ld   nsec timeout: %ld
",nsec,expected.tv_nsec);
    }


    printf("elapsed nanoseconds: %ld
",nsec);


    if((nsec>expected.tv_nsec))
        printf("expired timer
");

    else
        printf("not expired timer
");

    exit(EXIT_SUCCESS);
}

Output of my program is:

"elapsed nanoseconds: 145130" and "not expired timeout"

Where is the problem?

Answer 1

The time represented in a struct timespec has two components:

• tv_sec — a time_t value for the integer number of seconds.
• tv_nsec — a 32-bit integer for the number of nanoseconds, 0..999,999,999

Your calculation didn't take into account the difference between the tv_sec values. It is somewhat surprising that the difference between the nanosecond values was as large as you say, but far from impossible. To get the whole difference, you need to take into account both the tv_sec and the tv_nsec components.

sub_timespec()

You can subtract two values (to get the difference) using a function like:

enum { NS_PER_SECOND = 1000000000 };

void sub_timespec(struct timespec t1, struct timespec t2, struct timespec *td)
{
    td->tv_nsec = t2.tv_nsec - t1.tv_nsec;
    td->tv_sec  = t2.tv_sec - t1.tv_sec;
    if (td->tv_sec > 0 && td->tv_nsec < 0)
    {
        td->tv_nsec += NS_PER_SECOND;
        td->tv_sec--;
    }
    else if (td->tv_sec < 0 && td->tv_nsec > 0)
    {
        td->tv_nsec -= NS_PER_SECOND;
        td->tv_sec++;
    }
}

fmt_timespec

You can format it as a floating-point value with the specified number of decimal places using a function like this:

int fmt_timespec(const struct timespec *value, int dp, char *buffer, size_t buflen)
{
    assert(value != 0 && buffer != 0 && buflen != 0);
    if (value == 0 || buffer == 0 || buflen == 0)
    {
        errno = EINVAL;
        return -1;
    }
    assert(dp >= 0 && dp <= 9);
    if (dp < 0 || dp > 9)
    {
        errno = EINVAL;
        return -1;
    }
    if ((value->tv_sec > 0 && value->tv_nsec < 0) ||
        (value->tv_sec < 0 && value->tv_nsec > 0))
    {
        /* Non-zero components of struct timespec must have same sign */
        errno = EINVAL;
        return -1;
    }

    int len;
    if (dp == 0)
        len = snprintf(buffer, buflen, "%ld", value->tv_sec);
    else
    {
        long nsec = value->tv_nsec;
        long secs = value->tv_sec;
        const char *sign = (secs < 0 || (secs == 0 && nsec < 0)) ? "-" : "";
        if (secs < 0)
            secs = -secs;
        if (nsec < 0)
            nsec = -nsec;
        for (int i = 0; i < 9 - dp; i++)
            nsec /= 10;
        len = snprintf(buffer, buflen, "%s%ld.%.*ld", sign, secs, dp, nsec);
    }
    if (len > 0 && (size_t)len < buflen)
        return len;
    errno = EINVAL;
    return -1;
}

---

Revised version of code in question

The header time_io.h declares the format and scanning functions for struct timespec; the time_math.h header declares the functions for adding and subtracting struct timespec values. It is probably over-compartmenting the code to have that many headers.

#include "time_io.h"
#include "time_math.h"
#include <inttypes.h>
#include <stdio.h>
#include <stdlib.h>
#include <time.h>
#include <unistd.h>

enum { NS_PER_SECOND = 1000000000 };

int main(void)
{
    struct timespec tv3;
    if (clock_gettime(CLOCK_MONOTONIC, &tv3) == -1)
        perror("clock_gettime()");

    sleep(5);

    struct timespec tv1;
    if (clock_gettime(CLOCK_MONOTONIC, &tv1) == -1)
        perror("clock_gettime()");

    struct timespec td;
    sub_timespec(tv3, tv1, &td);

    int64_t ts_in_ns = td.tv_sec * NS_PER_SECOND + td.tv_nsec;

    char buffer[32];
    fmt_timespec(&td, 9, buffer, sizeof(buffer));

    printf("Elapsed time: %s (%" PRId64 " nanoseconds)
", buffer, ts_in_ns);

    return 0;
}

Example run:

Elapsed time: 5.005192000 (5005192000 nanoseconds)

On a Mac running macOS Sierra 10.12.6 (which finally has clock_gettime() — earlier versions of Mac OS X did not support it), the resolution of clock_gettime() is 1000 nanoseconds, effectively microseconds. So, the last 3 decimal places are always zeros on a Mac.

add_timespec()

For completeness, you can add two struct timespec values with:

void add_timespec(struct timespec t1, struct timespec t2, struct timespec *td)
{
    td->tv_nsec = t2.tv_nsec + t1.tv_nsec;
    td->tv_sec  = t2.tv_sec + t1.tv_sec;
    if (td->tv_nsec >= NS_PER_SECOND)
    {
        td->tv_nsec -= NS_PER_SECOND;
        td->tv_sec++;
    }
    else if (td->tv_nsec <= -NS_PER_SECOND)
    {
        td->tv_nsec += NS_PER_SECOND;
        td->tv_sec--;
    }
}

scn_timespec()

And the 'scanning' process is messier (input often is messier than output):

int scn_timespec(const char *str, struct timespec *value)
{
    assert(str != 0 && value != 0);
    if (str == 0 || value == 0)
    {
        errno = EINVAL;
        return -1;
    }
    long sec;
    long nsec = 0;
    int sign = +1;
    char *end;
    /* No library routine sets errno to 0 - but this one needs to */
    int old_errno = errno;

    errno = 0;

    /* Skip leading white space */
    while (isspace((unsigned char)*str))
        str++;

    /* Detect optional sign */
    if (*str == '+')
        str++;
    else if (*str == '-')
    {
        sign = -1;
        str++;
    }

    /* Next character must be a digit */
    if (!isdigit((unsigned char)*str))
    {
        errno = EINVAL;
        return -1;
    }

    /* Convert seconds part of string */
    sec = strtol(str, &end, 10);
    if (end == str || ((sec == LONG_MAX || sec == LONG_MIN) && errno == ERANGE))
    {
        errno = EINVAL;
        return -1;
    }

    if (*end != '' && !isspace((unsigned char)*end))
    {
        if (*end++ != '.')
        {
            errno = EINVAL;
            return -1;
        }
        if (*end == '')
            nsec = 0;
        else if (isdigit((unsigned char)*end))
        {
            char *frac = end;
            nsec = strtol(frac, &end, 10);
            if (end == str ||
                ((nsec == LONG_MAX || nsec == LONG_MIN) && errno == ERANGE) ||
                (nsec < 0 || nsec >= NS_PER_SECOND) || (end - frac > 9))
            {
                errno = EINVAL;
                return -1;
            }
            for (int i = 0; i < 9 - (end - frac); i++)
                nsec *= 10;
        }
    }

    /* Allow trailing white space - only */
    unsigned char uc;
    while ((uc = (unsigned char)*end++) != '')
    {
        if (!isspace(uc))
        {
            errno = EINVAL;
            return -1;
        }
    }

    /* Success! */
    value->tv_sec = sec * sign;
    value->tv_nsec = nsec * sign;
    errno = old_errno;
    return 0;
}