timer: only warn about timer expiry issues when we're more than 20ms behind

The most common trigger for this is the debouncing timer which is a mere
12ms and is effectively unavoidable, virtually every caller will
trigger those messages at some point.

Let's add a grace period of 20ms below which we don't log this message
to avoid logspam. And in the process, bump the equivalent warning
message up to 20ms as well.

Related #711

Signed-off-by: Peter Hutterer <peter.hutterer@who-t.net>
This commit is contained in:
Peter Hutterer 2021-12-07 11:18:07 +10:00
parent 64a49d18b9
commit a1e9150210
3 changed files with 6 additions and 3 deletions

View file

@ -1113,7 +1113,7 @@ evdev_note_time_delay(struct evdev_device *device,
return;
tdelta = us2ms(libinput->dispatch_time - eventtime);
if (tdelta > 10) {
if (tdelta > 20) {
evdev_log_bug_client_ratelimit(device,
&device->delay_warning_limit,
"event processing lagging behind by %dms, your system is too slow\n",

View file

@ -92,9 +92,12 @@ libinput_timer_set_flags(struct libinput_timer *timer,
uint32_t flags)
{
#ifndef NDEBUG
/* We only warn if we're more than 20ms behind */
const uint64_t timer_warning_limit = ms2us(20);
uint64_t now = libinput_now(timer->libinput);
if (expire < now) {
if ((flags & TIMER_FLAG_ALLOW_NEGATIVE) == 0)
if ((flags & TIMER_FLAG_ALLOW_NEGATIVE) == 0 &&
now - expire > timer_warning_limit)
log_bug_client_ratelimit(timer->libinput,
&timer->libinput->timer.expiry_in_past_limit,
"timer %s: scheduled expiry is in the past (-%dms), your system is too slow\n",

View file

@ -721,7 +721,7 @@ START_TEST(timer_delay_bug_warning)
for (int i = 0; i < 20; i++) {
litest_event(dev, EV_REL, REL_X, -1);
litest_event(dev, EV_SYN, SYN_REPORT, 0);
msleep(11);
msleep(21);
libinput_dispatch(li);
}