timer intervals coming up short - Linux

This is a discussion on timer intervals coming up short - Linux ; This program is a daemon waiting connections so it can fork a worker child. That much is relatively classic. But I also included a timer wakeup every one minute, with the interval calculated from the time of day value to ...

+ Reply to Thread
Results 1 to 6 of 6

Thread: timer intervals coming up short

  1. timer intervals coming up short

    This program is a daemon waiting connections so it can fork a worker child.
    That much is relatively classic. But I also included a timer wakeup every
    one minute, with the interval calculated from the time of day value to keep
    this intervals from from creeping longer. Thus it is syncronzied with the
    clock, having only some jitter depending on system loads, etc.

    Usually, the wakeup is just a tiny fraction of a second late, which can be
    expected. But I sometimes it actually wakes up early. Then I end up with
    two wakeups at the same top of minute.

    In the following, the 2nd wakeup should have been at 1160845890 seconds,
    but was at least 337 microseconds before that time. So in this case it
    scheduled the next setitimer() for 337 microseconds later.

    ================================================== ===========================
    --- SIGALRM (Alarm clock) ---
    rt_sigreturn(0x5) = -1 EINTR (Interrupted system call)
    rt_sigprocmask(SIG_SETMASK, ~[], NULL, 8) = 0
    getppid() = 2392
    gettimeofday({1160845830, 209}, NULL) = 0
    setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={59, 999790}}, NULL) = 0
    rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
    accept(3, 0xbffff540, [16]) = ? ERESTARTSYS (To be restarted)
    --- SIGALRM (Alarm clock) ---
    rt_sigreturn(0x5) = -1 EINTR (Interrupted system call)
    rt_sigprocmask(SIG_SETMASK, ~[], NULL, 8) = 0
    getppid() = 2392
    gettimeofday({1160845889, 999662}, NULL) = 0
    setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 337}}, NULL) = 0
    rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
    accept(3, 0xbffff540, [16]) = ? ERESTARTSYS (To be restarted)
    --- SIGALRM (Alarm clock) ---
    rt_sigreturn(0x5) = -1 EINTR (Interrupted system call)
    rt_sigprocmask(SIG_SETMASK, ~[], NULL, 8) = 0
    getppid() = 2392
    gettimeofday({1160845890, 9254}, NULL) = 0
    setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={59, 990745}}, NULL) = 0
    rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
    ================================================== ===========================

    This isn't actually causing any problems. Any processing that needs to
    happen at specific times would not be run prematurely because it would
    based on what time it is. So something to be run at 1160845890 above
    would not have been run in the 2nd wakeup above.

    But I am curious why this happens. Is there a worst case limit which it
    could never go beyond?

    --
    |---------------------------------------/----------------------------------|
    | Phil Howard KA9WGN (ka9wgn.ham.org) / Do not send to the address below |
    | first name lower case at ipal.net / spamtrap-2006-10-14-1757@ipal.net |
    |------------------------------------/-------------------------------------|

  2. Re: timer intervals coming up short


    phil-news-nospam@ipal.net wrote:

    > Usually, the wakeup is just a tiny fraction of a second late, which can be
    > expected. But I sometimes it actually wakes up early. Then I end up with
    > two wakeups at the same top of minute.


    Actually, it probably doesn't wake up early. You are being mislead by a
    time change.

    You are asking the system to sleep at least a certain amount of
    *relative* time. You are then checking the *absolute* time (the
    system's best guess of the actual wall time).

    The behavior you are seeing is common if the system's clock is a bit
    fast and rather than adjusting the clock's speed properly, it is being
    slewed backwards. This is common on machines where a time
    synchronization program is run on a schedule, say daily. If the clock
    is fast, it will be ahead every time the synchronization program runs
    and begin running extra slowly to compensate. Then what it catches up,
    it will run it's normal (too fast) speed again.

    While the clock is slowing down to let the real time catch up to it,
    there is less than one second in between each of its displayed seconds.

    This is all, sadly, normal and expected behavior. Programs that care
    about time need to distinguish between what kind of time they are
    asking for and how they are using it and may need their own sanitized
    timing routines.

    You are asking the system for its best guess of the real UTC time mixed
    in with an attempt to sanitize the time by not jumping it. There is no
    inherent reason there must be 1,000 milliseconds in-between when the
    system makes it's best guess that it's precisely 17:01 and when the
    system makes it's best guess that it's precisely 17:02. In fact, it
    will have more or less based on attempts to synchronize the clock.

    DS


  3. Re: timer intervals coming up short


    David Schwartz wrote:
    > phil-news-nospam@ipal.net wrote:
    >
    > > Usually, the wakeup is just a tiny fraction of a second late, which can be
    > > expected. But I sometimes it actually wakes up early. Then I end up with
    > > two wakeups at the same top of minute.

    >
    > Actually, it probably doesn't wake up early. You are being mislead by a
    > time change.
    >
    > You are asking the system to sleep at least a certain amount of
    > *relative* time. You are then checking the *absolute* time (the
    > system's best guess of the actual wall time).


    Also, what if the clocks being used for scheduling and wall time are
    not the same?

    Scheduling is driven by clock ticks, but reading the clock can come
    from real time clock hardware.

    To make a task sleep, the sleep time is converted into clock ticks, to
    calculate a wakeup time. This is going to end up truncated by integer
    division. Further error is introduced by the inevitable situation that
    the scheduling delay is invoked at some arbitrary point between two
    clock ticks.

    Suppose ticks are 1/100th of a second. Suppose the current tick counter
    is 700, and suppose that it's late in the period: a timer interrupt is
    about to go off in just one millisecond.

    A task asks to sleep for 14 milliseconds. This is 1.4 clock ticks,
    which truncates down to 1 clock tick in the straightforward
    calculation: (14 * HZ) / 1000.

    The kernel samples the current counter, which is 700, and adds 1 to
    that, putting the task to sleep until time 701.

    Guess what, the timer interrupt goes off 1 millisecond later,
    transitioning to time 701, and the task wakes up.

    If the real time clock is now sampled (perhaps an incrementing register
    in the CPU which has a very fine granularity), it shows that nowhere
    near the requested 14 milliseconds have elapsed.


  4. Re: timer intervals coming up short

    phil-news-nospam@ipal.net wrote:
    > gettimeofday({1160845889, 999662}, NULL) = 0


    Do you see how many significant figures are in that tv_usec field? It's
    coming from a hardware clock, not from counting interrupts: you are not
    getting a million of those per second.

    But the timer you are setting is driven by clock tick interrupts.

    > setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 337}}, NULL) = 0


    This remainder is only 337 microseconds. How many microseconds long is
    your system's clock tick? At 100 Hz, it's 10,000 microseconds long.

    > rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
    > accept(3, 0xbffff540, [16]) = ? ERESTARTSYS (To be restarted)
    > --- SIGALRM (Alarm clock) ---
    > rt_sigreturn(0x5) = -1 EINTR (Interrupted system call)
    > rt_sigprocmask(SIG_SETMASK, ~[], NULL, 8) = 0
    > getppid() = 2392
    > gettimeofday({1160845890, 9254}, NULL) = 0


    Do you see how approximately 10,000 microseconds have elapsed since the
    last time the alarm was delivered? At the last sampling, the last four
    digits of the microseconds field of the clock were 9662. Now they are
    9254. Hmmm!

    Could it be that your system has 10,000 microsecond clock tick periods?
    How is your kernel configured in this parameter?

    You cannot wake up a thread in between clock tick periods: not unless
    the scheduler were to reprogram the interrupt timer hardware.


  5. Re: timer intervals coming up short

    On 16 Oct 2006 21:44:45 -0700 Kaz Kylheku wrote:
    | phil-news-nospam@ipal.net wrote:
    |> gettimeofday({1160845889, 999662}, NULL) = 0
    |
    | Do you see how many significant figures are in that tv_usec field? It's
    | coming from a hardware clock, not from counting interrupts: you are not
    | getting a million of those per second.
    |
    | But the timer you are setting is driven by clock tick interrupts.
    |
    |> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 337}}, NULL) = 0
    |
    | This remainder is only 337 microseconds. How many microseconds long is
    | your system's clock tick? At 100 Hz, it's 10,000 microseconds long.
    |
    |> rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
    |> accept(3, 0xbffff540, [16]) = ? ERESTARTSYS (To be restarted)
    |> --- SIGALRM (Alarm clock) ---
    |> rt_sigreturn(0x5) = -1 EINTR (Interrupted system call)
    |> rt_sigprocmask(SIG_SETMASK, ~[], NULL, 8) = 0
    |> getppid() = 2392
    |> gettimeofday({1160845890, 9254}, NULL) = 0
    |
    | Do you see how approximately 10,000 microseconds have elapsed since the
    | last time the alarm was delivered? At the last sampling, the last four
    | digits of the microseconds field of the clock were 9662. Now they are
    | 9254. Hmmm!
    |
    | Could it be that your system has 10,000 microsecond clock tick periods?
    | How is your kernel configured in this parameter?

    Default.

    | You cannot wake up a thread in between clock tick periods: not unless
    | the scheduler were to reprogram the interrupt timer hardware.

    So would this still be a problem on an architecture with a high resolution
    clock comparator?

    --
    |---------------------------------------/----------------------------------|
    | Phil Howard KA9WGN (ka9wgn.ham.org) / Do not send to the address below |
    | first name lower case at ipal.net / spamtrap-2006-10-17-0822@ipal.net |
    |------------------------------------/-------------------------------------|

  6. Re: timer intervals coming up short


    Kaz Kylheku wrote:

    > To make a task sleep, the sleep time is converted into clock ticks, to
    > calculate a wakeup time. This is going to end up truncated by integer
    > division. Further error is introduced by the inevitable situation that
    > the scheduling delay is invoked at some arbitrary point between two
    > clock ticks.


    If the operating system does not round the sleep time up, it is broken.

    http://www.opengroup.org/onlinepubs/...nanosleep.html

    DS


+ Reply to Thread