clock_gettime returns some extrange values

Question

I'm trying to profile a program with this class:

namespace smtx{
    class CPerformance_clock
    {
        timespec t1;

        timespec diff(timespec start, timespec end)
        {
            timespec temp;
            if ((end.tv_nsec-start.tv_nsec)<0) {
                temp.tv_sec = end.tv_sec-start.tv_sec-1;
                temp.tv_nsec = 1000000000+end.tv_nsec-start.tv_nsec;
            } else {
                temp.tv_sec = end.tv_sec-start.tv_sec;
                temp.tv_nsec = end.tv_nsec-start.tv_nsec;
            }
            return temp;
        }

    public :
        CPerformance_clock(){}
        /**
         * Starts the clock by taking the initial measure
         */
        void start()
        {
            assert(clock_gettime(CLOCK_MONOTONIC_RAW,&t1) == 0);
        }
        long int getElapsedTime()
        {
            timespec t2, final;
            assert (clock_gettime(CLOCK_MONOTONIC_RAW,&t2) == 0);
            final = diff(t1, t2);
            return (final.tv_sec * 1000000000) + final.tv_nsec;

        }

        void restart()
        {
            clock_gettime(CLOCK_REALTIME,&t1);
        }
    };
};

I control min, max and average time, with this code

if(t > max_time)
{
    max_time = t;
}
if(t < min_time)
{
    min_time = t;
}
++count_time;
sum_time += t;
chunk_sum_time +=t;
++chunk_count_time;

Nothing extraordinary at all. But when I execute the program, the max time allways have a extrange time value: Min time: 831 ns at 40784 , Max_time: 9773850 ns at 1123 The max time is far long that the total execution time, so I don't understand this. I do not make any conversion o division in the process of display data, to don't lose data.

I've readed this post, Linux clock_gettime(CLOCK_MONOTONIC) strange non-monotonic behavior , but my kernel is newest, though is an ubuntu too.

To finish, I made test with CLOCK_MONOTONIC, CLOCK_REALTIME, CLOCK_MONOTONIC_RAW, and nothing solves this issue.

Also, I'm not sure that this matters but I'm programming and executing this program on a virtual machine.

Some help?

EDIT: To put an example of my problem: I process 4.000.000 of results in about 60 seconds. The average time of each result is 4000 nano seconds. An strange error could be 14 seconds, but the program run smooth and in any moment stops for 14 seconds.

In executions of 500.000 results (execued in 3 seconds) I get similar MAX_TIMEs, like 9 seconds.

Thanks in advance

Answer 1

The fluctuation is caused by the OS scheduler. It pauses your process and gives a chance to an other process to run.

Can you report back results with CLOCK_PROCESS_CPUTIME_ID?