[PATCH v2 libevdev] Enable event logging on request
Peter Hutterer
peter.hutterer at who-t.net
Thu Apr 3 19:54:55 PDT 2014
Check an environment variable in the form for
LIBEVDEV_LOG_EVENTS="error"
or
LIBEVDEV_LOG_EVENTS="info:event0,event3"
If set, log all or the selected devices to the normal event logger, with the
given priority.
Key codes in the normal alphanumeric range are obfuscated to avoid accidental
leakage of information, higher-order keys are sent as normal.
Signed-off-by: Peter Hutterer <peter.hutterer at who-t.net>
---
Changes to v1:
- use the event node name instead of the minor number, avoids confusion
- add tests
libevdev/libevdev-int.h | 5 +
libevdev/libevdev.c | 164 ++++++++++++++++++++++++++
libevdev/libevdev.h | 23 ++++
test/test-libevdev-events.c | 275 ++++++++++++++++++++++++++++++++++++++++++++
4 files changed, 467 insertions(+)
diff --git a/libevdev/libevdev-int.h b/libevdev/libevdev-int.h
index 98c75ce..5a164bd 100644
--- a/libevdev/libevdev-int.h
+++ b/libevdev/libevdev-int.h
@@ -107,6 +107,11 @@ struct libevdev {
unsigned long *tracking_id_changes;
size_t tracking_id_changes_sz; /* in bytes */
} mt_sync;
+
+ struct {
+ char *device_node;
+ enum libevdev_log_priority priority;
+ } debug;
};
struct logdata {
diff --git a/libevdev/libevdev.c b/libevdev/libevdev.c
index 96bd41b..74fd935 100644
--- a/libevdev/libevdev.c
+++ b/libevdev/libevdev.c
@@ -21,13 +21,16 @@
*/
#include <config.h>
+#include <dirent.h>
#include <errno.h>
+#include <limits.h>
#include <poll.h>
#include <stdlib.h>
#include <string.h>
#include <unistd.h>
#include <stdarg.h>
#include <stdbool.h>
+#include <sys/stat.h>
#include "libevdev.h"
#include "libevdev-int.h"
@@ -44,6 +47,32 @@ enum event_filter_status {
static int sync_mt_state(struct libevdev *dev, int create_events);
+static inline void
+log_event(struct libevdev *dev, int flags, const struct input_event *ev)
+{
+ const char *mode;
+ const char *type, *code;
+
+ if (dev->debug.priority == 0)
+ return;
+
+ if (flags & LIBEVDEV_READ_FLAG_SYNC)
+ mode = "S";
+ else if (flags & LIBEVDEV_READ_FLAG_NORMAL)
+ mode = "N";
+ else
+ mode = "I";
+
+ type = libevdev_event_type_get_name(ev->type);
+ if (ev->type == EV_KEY && ev->code < KEY_STOP)
+ code = "OBFUSCATED";
+ else
+ code = libevdev_event_code_get_name(ev->type, ev->code);
+
+ log_msg_cond(dev->debug.priority, "%s: EVENT(%s): %s %s %d\n",
+ dev->debug.device_node, mode, type, code, ev->value);
+}
+
static inline int*
slot_value(const struct libevdev *dev, int slot, int axis)
{
@@ -161,6 +190,7 @@ libevdev_reset(struct libevdev *dev)
free(dev->mt_sync.mt_state);
free(dev->mt_sync.tracking_id_changes);
free(dev->mt_sync.slot_update);
+ free(dev->debug.device_node);
memset(dev, 0, sizeof(*dev));
dev->fd = -1;
dev->initialized = false;
@@ -235,6 +265,129 @@ libevdev_get_log_priority(void)
return log_data.priority;
}
+static int
+is_event_device(const struct dirent *dir) {
+ return strncmp("event", dir->d_name, 5) == 0;
+}
+
+static char*
+get_event_node(struct libevdev *dev)
+{
+ struct dirent **entries;
+ int nentries, i;
+ struct stat st;
+ dev_t rdev;
+ char *node = NULL;
+
+ if (fstat(dev->fd, &st) == -1)
+ return NULL;
+
+ rdev = st.st_rdev;
+
+ nentries = scandir("/dev/input/",
+ &entries,
+ is_event_device,
+ versionsort);
+ if (nentries == -1)
+ return NULL;
+
+ for (i = 0; i < nentries; i++) {
+ char path[PATH_MAX];
+
+ snprintf(path, sizeof(path), "/dev/input/%s", entries[i]->d_name);
+ if (stat(path, &st) == -1)
+ continue;
+
+ if (st.st_rdev == rdev) {
+ node = strdup(entries[i]->d_name);
+ break;
+ }
+ }
+
+ for (i = 0; i < nentries; i++)
+ free(entries[i]);
+ free(entries);
+
+ return node;
+}
+
+static void
+enable_event_logging(struct libevdev *dev)
+{
+ enum libevdev_log_priority pri = 0;
+ const char *env;
+ char *tmp = NULL,
+ *tok = NULL, *saveptr;
+ char *node;
+
+ env = getenv("LIBEVDEV_LOG_EVENTS");
+ if (!env || strlen(env) == 0)
+ return;
+
+ if (dev->debug.device_node)
+ free(dev->debug.device_node);
+
+ node = get_event_node(dev);
+ if (!node) {
+ log_error("Failed to get device node for debugging\n");
+ return;
+ }
+
+ if (strncmp(env, "error", 5) == 0) {
+ pri = LIBEVDEV_LOG_ERROR;
+ tok = (char*)&env[5];
+ } else if (strncmp(env, "info", 4) == 0) {
+ pri = LIBEVDEV_LOG_INFO;
+ tok = (char*)&env[4];
+ } else if (strncmp(env, "debug", 5) == 0) {
+ pri = LIBEVDEV_LOG_DEBUG;
+ tok = (char*)&env[5];
+ }
+
+ if (tok && *tok == '\0') {
+ dev->debug.device_node = node;
+ dev->debug.priority = pri;
+ return;
+ }
+
+ if (!tok || *tok != ':') {
+ log_error("Invalid value '%s' for $LIBEVDEV_LOG_EVENTS\n", env);
+ free(node);
+ return;
+ }
+
+ tmp = strdup(tok + 1);
+ if (!tmp) {
+ log_error("Allocation failure, debugging disabled\n");
+ free(node);
+ return;
+ }
+
+ tok = strtok_r(tmp, ",", &saveptr);
+
+ while (tok) {
+ if (strncmp(tok, "event", 5) != 0) {
+ log_error("Invalid value '%s' for $LIBEVDEV_LOG_EVENTS\n", env);
+ break;
+ }
+
+ if (strncmp(tok, node, strlen(node)) == 0) {
+ dev->debug.device_node = node;
+ dev->debug.priority = pri;
+ break;
+ }
+
+ tok = strtok_r(NULL, ",", &saveptr);
+ }
+
+ free(tmp);
+
+ if (!dev->debug.device_node)
+ free(node);
+
+ return;
+}
+
LIBEVDEV_EXPORT int
libevdev_change_fd(struct libevdev *dev, int fd)
{
@@ -242,7 +395,11 @@ libevdev_change_fd(struct libevdev *dev, int fd)
log_bug("device not initialized. call libevdev_set_fd() first\n");
return -1;
}
+
dev->fd = fd;
+
+ enable_event_logging(dev);
+
return 0;
}
@@ -390,6 +547,8 @@ libevdev_set_fd(struct libevdev* dev, int fd)
dev->fd = fd;
+ enable_event_logging(dev);
+
/* devices with ABS_MT_SLOT - 1 aren't MT devices,
see the documentation for multitouch-related
functions for more details */
@@ -957,6 +1116,9 @@ libevdev_next_event(struct libevdev *dev, unsigned int flags, struct input_event
of the device too */
while (queue_shift(dev, &e) == 0) {
dev->queue_nsync--;
+
+ log_event(dev, 0, ev);
+
if (sanitize_event(dev, &e, dev->sync_state) != EVENT_FILTER_DISCARD)
update_state(dev, &e);
}
@@ -988,6 +1150,8 @@ libevdev_next_event(struct libevdev *dev, unsigned int flags, struct input_event
if (queue_shift(dev, ev) != 0)
return -EAGAIN;
+ log_event(dev, flags, ev);
+
filter_status = sanitize_event(dev, ev, dev->sync_state);
if (filter_status != EVENT_FILTER_DISCARD)
update_state(dev, ev);
diff --git a/libevdev/libevdev.h b/libevdev/libevdev.h
index aa7b90d..c20ed84 100644
--- a/libevdev/libevdev.h
+++ b/libevdev/libevdev.h
@@ -151,6 +151,29 @@ extern "C" {
* libevdev is licensed under the
* [X11 license](http://cgit.freedesktop.org/libevdev/tree/COPYING).
*
+ * Debugging events
+ * ================
+ * libevdev checks the LIBEVDEV_LOG_EVENTS environment variable during
+ * libevdev_set_fd() and libevdev_change_fd(). If set to "error", "info", or
+ * "debug", all events are logged with the respective priority before they
+ * are passed to the client. This is useful to check event sequences that
+ * happen before a specific bug in the higher layers of the stack
+ *
+ * To debug specific devices only, the event node may be provided as a
+ * comma-separated list after the priority:
+ * LIBEVDEV_LOG_EVENTS="error:event0,event5,event3" logs all events from the
+ * devices with the given /dev/input/event nodes. This requires that the
+ * libevdev process is able to iterate and stat each file in the /dev/input
+ * directory. An invalid value of the variable or unsuccessful attempt to
+ * initialize logging for a device will be logged as error. Debugging is
+ * disabled (for this device, if appropriate), otherwise libevdev continues
+ * normally.
+ *
+ * Events logged by libevdev are likely to end up in public bug reports. For
+ * this reason key event codes obfuscated to protect accidental leakage of
+ * private information. Key codes between KEY_ESC up to including
+ * KEY_COMPOSE are always logged as "OBFUSCATED".
+ *
* Reporting bugs
* ==============
* Please report bugs in the freedesktop.org bugzilla under the libevdev product:
diff --git a/test/test-libevdev-events.c b/test/test-libevdev-events.c
index dc412a7..5305639 100644
--- a/test/test-libevdev-events.c
+++ b/test/test-libevdev-events.c
@@ -25,7 +25,9 @@
#include <errno.h>
#include <unistd.h>
#include <fcntl.h>
+#include <stdarg.h>
#include <stdio.h>
+#include <stdlib.h>
#include <libevdev/libevdev-util.h>
#include "test-common.h"
@@ -1840,6 +1842,273 @@ START_TEST(test_event_mt_value_setters_current_slot)
}
END_TEST
+struct debug_log_data {
+ enum libevdev_log_priority priority;
+ char *expect_token;
+ char *dont_expect_token;
+ int logged;
+};
+
+void debug_log_func(enum libevdev_log_priority priority,
+ void *data,
+ const char *file, int line,
+ const char *func,
+ const char *format, va_list args)
+{
+ struct debug_log_data *debug_data = data;
+ char msg[1024];
+
+ ck_assert_int_eq(debug_data->priority, priority);
+
+ vsnprintf(msg, sizeof(msg), format, args);
+
+ if (debug_data->expect_token)
+ ck_assert(strstr(msg, debug_data->expect_token) != NULL);
+
+ if (debug_data->dont_expect_token)
+ ck_assert(strstr(msg, debug_data->dont_expect_token) == NULL);
+
+ debug_data->logged++;
+}
+
+START_TEST(test_event_log)
+{
+ struct uinput_device* uidev;
+ struct libevdev *dev;
+ const char *oldenv;
+ struct input_event ev;
+
+ struct debug_log_data debug_log_data;
+
+ oldenv = getenv("LIBEVDEV_LOG_EVENTS");
+ setenv("LIBEVDEV_LOG_EVENTS", "error", 1);
+
+ debug_log_data.priority = LIBEVDEV_LOG_ERROR;
+ debug_log_data.dont_expect_token = NULL;
+ debug_log_data.logged = 0;
+ libevdev_set_log_function(debug_log_func, &debug_log_data);
+
+ test_create_device(&uidev, &dev,
+ EV_REL, REL_X,
+ EV_REL, REL_Y,
+ EV_KEY, BTN_LEFT,
+ EV_KEY, KEY_A,
+ EV_KEY, KEY_STOP,
+ -1);
+
+ uinput_device_event(uidev, EV_REL, REL_X, 1);
+ uinput_device_event(uidev, EV_KEY, BTN_LEFT, 1);
+ uinput_device_event(uidev, EV_SYN, SYN_REPORT, 0);
+
+ debug_log_data.expect_token = "EV_REL";
+ libevdev_next_event(dev, LIBEVDEV_READ_FLAG_NORMAL, &ev);
+
+ debug_log_data.expect_token = "EV_KEY";
+ libevdev_next_event(dev, LIBEVDEV_READ_FLAG_NORMAL, &ev);
+
+ debug_log_data.expect_token = "EV_SYN";
+ libevdev_next_event(dev, LIBEVDEV_READ_FLAG_NORMAL, &ev);
+
+ uinput_device_event(uidev, EV_KEY, KEY_A, 1);
+ uinput_device_event(uidev, EV_KEY, KEY_STOP, 1);
+ uinput_device_event(uidev, EV_SYN, SYN_REPORT, 0);
+
+ debug_log_data.expect_token = "OBFUSCATED";
+ debug_log_data.dont_expect_token = "KEY_A";
+ libevdev_next_event(dev, LIBEVDEV_READ_FLAG_NORMAL, &ev);
+
+ debug_log_data.expect_token = "KEY_STOP";
+ debug_log_data.dont_expect_token = "OBFUSCATED";
+ libevdev_next_event(dev, LIBEVDEV_READ_FLAG_NORMAL, &ev);
+
+ debug_log_data.expect_token = "EV_SYN";
+ debug_log_data.dont_expect_token = NULL;
+ libevdev_next_event(dev, LIBEVDEV_READ_FLAG_NORMAL, &ev);
+
+ ck_assert_int_eq(debug_log_data.logged, 6);
+
+ libevdev_set_log_function(test_logfunc_abort_on_error, NULL);
+
+ uinput_device_free(uidev);
+ libevdev_free(dev);
+
+ if (oldenv)
+ setenv("LIBEVDEV_LOG_EVENTS", oldenv, 1);
+ else
+ unsetenv("LIBEVDEV_LOG_EVENTS");
+}
+END_TEST
+
+START_TEST(test_event_log_per_device)
+{
+ struct uinput_device *uidev1, *uidev2;
+ struct libevdev *dev1, *dev2;
+ const char *oldenv;
+ char env[1024];
+ struct input_event ev;
+ int rc;
+ int fd;
+ const char *node1, *node2;
+
+ struct debug_log_data debug_log_data;
+
+ oldenv = getenv("LIBEVDEV_LOG_EVENTS");
+
+ rc = uinput_device_new_with_events(&uidev1,
+ TEST_DEVICE_NAME, DEFAULT_IDS,
+ EV_SYN, SYN_REPORT,
+ EV_REL, REL_X,
+ EV_REL, REL_Y,
+ EV_REL, REL_WHEEL,
+ EV_KEY, BTN_LEFT,
+ EV_KEY, BTN_MIDDLE,
+ EV_KEY, BTN_RIGHT,
+ -1);
+ ck_assert_msg(rc == 0, "Failed to create uinput device: %s", strerror(-rc));
+ rc = uinput_device_new_with_events(&uidev2,
+ TEST_DEVICE_NAME " 2", DEFAULT_IDS,
+ EV_SYN, SYN_REPORT,
+ EV_REL, REL_X,
+ EV_REL, REL_Y,
+ EV_REL, REL_WHEEL,
+ EV_KEY, BTN_LEFT,
+ EV_KEY, BTN_MIDDLE,
+ EV_KEY, BTN_RIGHT,
+ -1);
+ ck_assert_msg(rc == 0, "Failed to create uinput device: %s", strerror(-rc));
+
+ node1 = strrchr(uinput_device_get_devnode(uidev1), '/') + 1;
+ node2 = strrchr(uinput_device_get_devnode(uidev2), '/') + 1;
+
+ sprintf(env, "error:%s", node2);
+ setenv("LIBEVDEV_LOG_EVENTS", env, 1);
+
+ fd = uinput_device_get_fd(uidev1);
+ fcntl(fd, F_SETFL, O_NONBLOCK);
+ rc = libevdev_new_from_fd(fd, &dev1);
+ ck_assert_int_eq(rc, 0);
+
+ fd = uinput_device_get_fd(uidev2);
+ fcntl(fd, F_SETFL, O_NONBLOCK);
+ rc = libevdev_new_from_fd(fd, &dev2);
+ ck_assert_int_eq(rc, 0);
+
+ /* check with the trailing : otherwise we may find event1 in
+ * event13, etc. */
+ debug_log_data.dont_expect_token = alloca(strlen(node1) + 2);
+ ck_assert(debug_log_data.dont_expect_token != NULL);
+ sprintf(debug_log_data.dont_expect_token, "%s:", node1);
+
+ debug_log_data.expect_token = alloca(strlen(node2) + 2);
+ ck_assert(debug_log_data.dont_expect_token != NULL);
+ sprintf(debug_log_data.expect_token, "%s:", node2);
+
+ debug_log_data.priority = LIBEVDEV_LOG_ERROR;
+ debug_log_data.logged = 0;
+ libevdev_set_log_function(debug_log_func, &debug_log_data);
+
+ uinput_device_event(uidev1, EV_REL, REL_X, 1);
+ uinput_device_event(uidev1, EV_KEY, BTN_LEFT, 1);
+ uinput_device_event(uidev1, EV_SYN, SYN_REPORT, 0);
+
+ uinput_device_event(uidev2, EV_REL, REL_X, 1);
+ uinput_device_event(uidev2, EV_KEY, BTN_LEFT, 1);
+ uinput_device_event(uidev2, EV_SYN, SYN_REPORT, 0);
+
+ while (libevdev_next_event(dev1, LIBEVDEV_READ_FLAG_NORMAL, &ev) != -EAGAIN &&
+ libevdev_next_event(dev2, LIBEVDEV_READ_FLAG_NORMAL, &ev) != -EAGAIN)
+ ;
+
+ ck_assert_int_eq(debug_log_data.logged, 3);
+
+ libevdev_set_log_function(test_logfunc_abort_on_error, NULL);
+
+ uinput_device_free(uidev1);
+ uinput_device_free(uidev2);
+ libevdev_free(dev1);
+ libevdev_free(dev2);
+
+ if (oldenv)
+ setenv("LIBEVDEV_LOG_EVENTS", oldenv, 1);
+ else
+ unsetenv("LIBEVDEV_LOG_EVENTS");
+}
+END_TEST
+
+void event_debug_log_error_func(enum libevdev_log_priority priority,
+ void *data,
+ const char *file, int line,
+ const char *func,
+ const char *format, va_list args)
+{
+ int *called = data;
+ (*called)++;
+}
+
+static void
+test_log_env_setting(const char *env, int is_error)
+{
+ struct uinput_device* uidev;
+ struct libevdev *dev;
+ struct input_event ev;
+ int error_func_called = 0;
+
+ setenv("LIBEVDEV_LOG_EVENTS", env, 1);
+
+ libevdev_set_log_function(event_debug_log_error_func, &error_func_called);
+
+ test_create_device(&uidev, &dev,
+ EV_REL, REL_X,
+ EV_REL, REL_Y,
+ EV_KEY, BTN_LEFT,
+ EV_KEY, KEY_A,
+ EV_KEY, KEY_STOP,
+ -1);
+
+ uinput_device_event(uidev, EV_REL, REL_X, 1);
+ uinput_device_event(uidev, EV_KEY, BTN_LEFT, 1);
+ uinput_device_event(uidev, EV_SYN, SYN_REPORT, 0);
+
+ libevdev_next_event(dev, LIBEVDEV_READ_FLAG_NORMAL, &ev);
+ libevdev_next_event(dev, LIBEVDEV_READ_FLAG_NORMAL, &ev);
+ libevdev_next_event(dev, LIBEVDEV_READ_FLAG_NORMAL, &ev);
+
+ ck_assert_int_eq(error_func_called, is_error);
+
+ libevdev_set_log_function(test_logfunc_abort_on_error, NULL);
+
+ uinput_device_free(uidev);
+ libevdev_free(dev);
+}
+
+START_TEST(test_event_log_invalid_setting)
+{
+ const char *oldenv = getenv("LIBEVDEV_LOG_EVENTS");
+ enum libevdev_log_priority old = libevdev_get_log_priority();
+
+ libevdev_set_log_priority(LIBEVDEV_LOG_ERROR);
+
+ test_log_env_setting("", 0);
+ test_log_env_setting("foo", 1);
+ test_log_env_setting("debug:foo", 1);
+ test_log_env_setting("debug:event0", 0);
+ test_log_env_setting("debug:eventbanana", 0);
+ test_log_env_setting("debug:event0,event1", 0);
+ test_log_env_setting("debug:event0,", 0);
+ test_log_env_setting("debug:,event0,", 0);
+ test_log_env_setting("debug:/event0,", 1);
+ test_log_env_setting("debug:,,", 0);
+ test_log_env_setting("debug,", 1);
+
+ if (oldenv)
+ setenv("LIBEVDEV_LOG_EVENTS", oldenv, 1);
+ else
+ unsetenv("LIBEVDEV_LOG_EVENTS");
+
+ libevdev_set_log_priority(old);
+}
+END_TEST
+
Suite *
libevdev_events(void)
{
@@ -1890,6 +2159,12 @@ libevdev_events(void)
tcase_add_test(tc, test_event_mt_value_setters_current_slot);
suite_add_tcase(s, tc);
+ tc = tcase_create("event debug logging");
+ tcase_add_test(tc, test_event_log);
+ tcase_add_test(tc, test_event_log_per_device);
+ tcase_add_test(tc, test_event_log_invalid_setting);
+ suite_add_tcase(s, tc);
+
return s;
}
--
1.9.0
More information about the Input-tools
mailing list