Micro-benchmark for various time syscalls...

[Bruce Evans]

On Mon, 2 Jun 2008, Claus Guttesen wrote:

>> % ./bench_time 9079882 | sort -rnk1
>> Timing micro-benchmark.  9079882 syscall iterations.
>> Avg. us/call    Elapsed     Name
>> 9.322484    84.647053       gettimeofday(2)
>> 8.955324    81.313291       time(3)
>> 8.648315    78.525684       clock_gettime(2/CLOCK_REALTIME)
>> 8.598495    78.073325       clock_gettime(2/CLOCK_MONOTONIC)
>> 0.674194    6.121600        clock_gettime(2/CLOCK_PROF)
>> 0.648083    5.884515        clock_gettime(2/CLOCK_VIRTUAL)
>> 0.330556    3.001412        clock_gettime(2/CLOCK_REALTIME_FAST)
>> 0.306514    2.783111        clock_gettime(2/CLOCK_SECOND)
>> 0.262788    2.386085        clock_gettime(2/CLOCK_MONOTONIC_FAST)

In previous mail, I said that these were very slow.

> rozetta~/devel/c%>sysctl hw.model
> hw.model: Intel(R) Xeon(R) CPU           E5345  @ 2.33GHz
>
> rozetta~/devel/c%>./bench_time 9079882 | sort -rnk1
> Timing micro-benchmark.  9079882 syscall iterations.
> Avg. us/call    Elapsed         Name
> 1.405469        12.761494       clock_gettime(2/CLOCK_REALTIME)
> 1.313101        11.922799       time(3)
> 1.305518        11.853953       clock_gettime(2/CLOCK_MONOTONIC)
> 1.303947        11.839681       gettimeofday(2)
> 0.442908        4.021557        clock_gettime(2/CLOCK_PROF)
> 0.436484        3.963223        clock_gettime(2/CLOCK_VIRTUAL)
> 0.217718        1.976851        clock_gettime(2/CLOCK_MONOTONIC_FAST)
> 0.215264        1.954571        clock_gettime(2/CLOCK_REALTIME_FAST)
> 0.211779        1.922932        clock_gettime(2/CLOCK_SECOND)

These seem about right for a normal untuned ~2GHz system:
- there is a syscall overhead of about 200 nsec
- the hardware parts of the ACPI (?) timecounter are very slow, so they
   add 1100 nsec
- anomalous extra 100 nsec for CLOCK_REALTIME.  CLOCK_REALTIME does less than
   gettimeofday().
- CLOCK_PROF and CLOCK_VIRTUAL use the slow function calcru() in the kernel.
   This apparently takes about the same time as a syscall.  calcru() uses
   cpu_ticks() (which normally uses the TSC on i386 and amd64) to determine
   the time spent since the thread was last context switched, so it is more
   accurate than CLOCK_REALTIME_FAST but less accurate than CLOCK_REALTIME;
   using the TSC makes it faster than a non-TSC timecounter.  calcru() still
   seems to have broken accounting for the current timeslice in other running
   threads in the process.

> gettimeofday is 6 times slower on this system, 28 times slower on your system.

1.epsilon times slower on my system :-).

Bruce