3

As has been known for a while (see, e.g., this old question, and bug reports that pop when you google this), clock_gettime() doesn't appear to report back time monotonically. To rule out any silly error I might have overseen, here is the relevant code (excerpt from larger program): 

<include time.h>

long nano_1, nano_2;
double delta;
struct timespec tspec, *tspec_ptr;

clock_gettime(CLOCK_MONOTONIC_RAW, tspec_ptr);
nano_1 = tspec.tv_nsec;
sort_selection(sorted_ptr, n);
clock_gettime(CLOCK_MONOTONIC_RAW, tspec_ptr);
nano_2 = tspec.tv_nsec;  
delta = (nano_2 - nano_1)/1000000.0;
printf("\nSelection sort took %g micro seconds.\n", (double) delta);

Sorting small arrays (about 1,000 elements) reports plausible times. When I sort larger ones (10,000+) using 3 sort algorithms, 1-2 of the 3 report back negative sort time. I tried all clock types mentioned in the man page, not only CLOCK_MONOTONIC_RAW - no change.

(1) Anything I overlooked in my code?
(2) Is there an alternative to clock_gettime() that measures time in increments more accurate than seconds? I don't need nanonseconds, but seconds is too coarse to really help.

System:
- Ubuntu 12.04.
- kernel 3.2.0-30
- gcc 4.6.3.
- libc version 2.15
- compiled with -lrt

Community
  • 1
  • 1
gnometorule
  • 2,151
  • 2
  • 20
  • 29
  • How big is the delta when it happens? Is there something going on in the background that makes the clock "run true" (if it knows that the oscillator is slightly fast compared to network time, it could subtract a small amount from the time every now and then to adjust...). If ms accuracy is enough, could you use `clock()`? – Floris Dec 10 '13 at 00:17
  • @Floris: I've seen negative results typically in the negative several hundred microseconds. Nothing should be going on in the background, other than usual kernel processes; in any case, I wait for the results without starting any other program, and don't think I installed any software that would have fiddled with timer. If installing a particular software is known to bug clock_gettime() out, knowing which might help...although I doubt it as I don't install much other than libraries like gtk. – gnometorule Dec 10 '13 at 00:19
  • Some interesting information at http://stackoverflow.com/questions/12392278/measure-time-in-linux-getrusage-vs-clock-gettime-vs-clock-vs-gettimeofday - did you see it? – Floris Dec 10 '13 at 00:22
  • 3
    Your time calculation is wrong. Say the start time was 1sec,999msec. And the end time was 2sec 1 msec. You're now subtracting 999 from 1. – nos Dec 10 '13 at 00:34
  • 1
    @nos: I (foolishly) assumed that the nanoseconds element was nanoseconds since the epoch, not since the last full second since the epoch. Considering the size of that number, not very clever, but that's the assumption I operated under. – gnometorule Dec 10 '13 at 00:44

2 Answers2

7

This has nothing to do with the mythology of clock_gettime's monotonic clock not actually being monotonic (which probably has a basis in reality, but which was never well documented and probably fixed a long time ago). It's just a bug in your program. tv_nsec is the nanoseconds portion of a time value that's stored as two fields:

  • tv_sec - whole seconds
  • tv_nsec - nanoseconds in the range 0 to 999999999

Of course tv_nsec is going to jump backwards from 999999999 to 0 when tv_sec increments. To compute differences of timespec structs, you need to take 1000000000 times the difference in seconds and add that to the difference in nanoseconds. Of course this could quickly overflow if you don't convert to a 64-bit type first.

R.. GitHub STOP HELPING ICE
  • 208,859
  • 35
  • 376
  • 711
  • Good catch. I originally had a comment about "wrapping" but then thought - no this clock has a long period, no wrapping, no sir. I didn't actually noticed that the code only looked at the ns. This is definitely a bug, and most likely the correct answer. – Floris Dec 10 '13 at 00:33
  • This makes so much sense. There is no way one could store nanoseconds since the epoch in any reasonable data type...will try out as soon as I can, but expect your answer to resolve this issue, and accept pro-actively. The correct results for small times should have been a giveaway: I was lucky all ran within the second they started. If I run into something worth of asking/pointing out when I adjust my code, I'll leave a comment. Tyvm. – gnometorule Dec 10 '13 at 00:36
  • 1
    Do e.g. `sec = end_sec - start_sec; nsec = end_nsec - start_nsec; if (nsec < 0) { sec--; nsec+=1000000000;}` and print out both the sec and nsec component. – nos Dec 10 '13 at 00:38
1

Based on a bit of reading around (including the link I provided above, and How to measure the ACTUAL execution time of a C program under Linux?) it seems that getrusage() or clock() should both provide you with a "working" timer that measures the time spent by your calculation only. It does puzzle me that your other function doesn't always give a >= 0 interval, I must say.

For use on getrusage, see http://linux.die.net/man/2/getrusage

Community
  • 1
  • 1
Floris
  • 45,857
  • 6
  • 70
  • 122