Bug 264131
| Summary: | 2nd and subsequent events on a repeating EVFILT_TIMER are delivered with twice the requested timer period | ||||||
|---|---|---|---|---|---|---|---|
| Product: | Base System | Reporter: | Conor Hughes <conorh> | ||||
| Component: | kern | Assignee: | Mark Johnston <markj> | ||||
| Status: | Closed FIXED | ||||||
| Severity: | Affects Only Me | CC: | markj | ||||
| Priority: | --- | ||||||
| Version: | 13.1-RELEASE | ||||||
| Hardware: | Any | ||||||
| OS: | Any | ||||||
| Attachments: |
|
||||||
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. |
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:~ $