From 6c7afdeab010025c80508effd2b0039bc5181b82 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Zbigniew=20J=C4=99drzejewski-Szmek?= Date: Thu, 18 Feb 2021 10:40:16 +0100 Subject: [PATCH 1/2] rfkill: improve error logging If we get something of unexpected size, log the sizes. Also, don't log twice. --- src/rfkill/rfkill.c | 64 ++++++++++++++++++++------------------------- 1 file changed, 29 insertions(+), 35 deletions(-) diff --git a/src/rfkill/rfkill.c b/src/rfkill/rfkill.c index 91dc72f425..238d2cb579 100644 --- a/src/rfkill/rfkill.c +++ b/src/rfkill/rfkill.c @@ -135,8 +135,6 @@ static int determine_state_file( static int load_state(Context *c, const struct rfkill_event *event) { _cleanup_free_ char *state_file = NULL, *value = NULL; - struct rfkill_event we; - ssize_t l; int b, r; assert(c); @@ -168,18 +166,19 @@ static int load_state(Context *c, const struct rfkill_event *event) { if (b < 0) return log_error_errno(b, "Failed to parse state file %s: %m", state_file); - we = (struct rfkill_event) { - .op = RFKILL_OP_CHANGE, + struct rfkill_event we = { .idx = event->idx, + .op = RFKILL_OP_CHANGE, .soft = b, }; - l = write(c->rfkill_fd, &we, sizeof(we)); + ssize_t l = write(c->rfkill_fd, &we, sizeof we); if (l < 0) return log_error_errno(errno, "Failed to restore rfkill state for %i: %m", event->idx); - if (l != sizeof(we)) + if (l != sizeof we) return log_error_errno(SYNTHETIC_ERRNO(EIO), - "Couldn't write rfkill event structure, too short."); + "Couldn't write rfkill event structure, too short (wrote %zd of %zu bytes).", + l, sizeof we); log_debug("Loaded state '%s' from %s.", one_zero(b), state_file); return 0; @@ -306,43 +305,38 @@ static int run(int argc, char *argv[]) { for (;;) { struct rfkill_event event; - const char *type; - ssize_t l; - l = read(c.rfkill_fd, &event, sizeof(event)); + ssize_t l = read(c.rfkill_fd, &event, sizeof event); if (l < 0) { - if (errno == EAGAIN) { + if (errno != EAGAIN) + return log_error_errno(errno, "Failed to read from /dev/rfkill: %m"); - if (!ready) { - /* Notify manager that we are - * now finished with - * processing whatever was - * queued */ - (void) sd_notify(false, "READY=1"); - ready = true; - } - - /* Hang around for a bit, maybe there's more coming */ - - r = fd_wait_for_event(c.rfkill_fd, POLLIN, EXIT_USEC); - if (r == -EINTR) - continue; - if (r < 0) - return log_error_errno(r, "Failed to poll() on device: %m"); - if (r > 0) - continue; - - log_debug("All events read and idle, exiting."); - break; + if (!ready) { + /* Notify manager that we are now finished with processing whatever was + * queued */ + (void) sd_notify(false, "READY=1"); + ready = true; } - log_error_errno(errno, "Failed to read from /dev/rfkill: %m"); + /* Hang around for a bit, maybe there's more coming */ + + r = fd_wait_for_event(c.rfkill_fd, POLLIN, EXIT_USEC); + if (r == -EINTR) + continue; + if (r < 0) + return log_error_errno(r, "Failed to poll() on device: %m"); + if (r > 0) + continue; + + log_debug("All events read and idle, exiting."); + break; } if (l != RFKILL_EVENT_SIZE_V1) - return log_error_errno(SYNTHETIC_ERRNO(EIO), "Read event structure of invalid size."); + return log_error_errno(SYNTHETIC_ERRNO(EIO), "Read event structure of unexpected size (%zd, not %d)", + l, RFKILL_EVENT_SIZE_V1); - type = rfkill_type_to_string(event.type); + const char *type = rfkill_type_to_string(event.type); if (!type) { log_debug("An rfkill device of unknown type %i discovered, ignoring.", event.type); continue; From a71c09685021cbcecb7566a00342421f635cc002 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Zbigniew=20J=C4=99drzejewski-Szmek?= Date: Thu, 18 Feb 2021 10:48:08 +0100 Subject: [PATCH 2/2] rfkill: use short writes and accept long reads I'm seeing the following with kernel-core-5.10.16-200.fc33.x86_64: $ sudo SYSTEMD_LOG_LEVEL=debug build/systemd-rfkill Reading struct rfkill_event: got 8 bytes. A new rfkill device has been added with index 0 and type bluetooth. Found cgroup2 on /sys/fs/cgroup/, full unified hierarchy Found container virtualization none. rfkill0: Operating on rfkill device 'tpacpi_bluetooth_sw'. Writing struct rfkill_event successful (8 of 9 bytes). Loaded state '0' from /var/lib/systemd/rfkill/platform-thinkpad_acpi:bluetooth. Reading struct rfkill_event: got 8 bytes. A new rfkill device has been added with index 1 and type wwan. rfkill1: Operating on rfkill device 'tpacpi_wwan_sw'. Writing struct rfkill_event successful (8 of 9 bytes). Loaded state '0' from /var/lib/systemd/rfkill/platform-thinkpad_acpi:wwan. Reading struct rfkill_event: got 8 bytes. A new rfkill device has been added with index 2 and type bluetooth. rfkill2: Operating on rfkill device 'hci0'. Writing struct rfkill_event successful (8 of 9 bytes). Loaded state '0' from /var/lib/systemd/rfkill/pci-0000:00:14.0-usb-0:7:1.0:bluetooth. Reading struct rfkill_event: got 8 bytes. A new rfkill device has been added with index 3 and type wlan. rfkill3: Operating on rfkill device 'phy0'. Writing struct rfkill_event successful (8 of 9 bytes). Loaded state '0' from /var/lib/systemd/rfkill/pci-0000:04:00.0:wlan. All events read and idle, exiting. We were expecting a read of exactly RFKILL_EVENT_SIZE_V1==8 bytes. But the structure has 9 after [1]. [1] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=14486c82612a177cb910980c70ba900827ca0894 For some reason the kernel does not accept the full structure size, but cuts the write short after 8 bytes: static ssize_t rfkill_fop_write(struct file *file, const char __user *buf, size_t count, loff_t *pos) { struct rfkill_event ev; /* we don't need the 'hard' variable but accept it */ if (count < RFKILL_EVENT_SIZE_V1 - 1) return -EINVAL; /* * Copy as much data as we can accept into our 'ev' buffer, * but tell userspace how much we've copied so it can determine * our API version even in a write() call, if it cares. */ count = min(count, sizeof(ev)); if (copy_from_user(&ev, buf, count)) return -EFAULT; ... so it should accept the full size. I'm not sure what is going on here. But we don't care about the extra fields, so let's accept a write as long as it's at least RFKILL_EVENT_SIZE_V1. Fixes #18677. --- src/rfkill/rfkill.c | 17 +++++++++++++---- 1 file changed, 13 insertions(+), 4 deletions(-) diff --git a/src/rfkill/rfkill.c b/src/rfkill/rfkill.c index 238d2cb579..e2d1a1be5f 100644 --- a/src/rfkill/rfkill.c +++ b/src/rfkill/rfkill.c @@ -171,14 +171,17 @@ static int load_state(Context *c, const struct rfkill_event *event) { .op = RFKILL_OP_CHANGE, .soft = b, }; + assert_cc(offsetof(struct rfkill_event, op) < RFKILL_EVENT_SIZE_V1); + assert_cc(offsetof(struct rfkill_event, soft) < RFKILL_EVENT_SIZE_V1); ssize_t l = write(c->rfkill_fd, &we, sizeof we); if (l < 0) return log_error_errno(errno, "Failed to restore rfkill state for %i: %m", event->idx); - if (l != sizeof we) + if (l < RFKILL_EVENT_SIZE_V1) return log_error_errno(SYNTHETIC_ERRNO(EIO), "Couldn't write rfkill event structure, too short (wrote %zd of %zu bytes).", l, sizeof we); + log_debug("Writing struct rfkill_event successful (%zd of %zu bytes).", l, sizeof we); log_debug("Loaded state '%s' from %s.", one_zero(b), state_file); return 0; @@ -304,7 +307,7 @@ static int run(int argc, char *argv[]) { } for (;;) { - struct rfkill_event event; + struct rfkill_event event = {}; ssize_t l = read(c.rfkill_fd, &event, sizeof event); if (l < 0) { @@ -332,9 +335,15 @@ static int run(int argc, char *argv[]) { break; } - if (l != RFKILL_EVENT_SIZE_V1) - return log_error_errno(SYNTHETIC_ERRNO(EIO), "Read event structure of unexpected size (%zd, not %d)", + if (l < RFKILL_EVENT_SIZE_V1) + return log_error_errno(SYNTHETIC_ERRNO(EIO), "Short read of struct rfkill_event: (%zd < %d)", l, RFKILL_EVENT_SIZE_V1); + log_debug("Reading struct rfkill_event: got %zd bytes.", l); + + /* The event structure has more fields. We only care about the first few, so it's OK if we + * don't read the full structure. */ + assert_cc(offsetof(struct rfkill_event, op) < RFKILL_EVENT_SIZE_V1); + assert_cc(offsetof(struct rfkill_event, type) < RFKILL_EVENT_SIZE_V1); const char *type = rfkill_type_to_string(event.type); if (!type) {