return rc == -EAGAIN ? 0 : rc;
}
+static inline void
+evdev_note_time_delay(struct evdev_device *device,
+ const struct input_event *ev)
+{
+ struct libinput *libinput = evdev_libinput_context(device);
+ uint32_t tdelta;
+
+ /* if we have a current libinput_dispatch() snapshot, compare our
+ * event time with the one from the snapshot. If we have more than
+ * 10ms delay, complain about it. This catches delays in processing
+ * where there is no steady event flow and thus SYN_DROPPED may not
+ * get hit by the kernel despite us being too slow.
+ */
+ if (libinput->dispatch_time == 0)
+ return;
+
+ tdelta = us2ms(libinput->dispatch_time - input_event_time(ev));
+ if (tdelta > 10) {
+ evdev_log_bug_client_ratelimit(device,
+ &device->delay_warning_limit,
+ "event processing lagging behind by %dms, your system is too slow\n",
+ tdelta);
+ }
+}
+
static void
evdev_device_dispatch(void *data)
{
struct libinput *libinput = evdev_libinput_context(device);
struct input_event ev;
int rc;
+ bool once = false;
/* If the compositor is repainting, this function is called only once
* per frame and we have to process all the events available on the
if (rc == 0)
rc = LIBEVDEV_READ_STATUS_SUCCESS;
} else if (rc == LIBEVDEV_READ_STATUS_SUCCESS) {
+ if (!once) {
+ evdev_note_time_delay(device, &ev);
+ once = true;
+ }
evdev_device_dispatch_one(device, &ev);
}
} while (rc == LIBEVDEV_READ_STATUS_SUCCESS);
/* at most 5 SYN_DROPPED log-messages per 30s */
ratelimit_init(&device->syn_drop_limit, s2us(30), 5);
+ /* at most 5 "delayed processing" log messages per minute */
+ ratelimit_init(&device->delay_warning_limit, s2us(60), 5);
/* at most 5 log-messages per 5s */
ratelimit_init(&device->nonpointer_rel_limit, s2us(5), 5);
double trackpoint_multiplier; /* trackpoint constant multiplier */
bool use_velocity_averaging; /* whether averaging should be applied on velocity calculation */
struct ratelimit syn_drop_limit; /* ratelimit for SYN_DROPPED logging */
+ struct ratelimit delay_warning_limit; /* ratelimit for delayd processing logging */
struct ratelimit nonpointer_rel_limit; /* ratelimit for REL_* events from non-pointer devices */
uint32_t model_flags;
struct mtdev *mtdev;
struct list device_group_list;
uint64_t last_event_time;
+ uint64_t dispatch_time;
bool quirks_initialized;
struct quirks_context *quirks;
LIBINPUT_EXPORT int
libinput_dispatch(struct libinput *libinput)
{
+ static uint8_t take_time_snapshot;
struct libinput_source *source;
struct epoll_event ep[32];
int i, count;
+ /* Every 10 calls to libinput_dispatch() we take the current time so
+ * we can check the delay between our current time and the event
+ * timestamps */
+ if ((++take_time_snapshot % 10) == 0)
+ libinput->dispatch_time = libinput_now(libinput);
+ else if (libinput->dispatch_time)
+ libinput->dispatch_time = 0;
+
count = epoll_wait(libinput->epoll_fd, ep, ARRAY_LENGTH(ep), 0);
if (count < 0)
return -errno;
/* valgrind is too slow and some of our offsets are too
* short, don't abort if during a valgrind run we get a
* negative offset */
- if ((!RUNNING_ON_VALGRIND && !in_debugger) ||
- !strstr(format, "your system is too slow"))
- litest_abort_msg("libinput bug triggered, aborting.\n");
+ if ((RUNNING_ON_VALGRIND && in_debugger) ||
+ !strstr(format, "scheduled expiry is in the past")) {
+ /* noop */
+ } else if (!strstr(format, "event processing lagging behind")) {
+ /* noop */
+ } else {
+ litest_abort_msg("libinput bug triggered, aborting.\n");
+ }
}
if (strstr(format, "Touch jump detected and discarded")) {
}
END_TEST
+static void timer_delay_warning(struct libinput *libinput,
+ enum libinput_log_priority priority,
+ const char *format,
+ va_list args)
+{
+ int *warning_triggered = (int*)libinput_get_user_data(libinput);
+
+ if (priority == LIBINPUT_LOG_PRIORITY_ERROR &&
+ strstr(format, "event processing lagging behind by"))
+ (*warning_triggered)++;
+}
+
+
+START_TEST(timer_delay_bug_warning)
+{
+ struct litest_device *dev = litest_current_device();
+ struct libinput *li = dev->libinput;
+ int warning_triggered = 0;
+
+ litest_drain_events(li);
+
+ for (int i = 0; i < 10; i++) {
+ litest_button_click(dev, BTN_LEFT, true);
+ libinput_dispatch(li);
+ litest_button_click(dev, BTN_LEFT, false);
+ msleep(11);
+
+ libinput_set_user_data(li, &warning_triggered);
+ libinput_log_set_handler(li, timer_delay_warning);
+ libinput_dispatch(li);
+ }
+
+ ck_assert_int_ge(warning_triggered, 1);
+ litest_restore_log_handler(li);
+}
+END_TEST
+
START_TEST(timer_flush)
{
struct libinput *li;
litest_add_deviceless("config:status string", config_status_string);
litest_add_for_device("timer:offset-warning", timer_offset_bug_warning, LITEST_SYNAPTICS_TOUCHPAD);
+ litest_add_for_device("timer:delay-warning", timer_delay_bug_warning, LITEST_MOUSE);
litest_add_no_device("timer:flush", timer_flush);
litest_add_no_device("misc:fd", fd_no_event_leak);