[PATCH v2 libevdev] Enable event logging on request

Peter Hutterer peter.hutterer at who-t.net
Sun Apr 6 16:22:04 PDT 2014


On Fri, Apr 04, 2014 at 10:04:01PM +0200, David Herrmann wrote:
> Hi
> 
> On Fri, Apr 4, 2014 at 4:54 AM, Peter Hutterer <peter.hutterer at who-t.net> wrote:
> > 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);
> 
> This chains the default log-level test here. So LIBEVDEV_LOG_EVENTS
> still requires a suitable LIBEVDEV_LOG_LEVEL. Is that intentional?
> Wasn't clear to me from the documentation, you might wanna add that
> (or maybe I missed it, then I'm sorry..).
> 
> Or how about forcing the log-level to DEBUG in case LIBEVDEV_LOG_EVENTS is
> set?

my main argument for having the priority in the env variable was because
that enables the logging system to take care of it. so let's say the X server
would be hooked up nicely for logging from libevdev (it isn't atm) you could
control where this stuff should show up and at what verbosity level.
debug my end up in the log file only, but error may end up on stderr, or
something like that. This is a lot of logspam, not forcing it into debug
means we can use debug for other messages that don't have the same volume of
spam without running the risk of everyone ignoring it.

> > +}
> > +
> >  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);
> 
> What are you doing? You iterate "/dev/input/" until you find an
> event-node with the same major-minor than the fd? Why not use:
> 
> sprintf(buf, "event%d", minor(st.st_rdev));
> 
> and be done with it. You might wanna use "access(.., F_OK)" to see
> whether the node really exists, but even that is not needed, imho.
>
> - all nodes have _hardcoded_ names in /sys (/sys/class/input/eventXY)
> and these IDs are guaranteed to be equal to the minor-ID!

huh, funny that. yes, you're right, this is a lot simpler. Having said that,
the reason I never noticed this before is because there is an offset of 64.
And that e.g. 69 always maps to event5 is not immediately obvious, just just
assumed it kept incrementing in some unspecified manner.

> - your code _filters_ for nodes called "eventX"
> - the kernel _hardcodes_ the input/event<minor> path
> => The only reason the node doesn't exist but we need that scanning,
> is if someone _intentionally_ destroys device-nodes and recreates with
> different IDs. In that case, the 'eventXY'-nodes in /dev/input/ would
> differ from the names in /sys/class/input/. That is so _wrong_ that I
> don't think we should ever encourage people to do that.

The extra check was to verify that between us getting the fd and doing this
check the device hadn't disappeared. if you're not aware of the hardcoded
minor, then that all makes sense :)

> 
> > +
> > +       return node;
> > +}
> > +
> > +static void
> > +enable_event_logging(struct libevdev *dev)
> 
> I think "enable_event_logging()" is a misleading name here as it gives
> the impression it enables it _unconditionally_. I don't have any
> better idea, though. So up to the native speak to decide..

this one I'll leave as-is, but I did add a comment to make it obvious that
it only does it on the env variable to be set. Functions that start with
"maybe" are even worse, imo.

> > +{
> > +       enum libevdev_log_priority pri = 0;
> > +       const char *env;
> > +       char *tmp = NULL,
> > +            *tok = NULL, *saveptr;
> > +       char *node;
> > +
> > +       env = getenv("LIBEVDEV_LOG_EVENTS");
> 
> Are you sure you don't want to use secure_getenv()? Yes, we obfuscate
> most input, but I still think it's wrong to allow users to trigger
> that without privileges.

tbh that would pretty much defeat the usefulness of the patch. Xorg, for
now, is still setuid root and thus the whole point of allowing simple
debugging of events would be moot. Having said that, I'm still trying to
figure out a better way than this, it's not as easy as I hoped. Most users
run display managers of some sorts, so passing an environment variable to X
is more complicated than I want.

> > +       if (!env || strlen(env) == 0)
> > +               return;
> > +
> > +       if (dev->debug.device_node)
> > +               free(dev->debug.device_node);
> 
> Please add "dev->debug.device_node = NULL;", otherwise your
> error-paths are wrong and you trigger double-free assertions.

amended.

> > +
> > +       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) {
> 
> tok = "event15"
> node = "event1"
> 
> => false positive
> 
> You need to test "tok[strlen(node)] == 0".
> 
> Btw., strtok_r() sets a terminating zero, right? (otherwise, the
> strdup() would be redundant..) So why not use strcmp()?

yes, strtok_r sets a terminating zero and can't work on a const char. but
the strncmp isn't necessary, especially since we can trust the data in
"node" anyway. amended.

> 
> > +                       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)
> >  {
..
> > 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".
> > + *
> 
> I'm still not big fan of it, but that's personal taste. Acked-by-me
> and if you fix the issues, I can do another review. Code looks fine
> besides the minor issues I pointed out.

I'd still appreciate ideas for better approaches to this. libevev is the
lowest common denominator and the best point to hook in to debug event
sequences. Any idea for event logging that doesn't require building the
higher layers of the stack will be considered.

Cheers,
   Peter



More information about the Input-tools mailing list