Bug 224837

Extremly unaccurate nanosleep() called to sleep for 0.6 seconds actually sleeps up to 0.640 seconds. More then 5% error.

This test program:



#include <stdio.h>
#include <time.h>
#include <stdint.h>


double  time_diff(struct timespec * start, struct timespec * stop) // in millese
conds
{
    struct timespec result;

    if ((stop->tv_nsec - start->tv_nsec) < 0) {
        result.tv_sec = stop->tv_sec - start->tv_sec - 1;
        result.tv_nsec = stop->tv_nsec - start->tv_nsec + 1000000000;
    } else {
        result.tv_sec = stop->tv_sec - start->tv_sec;
        result.tv_nsec = stop->tv_nsec - start->tv_nsec;
    };

   return ((result.tv_sec*1000) + ((double)(result.tv_nsec)/1000000.0));
};

int main(int argc, char * argv[])
{

struct timespec before_sleep, after_sleep, time_for_sleep;

while(1)
{
clock_gettime(CLOCK_MONOTONIC, &before_sleep);

time_for_sleep.tv_sec=0;
time_for_sleep.tv_nsec=600 * 1000 * 1000; //nanoseconds
nanosleep(&time_for_sleep,NULL);

clock_gettime(CLOCK_MONOTONIC, &after_sleep);

printf("Sleeping for %d ms, real sleep is %f\n",
       (int)( time_for_sleep.tv_nsec / (1000*1000)),
       time_diff(&before_sleep, &after_sleep));
};


return 0;
};

produce the following results:


[der@perforce ~/nano]$ ./nano
Sleeping for 600 ms, real sleep is 638.271304
Sleeping for 600 ms, real sleep is 638.468908
Sleeping for 600 ms, real sleep is 638.523862
Sleeping for 600 ms, real sleep is 638.527911
Sleeping for 600 ms, real sleep is 638.523231
Sleeping for 600 ms, real sleep is 638.524958
Sleeping for 600 ms, real sleep is 638.525569
Sleeping for 600 ms, real sleep is 638.574649
Sleeping for 600 ms, real sleep is 638.466486
Sleeping for 600 ms, real sleep is 631.819499
Sleeping for 600 ms, real sleep is 638.328923
Sleeping for 600 ms, real sleep is 638.526769
Sleeping for 600 ms, real sleep is 638.531379
Sleeping for 600 ms, real sleep is 638.539257
Sleeping for 600 ms, real sleep is 638.523906
Sleeping for 600 ms, real sleep is 638.524129
Sleeping for 600 ms, real sleep is 638.523692
^C

[der@perforce ~/nano]$ uname -a
FreeBSD perforce 11.0-RELEASE-p9 FreeBSD 11.0-RELEASE-p9 #0: Tue Apr 11 08:48:40 UTC 2017     root@amd64-builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC  amd64
[der@perforce ~/nano]$
[der@perforce ~/nano]$ sysctl -a | grep kern | grep hz
kern.clockrate: { hz = 1000, tick = 1000, profhz = 8128, stathz = 127 }
kern.hz: 1000


I have tryed to change kern.hz in /boot/loader.conf, both 100 and 10000 values do not change anything.

I have tested on FreeBSD-10.3 i386 and amd64 - same results.

It seems like on 10-seconds interval it cause error up to 0.17 seconds.

For extremly short intervals, like 1 ms (0.001 seconds) error is still 5-7%.
=============================================

Exactly the same program compiled and running under Linux (CentOS) produce the following results:

aeder@Moria$ ./nano
Sleeping for 600 ms, real sleep is 600.113074
Sleeping for 600 ms, real sleep is 600.112979
Sleeping for 600 ms, real sleep is 600.128481
Sleeping for 600 ms, real sleep is 600.139906
Sleeping for 600 ms, real sleep is 600.085603
Sleeping for 600 ms, real sleep is 600.123303
Sleeping for 600 ms, real sleep is 600.139970
Sleeping for 600 ms, real sleep is 600.058206
Sleeping for 600 ms, real sleep is 600.139756
Sleeping for 600 ms, real sleep is 600.139840
Sleeping for 600 ms, real sleep is 600.139880
Sleeping for 600 ms, real sleep is 600.068483
Sleeping for 600 ms, real sleep is 600.139898
Sleeping for 600 ms, real sleep is 600.098436
^C
aeder@Moria$ uname -a
Linux Moria 2.6.32-431.el6.i686 #1 SMP Fri Nov 22 00:26:36 UTC 2013 i686 i686 i386 GNU/Linux

==============================================
Really old FreeBSD version (6.3) on old hardware:

fspa2# ./nano
Sleeping for 600 ms, real sleep is 600.631924
Sleeping for 600 ms, real sleep is 600.852902
Sleeping for 600 ms, real sleep is 600.977778
Sleeping for 600 ms, real sleep is 600.978615
Sleeping for 600 ms, real sleep is 600.981130
Sleeping for 600 ms, real sleep is 600.980293
Sleeping for 600 ms, real sleep is 600.981689
Sleeping for 600 ms, real sleep is 600.979454
Sleeping for 600 ms, real sleep is 600.981689
Sleeping for 600 ms, real sleep is 600.979175
Sleeping for 600 ms, real sleep is 600.987276
Sleeping for 600 ms, real sleep is 600.974425
Sleeping for 600 ms, real sleep is 600.982247
Sleeping for 600 ms, real sleep is 600.979734
Sleeping for 600 ms, real sleep is 600.981689
Sleeping for 600 ms, real sleep is 600.980851
^C

fspa2# uname -a
FreeBSD fspa2 6.3-RELEASE FreeBSD 6.3-RELEASE #0: Wed Jan 16 04:45:45 UTC 2008     root@dessler.cse.buffalo.edu:/usr/obj/usr/src/sys/SMP  i386
fspa2#
fspa2# sysctl -a | grep kern | grep hz
kern.clockrate: { hz = 1000, tick = 1000, profhz = 666, stathz = 133 }

==============================================

It seems for me that nanosleep() is broken somehow in recent versions of FreeBSD.
It's really annoing and will cause to write wrappers over nanosleep() in userland.