[Bug 264131] 2nd and subsequent events on a repeating EVFILT_TIMER are delivered with twice the requested timer period

From: <bugzilla-noreply_at_freebsd.org>
Date: Sat, 21 May 2022 19:21:41 UTC
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=264131

            Bug ID: 264131
           Summary: 2nd and subsequent events on a repeating EVFILT_TIMER
                    are delivered with twice the requested timer period
           Product: Base System
           Version: 13.1-RELEASE
          Hardware: Any
                OS: Any
            Status: New
          Severity: Affects Only Me
          Priority: ---
         Component: kern
          Assignee: bugs@FreeBSD.org
          Reporter: conorh@conorh.net
 Attachment #234088 text/plain
         mime type:

Created attachment 234088
  --> https://bugs.freebsd.org/bugzilla/attachment.cgi?id=234088&action=edit
reproducing test program

As of FreeBSD 13.1, a repeating interval timer added to a kqueue (via
EVFILT_TIMER, EV_ADD | EV_ENABLE) delivers the second and subsequent events
with a period twice that of the requested timer period. The first event is
delivered on-time. This appears to have been introduced in FreeBSD 13.1; 13.0
and 12.3 (what I tested) don't exhibit the problem.

Attaching a test program that creates such a timer for 500ms and waits for
events one at a time forever, noting the calculated time interval between
events. On 12.3 and 13.0, the program reports firing times reliably within a
few ms of the requested 500ms:

conorh@freebsd13dot0:~ $ ./repro_timer
got event, ident 1, filter -7, data 1; last fire was 500 ms ago
got event, ident 1, filter -7, data 1; last fire was 500 ms ago
got event, ident 1, filter -7, data 1; last fire was 499 ms ago
got event, ident 1, filter -7, data 1; last fire was 500 ms ago
got event, ident 1, filter -7, data 1; last fire was 501 ms ago
got event, ident 1, filter -7, data 1; last fire was 499 ms ago
got event, ident 1, filter -7, data 1; last fire was 498 ms ago
got event, ident 1, filter -7, data 1; last fire was 501 ms ago
got event, ident 1, filter -7, data 1; last fire was 499 ms ago
got event, ident 1, filter -7, data 1; last fire was 498 ms ago
^C
conorh@freebsd13dot0:~ $

But on 13.1, it reports the first event around 500ms, and the second and
subsequent ones around 1000ms:

conorh@freebsd13dot1:~ $ ./repro_timer
got event, ident 1, filter -7, data 1; last fire was 501 ms ago
got event, ident 1, filter -7, data 1; last fire was 998 ms ago
got event, ident 1, filter -7, data 1; last fire was 999 ms ago
got event, ident 1, filter -7, data 1; last fire was 1000 ms ago
got event, ident 1, filter -7, data 1; last fire was 999 ms ago
got event, ident 1, filter -7, data 1; last fire was 1001 ms ago
got event, ident 1, filter -7, data 1; last fire was 1000 ms ago
got event, ident 1, filter -7, data 1; last fire was 1000 ms ago
^C
conorh@freebsd13dot1:~ $

-- 
You are receiving this mail because:
You are the assignee for the bug.