Bug 224837 - Describe kern.timecounter.alloweddeviation sysctl() (and probable more) in nanosleep(2) man page.
Summary: Describe kern.timecounter.alloweddeviation sysctl() (and probable more) in na...
Status: New
Alias: None
Product: Documentation
Classification: Unclassified
Component: Manual Pages (show other bugs)
Version: Latest
Hardware: Any Any
: --- Affects Some People
Assignee: freebsd-bugs (Nobody)
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2018-01-02 10:56 UTC by Aleksander Derevianko
Modified: 2020-04-19 08:19 UTC (History)
3 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Aleksander Derevianko 2018-01-02 10:56:50 UTC
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.
Comment 1 Conrad Meyer freebsd_committer 2018-01-02 19:35:05 UTC
Try tuning down kern.timecounter.alloweddeviation to zero.
Comment 2 Aleksander Derevianko 2018-01-03 11:50:53 UTC
(In reply to Conrad Meyer from comment #1)

Thanks, it works like a charm! Now precision is pretty good.

Sleeping for 600 ms, real sleep is 600.081164
Sleeping for 600 ms, real sleep is 600.062304
Sleeping for 600 ms, real sleep is 600.063774
Sleeping for 600 ms, real sleep is 600.101515
Sleeping for 600 ms, real sleep is 600.088049
Sleeping for 600 ms, real sleep is 600.066452
Sleeping for 600 ms, real sleep is 600.062314
Sleeping for 600 ms, real sleep is 600.084151
Sleeping for 600 ms, real sleep is 600.059051
Sleeping for 600 ms, real sleep is 600.062662
Sleeping for 600 ms, real sleep is 600.064423


Now I can google kern.timecounter.alloweddeviation and find a lot of references to it, but before that googling for "nanosleep + freebsd" return nothing useful.

May be, adding it in nanosleep(2) man page?
Comment 3 commit-hook freebsd_committer 2020-04-19 08:19:38 UTC
A commit references this bug:

Author: mandree
Date: Sun Apr 19 08:18:44 UTC 2020
New revision: 532086
URL: https://svnweb.freebsd.org/changeset/ports/532086

Log:
  multimedia/librtmp, rtmpdump: Update to 20190330.

  PR:		224836
  PR:		224837
  Submitted by:	daniel.engberg.lists@pyret.net
  Approved by:	maintainer timeout (hrs@, 35 d)

Changes:
  head/multimedia/librtmp/Makefile
  head/multimedia/librtmp/distinfo
  head/multimedia/rtmpdump/Makefile
  head/multimedia/rtmpdump/distinfo