Created attachment 234088 [details] 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:~ $
Thanks for the report and test program. It looks like this is a regression from commit 7cb40543e964. This patch fixes the problem for me but needs more thought: diff --git a/sys/kern/kern_event.c b/sys/kern/kern_event.c index 33607fe8c5f4..f1ee8de4e7ee 100644 --- a/sys/kern/kern_event.c +++ b/sys/kern/kern_event.c @@ -739,7 +739,7 @@ filt_timerexpire_l(struct knote *kn, bool proc_locked) if (delta == 0) delta = 1; kn->kn_data += delta; - kc->next += (delta + 1) * kc->to; + kc->next += delta * kc->to; if (now >= kc->next) /* overflow */ kc->next = now + kc->to; KNOTE_ACTIVATE(kn, 0); /* XXX - handle locking */
A commit in branch main references this bug: URL: https://cgit.FreeBSD.org/src/commit/?id=524dadf7a8725dea144571843e611dbdbd59d668 commit 524dadf7a8725dea144571843e611dbdbd59d668 Author: Mark Johnston <markj@FreeBSD.org> AuthorDate: 2022-05-25 00:14:33 +0000 Commit: Mark Johnston <markj@FreeBSD.org> CommitDate: 2022-05-25 00:14:33 +0000 kevent: Fix an off-by-one in filt_timerexpire_l() Suppose a periodic kevent timer fires close to its deadline, so that now - kc->next is small. Then delta ends up being 1, and the next timer deadline is set to (delta + 1) * kc->to, where kc->to is the timer period. This means that the timer fires at half of the requested rate, and the value returned in kn_data is similarly inaccurate. PR: 264131 Fixes: 7cb40543e964 ("filt_timerexpire: do not iterate over the interval") Reviewed by: kib MFC after: 2 weeks Sponsored by: The FreeBSD Foundation Differential Revision: https://reviews.freebsd.org/D35313 sys/kern/kern_event.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
A commit in branch stable/13 references this bug: URL: https://cgit.FreeBSD.org/src/commit/?id=129112f80d2bfe6091ebb8656912fb55d6192e1f commit 129112f80d2bfe6091ebb8656912fb55d6192e1f Author: Mark Johnston <markj@FreeBSD.org> AuthorDate: 2022-05-25 00:14:33 +0000 Commit: Mark Johnston <markj@FreeBSD.org> CommitDate: 2022-06-08 00:42:21 +0000 kevent: Fix an off-by-one in filt_timerexpire_l() Suppose a periodic kevent timer fires close to its deadline, so that now - kc->next is small. Then delta ends up being 1, and the next timer deadline is set to (delta + 1) * kc->to, where kc->to is the timer period. This means that the timer fires at half of the requested rate, and the value returned in kn_data is similarly inaccurate. PR: 264131 Fixes: 7cb40543e964 ("filt_timerexpire: do not iterate over the interval") Reviewed by: kib Sponsored by: The FreeBSD Foundation (cherry picked from commit 524dadf7a8725dea144571843e611dbdbd59d668) sys/kern/kern_event.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
A commit in branch releng/13.1 references this bug: URL: https://cgit.FreeBSD.org/src/commit/?id=c48048ebdbed0901dacf1632af3b3db600533e64 commit c48048ebdbed0901dacf1632af3b3db600533e64 Author: Mark Johnston <markj@FreeBSD.org> AuthorDate: 2022-05-25 00:14:33 +0000 Commit: Mark Johnston <markj@FreeBSD.org> CommitDate: 2022-07-25 21:01:16 +0000 kevent: Fix an off-by-one in filt_timerexpire_l() Suppose a periodic kevent timer fires close to its deadline, so that now - kc->next is small. Then delta ends up being 1, and the next timer deadline is set to (delta + 1) * kc->to, where kc->to is the timer period. This means that the timer fires at half of the requested rate, and the value returned in kn_data is similarly inaccurate. Approved by: so Security: FreeBSD-EN-22:16.kqueue PR: 264131 Fixes: 7cb40543e964 ("filt_timerexpire: do not iterate over the interval") Reviewed by: kib Sponsored by: The FreeBSD Foundation (cherry picked from commit 524dadf7a8725dea144571843e611dbdbd59d668) (cherry picked from commit 129112f80d2bfe6091ebb8656912fb55d6192e1f) sys/kern/kern_event.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
Fixed in 13.1-p1.