From 030a0d79ffaa84cda267a9ca53d5a0768dbcd862 Mon Sep 17 00:00:00 2001 From: Luca Boccassi Date: Mon, 10 Aug 2020 11:24:51 +0100 Subject: [PATCH 1/6] udev-util: add device_wait_for_devlink Allows to wait for an event by matching on the devlink that gets created. --- src/shared/udev-util.c | 97 ++++++++++++++++++++++++++++++++++++------ src/shared/udev-util.h | 1 + 2 files changed, 84 insertions(+), 14 deletions(-) diff --git a/src/shared/udev-util.c b/src/shared/udev-util.c index 7cd7156a89..eb79bbbcf0 100644 --- a/src/shared/udev-util.c +++ b/src/shared/udev-util.c @@ -1,12 +1,14 @@ /* SPDX-License-Identifier: LGPL-2.1+ */ #include +#include #include "alloc-util.h" #include "device-util.h" #include "env-file.h" #include "log.h" #include "parse-util.h" +#include "path-util.h" #include "signal-util.h" #include "string-table.h" #include "string-util.h" @@ -108,8 +110,31 @@ int udev_parse_config_full( return 0; } +/* Note that if -ENOENT is returned, it will be logged at debug level rather than error, + * because it's an expected, common occurrence that the caller will handle with a fallback */ +static int device_new_from_dev_path(const char *devlink, sd_device **ret_device) { + struct stat st; + int r; + + assert(devlink); + + r = stat(devlink, &st); + if (r < 0) + return log_full_errno(errno == ENOENT ? LOG_DEBUG : LOG_ERR, errno, "Failed to stat() %s: %m", devlink); + + if (!S_ISBLK(st.st_mode)) + return log_error_errno(SYNTHETIC_ERRNO(ENOTBLK), "%s does not point to a block device: %m", devlink); + + r = sd_device_new_from_devnum(ret_device, 'b', st.st_rdev); + if (r < 0) + return log_error_errno(r, "Failed to initialize device from %s: %m", devlink); + + return 0; +} + struct DeviceMonitorData { const char *sysname; + const char *devlink; sd_device *device; }; @@ -119,37 +144,68 @@ static int device_monitor_handler(sd_device_monitor *monitor, sd_device *device, assert(device); assert(data); - assert(data->sysname); + assert(data->sysname || data->devlink); assert(!data->device); - if (sd_device_get_sysname(device, &sysname) >= 0 && streq(sysname, data->sysname)) { - data->device = sd_device_ref(device); - return sd_event_exit(sd_device_monitor_get_event(monitor), 0); + if (data->sysname && sd_device_get_sysname(device, &sysname) >= 0 && streq(sysname, data->sysname)) + goto found; + + if (data->devlink) { + const char *devlink; + + FOREACH_DEVICE_DEVLINK(device, devlink) + if (path_equal(devlink, data->devlink)) + goto found; + + if (sd_device_get_devname(device, &devlink) >= 0 && path_equal(devlink, data->devlink)) + goto found; } return 0; + +found: + data->device = sd_device_ref(device); + return sd_event_exit(sd_device_monitor_get_event(monitor), 0); } static int device_timeout_handler(sd_event_source *s, uint64_t usec, void *userdata) { return sd_event_exit(sd_event_source_get_event(s), -ETIMEDOUT); } -int device_wait_for_initialization(sd_device *device, const char *subsystem, usec_t timeout, sd_device **ret) { +static int device_wait_for_initialization_internal( + sd_device *_device, + const char *devlink, + const char *subsystem, + usec_t timeout, + sd_device **ret) { _cleanup_(sd_device_monitor_unrefp) sd_device_monitor *monitor = NULL; _cleanup_(sd_event_source_unrefp) sd_event_source *timeout_source = NULL; _cleanup_(sd_event_unrefp) sd_event *event = NULL; - struct DeviceMonitorData data = {}; + /* Ensure that if !_device && devlink, device gets unrefd on errors since it will be new */ + _cleanup_(sd_device_unrefp) sd_device *device = sd_device_ref(_device); + struct DeviceMonitorData data = { + .devlink = devlink, + }; int r; - assert(device); + assert(device || (subsystem && devlink)); - if (sd_device_get_is_initialized(device) > 0) { - if (ret) - *ret = sd_device_ref(device); - return 0; + /* Devlink might already exist, if it does get the device to use the sysname filtering */ + if (!device && devlink) { + r = device_new_from_dev_path(devlink, &device); + if (r < 0 && r != -ENOENT) + return r; } - assert_se(sd_device_get_sysname(device, &data.sysname) >= 0); + if (device) { + if (sd_device_get_is_initialized(device) > 0) { + if (ret) + *ret = sd_device_ref(device); + return 0; + } + /* We need either the sysname or the devlink for filtering */ + assert_se(sd_device_get_sysname(device, &data.sysname) >= 0 || devlink); + } /* Wait until the device is initialized, so that we can get access to the ID_PATH property */ @@ -161,7 +217,7 @@ int device_wait_for_initialization(sd_device *device, const char *subsystem, use if (r < 0) return log_error_errno(r, "Failed to acquire monitor: %m"); - if (!subsystem) { + if (device && !subsystem) { r = sd_device_get_subsystem(device, &subsystem); if (r < 0 && r != -ENOENT) return log_device_error_errno(device, r, "Failed to get subsystem: %m"); @@ -192,7 +248,12 @@ int device_wait_for_initialization(sd_device *device, const char *subsystem, use /* Check again, maybe things changed. Udev will re-read the db if the device wasn't initialized * yet. */ - if (sd_device_get_is_initialized(device) > 0) { + if (!device && devlink) { + r = device_new_from_dev_path(devlink, &device); + if (r < 0 && r != -ENOENT) + return r; + } + if (device && sd_device_get_is_initialized(device) > 0) { if (ret) *ret = sd_device_ref(device); return 0; @@ -207,6 +268,14 @@ int device_wait_for_initialization(sd_device *device, const char *subsystem, use return 0; } +int device_wait_for_initialization(sd_device *device, const char *subsystem, usec_t timeout, sd_device **ret) { + return device_wait_for_initialization_internal(device, NULL, subsystem, timeout, ret); +} + +int device_wait_for_devlink(const char *devlink, const char *subsystem, usec_t timeout, sd_device **ret) { + return device_wait_for_initialization_internal(NULL, devlink, subsystem, timeout, ret); +} + int device_is_renaming(sd_device *dev) { int r; diff --git a/src/shared/udev-util.h b/src/shared/udev-util.h index c35d29344f..04c7ce5520 100644 --- a/src/shared/udev-util.h +++ b/src/shared/udev-util.h @@ -29,5 +29,6 @@ static inline int udev_parse_config(void) { } int device_wait_for_initialization(sd_device *device, const char *subsystem, usec_t timeout, sd_device **ret); +int device_wait_for_devlink(const char *path, const char *subsystem, usec_t timeout, sd_device **ret); int device_is_renaming(sd_device *dev); bool device_for_action(sd_device *dev, DeviceAction action); From c419b6f0cf6c29d886a4325c186bd3f821745abc Mon Sep 17 00:00:00 2001 From: Luca Boccassi Date: Mon, 10 Aug 2020 11:19:22 +0100 Subject: [PATCH 2/6] dissect: wait for udev event if verity device not yet available The symlink /dev/mapper/dm_name is created by udev after a mapper device is set up. So libdevmapper/libcrypsetup might tell us that a verity device exists, but the symlink we use as the source for the mount operation might not be there yet. Instead of falling back to a new unique device set up, wait for the udev event matching on the expected devlink for at least 100ms (after which the benefits of sharing a device in terms of setup time start to disappear - on my production machines, opening a new verity device seems to take between 150ms and 300ms) --- src/shared/dissect-image.c | 13 +++++++++---- 1 file changed, 9 insertions(+), 4 deletions(-) diff --git a/src/shared/dissect-image.c b/src/shared/dissect-image.c index 8cbf4828b8..48b98c4f2d 100644 --- a/src/shared/dissect-image.c +++ b/src/shared/dissect-image.c @@ -1452,6 +1452,15 @@ static int verity_partition( if (!IN_SET(r, 0, -ENODEV, -ENOENT)) return log_debug_errno(r, "Checking whether existing verity device %s can be reused failed: %m", node); if (r == 0) { + /* devmapper might say that the device exists, but the devlink might not yet have been + * created. Check and wait for the udev event in that case. */ + r = device_wait_for_devlink(node, "block", 100 * USEC_PER_MSEC, NULL); + /* Fallback to activation with a unique device if it's taking too long */ + if (r == -ETIMEDOUT) + break; + if (r < 0) + return r; + if (cd) crypt_free(cd); cd = existing_cd; @@ -1461,10 +1470,6 @@ static int verity_partition( break; } - /* Sanity check: libdevmapper is known to report that the device already exists and is active, - * but it's actually not there, so the later filesystem probe or mount would fail. */ - if (r == 0) - r = access(node, F_OK); /* An existing verity device was reported by libcryptsetup/libdevmapper, but we can't use it at this time. * Fall back to activating it with a unique device name. */ if (r != 0 && FLAGS_SET(flags, DISSECT_IMAGE_VERITY_SHARE)) From 9ecb5c10fdfadc945fda93b0b28fb88d1102d399 Mon Sep 17 00:00:00 2001 From: Luca Boccassi Date: Mon, 10 Aug 2020 11:15:48 +0100 Subject: [PATCH 3/6] dissect: account for EBUSY when verity device already exists In some cases, libdevmapper/libcrypsetup might return EBUSY instead of EEXIST when opening a shared device. Treat it in the same way. --- src/shared/dissect-image.c | 21 ++++++++++++++------- 1 file changed, 14 insertions(+), 7 deletions(-) diff --git a/src/shared/dissect-image.c b/src/shared/dissect-image.c index 48b98c4f2d..97f0e46e78 100644 --- a/src/shared/dissect-image.c +++ b/src/shared/dissect-image.c @@ -1430,26 +1430,33 @@ static int verity_partition( * Improvements in libcrypsetup can ensure this never happens: https://gitlab.com/cryptsetup/cryptsetup/-/merge_requests/96 */ if (r == -EINVAL && FLAGS_SET(flags, DISSECT_IMAGE_VERITY_SHARE)) return verity_partition(m, v, root_hash, root_hash_size, verity_data, NULL, root_hash_sig ?: hash_sig_from_file, root_hash_sig_size, flags & ~DISSECT_IMAGE_VERITY_SHARE, d); - if (!IN_SET(r, 0, -EEXIST, -ENODEV)) + if (!IN_SET(r, + 0, /* Success */ + -EEXIST, /* Volume is already open and ready to be used */ + -EBUSY, /* Volume is being opened but not ready, crypt_init_by_name can fetch details */ + -ENODEV /* Volume is being opened but not ready, crypt_init_by_name would fail, try to open again */)) return r; - if (r == -EEXIST) { + if (IN_SET(r, -EEXIST, -EBUSY)) { struct crypt_device *existing_cd = NULL; if (!restore_deferred_remove){ /* To avoid races, disable automatic removal on umount while setting up the new device. Restore it on failure. */ r = dm_deferred_remove_cancel(name); - if (r < 0) + /* If activation returns EBUSY there might be no deferred removal to cancel, that's fine */ + if (r < 0 && r != -ENXIO) return log_debug_errno(r, "Disabling automated deferred removal for verity device %s failed: %m", node); - restore_deferred_remove = strdup(name); - if (!restore_deferred_remove) - return -ENOMEM; + if (r == 0) { + restore_deferred_remove = strdup(name); + if (!restore_deferred_remove) + return -ENOMEM; + } } r = verity_can_reuse(root_hash, root_hash_size, !!root_hash_sig || !!hash_sig_from_file, name, &existing_cd); /* Same as above, -EINVAL can randomly happen when it actually means -EEXIST */ if (r == -EINVAL && FLAGS_SET(flags, DISSECT_IMAGE_VERITY_SHARE)) return verity_partition(m, v, root_hash, root_hash_size, verity_data, NULL, root_hash_sig ?: hash_sig_from_file, root_hash_sig_size, flags & ~DISSECT_IMAGE_VERITY_SHARE, d); - if (!IN_SET(r, 0, -ENODEV, -ENOENT)) + if (!IN_SET(r, 0, -ENODEV, -ENOENT, -EBUSY)) return log_debug_errno(r, "Checking whether existing verity device %s can be reused failed: %m", node); if (r == 0) { /* devmapper might say that the device exists, but the devlink might not yet have been From ecab4c470cae07a65a10e9aa2aec3878a06f2904 Mon Sep 17 00:00:00 2001 From: Luca Boccassi Date: Mon, 10 Aug 2020 11:22:30 +0100 Subject: [PATCH 4/6] dissect: yield for 2ms when a verity device cannot be opened before retrying If we don't succeed on the first try it's because another process is opening the same device. Do a microsleep for 2ms to increase the chances it has completed the next time around the loop. --- src/shared/dissect-image.c | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/shared/dissect-image.c b/src/shared/dissect-image.c index 97f0e46e78..66b7ec5284 100644 --- a/src/shared/dissect-image.c +++ b/src/shared/dissect-image.c @@ -1475,6 +1475,9 @@ static int verity_partition( } if (r == 0) break; + + /* Device is being opened by another process, but it has not finished yet, yield for 2ms */ + (void) usleep(2 * USEC_PER_MSEC); } /* An existing verity device was reported by libcryptsetup/libdevmapper, but we can't use it at this time. From efc3b12fdbe38f023b70839df5653ecae5ce44d3 Mon Sep 17 00:00:00 2001 From: Luca Boccassi Date: Mon, 10 Aug 2020 11:45:07 +0100 Subject: [PATCH 5/6] tree-wide: enable/disable libcrypsetup debug output depending on our level Avoid always setting to debug, as it will incur in many more callbacks from libcrypsetup that then get discarded, wasting resources. --- src/cryptsetup/cryptsetup.c | 9 +++------ src/home/homework-luks.c | 12 ++++++------ src/partition/growfs.c | 6 ++---- src/shared/crypt-util.c | 8 +++++++- src/shared/crypt-util.h | 2 +- src/shared/dissect-image.c | 4 ++-- src/veritysetup/veritysetup.c | 4 ++-- 7 files changed, 23 insertions(+), 22 deletions(-) diff --git a/src/cryptsetup/cryptsetup.c b/src/cryptsetup/cryptsetup.c index 6d3f842dbe..8be9c9acac 100644 --- a/src/cryptsetup/cryptsetup.c +++ b/src/cryptsetup/cryptsetup.c @@ -839,10 +839,7 @@ static int run(int argc, char *argv[]) { log_setup_service(); - crypt_set_log_callback(NULL, cryptsetup_log_glue, NULL); - if (DEBUG_LOGGING) - /* libcryptsetup won't even consider debug messages by default */ - crypt_set_debug_level(CRYPT_DEBUG_ALL); + cryptsetup_enable_logging(cd); umask(0022); @@ -906,7 +903,7 @@ static int run(int argc, char *argv[]) { if (r < 0) return log_error_errno(r, "crypt_init() failed: %m"); - crypt_set_log_callback(cd, cryptsetup_log_glue, NULL); + cryptsetup_enable_logging(cd); status = crypt_status(cd, argv[2]); if (IN_SET(status, CRYPT_ACTIVE, CRYPT_BUSY)) { @@ -1032,7 +1029,7 @@ static int run(int argc, char *argv[]) { if (r < 0) return log_error_errno(r, "crypt_init_by_name() failed: %m"); - crypt_set_log_callback(cd, cryptsetup_log_glue, NULL); + cryptsetup_enable_logging(cd); r = crypt_deactivate(cd, argv[2]); if (r < 0) diff --git a/src/home/homework-luks.c b/src/home/homework-luks.c index b0f237c51b..1eb08e1423 100644 --- a/src/home/homework-luks.c +++ b/src/home/homework-luks.c @@ -238,7 +238,7 @@ static int luks_setup( if (r < 0) return log_error_errno(r, "Failed to allocate libcryptsetup context: %m"); - crypt_set_log_callback(cd, cryptsetup_log_glue, NULL); + cryptsetup_enable_logging(cd); r = crypt_load(cd, CRYPT_LUKS2, NULL); if (r < 0) @@ -338,7 +338,7 @@ static int luks_open( if (r < 0) return log_error_errno(r, "Failed to initialize cryptsetup context for %s: %m", dm_name); - crypt_set_log_callback(cd, cryptsetup_log_glue, NULL); + cryptsetup_enable_logging(cd); r = crypt_load(cd, CRYPT_LUKS2, NULL); if (r < 0) @@ -1335,7 +1335,7 @@ int home_deactivate_luks(UserRecord *h) { else { log_info("Discovered used LUKS device %s.", dm_node); - crypt_set_log_callback(cd, cryptsetup_log_glue, NULL); + cryptsetup_enable_logging(cd); r = crypt_deactivate(cd, dm_name); if (IN_SET(r, -ENODEV, -EINVAL, -ENOENT)) { @@ -1494,7 +1494,7 @@ static int luks_format( if (r < 0) return log_error_errno(r, "Failed to allocate libcryptsetup context: %m"); - crypt_set_log_callback(cd, cryptsetup_log_glue, NULL); + cryptsetup_enable_logging(cd); /* Normally we'd, just leave volume key generation to libcryptsetup. However, we can't, since we * can't extract the volume key from the library again, but we need it in order to encrypt the JSON @@ -2971,7 +2971,7 @@ int home_lock_luks(UserRecord *h) { return log_error_errno(r, "Failed to initialize cryptsetup context for %s: %m", dm_name); log_info("Discovered used LUKS device %s.", dm_node); - crypt_set_log_callback(cd, cryptsetup_log_glue, NULL); + cryptsetup_enable_logging(cd); if (syncfs(root_fd) < 0) /* Snake oil, but let's better be safe than sorry */ return log_error_errno(errno, "Failed to synchronize file system %s: %m", p); @@ -3036,7 +3036,7 @@ int home_unlock_luks(UserRecord *h, PasswordCache *cache) { return log_error_errno(r, "Failed to initialize cryptsetup context for %s: %m", dm_name); log_info("Discovered used LUKS device %s.", dm_node); - crypt_set_log_callback(cd, cryptsetup_log_glue, NULL); + cryptsetup_enable_logging(cd); r = -ENOKEY; FOREACH_POINTER(list, cache->pkcs11_passwords, cache->fido2_passwords, h->password) { diff --git a/src/partition/growfs.c b/src/partition/growfs.c index 98a7e4d31d..2728cb8ba8 100644 --- a/src/partition/growfs.c +++ b/src/partition/growfs.c @@ -56,7 +56,7 @@ static int resize_crypt_luks_device(dev_t devno, const char *fstype, dev_t main_ if (r < 0) return log_error_errno(r, "crypt_init(\"%s\") failed: %m", devpath); - crypt_set_log_callback(cd, cryptsetup_log_glue, NULL); + cryptsetup_enable_logging(cd); r = crypt_load(cd, CRYPT_LUKS, NULL); if (r < 0) @@ -85,9 +85,7 @@ static int maybe_resize_underlying_device(const char *mountpath, dev_t main_devn int r; #if HAVE_LIBCRYPTSETUP - crypt_set_log_callback(NULL, cryptsetup_log_glue, NULL); - if (DEBUG_LOGGING) - crypt_set_debug_level(CRYPT_DEBUG_ALL); + cryptsetup_enable_logging(NULL); #endif r = get_block_device_harder(mountpath, &devno); diff --git a/src/shared/crypt-util.c b/src/shared/crypt-util.c index 20bdc5489e..52bd12bb8d 100644 --- a/src/shared/crypt-util.c +++ b/src/shared/crypt-util.c @@ -4,7 +4,7 @@ #include "crypt-util.h" #include "log.h" -void cryptsetup_log_glue(int level, const char *msg, void *usrptr) { +static void cryptsetup_log_glue(int level, const char *msg, void *usrptr) { switch (level) { case CRYPT_LOG_NORMAL: level = LOG_NOTICE; @@ -25,4 +25,10 @@ void cryptsetup_log_glue(int level, const char *msg, void *usrptr) { log_full(level, "%s", msg); } + +void cryptsetup_enable_logging(struct crypt_device *cd) { + crypt_set_log_callback(cd, cryptsetup_log_glue, NULL); + crypt_set_debug_level(DEBUG_LOGGING ? CRYPT_DEBUG_ALL : CRYPT_DEBUG_NONE); +} + #endif diff --git a/src/shared/crypt-util.h b/src/shared/crypt-util.h index c25b11599c..b9f465fbc1 100644 --- a/src/shared/crypt-util.h +++ b/src/shared/crypt-util.h @@ -8,5 +8,5 @@ DEFINE_TRIVIAL_CLEANUP_FUNC(struct crypt_device *, crypt_free); -void cryptsetup_log_glue(int level, const char *msg, void *usrptr); +void cryptsetup_enable_logging(struct crypt_device *cd); #endif diff --git a/src/shared/dissect-image.c b/src/shared/dissect-image.c index 66b7ec5284..f41d1a0e48 100644 --- a/src/shared/dissect-image.c +++ b/src/shared/dissect-image.c @@ -1277,7 +1277,7 @@ static int decrypt_partition( if (r < 0) return log_debug_errno(r, "Failed to initialize dm-crypt: %m"); - crypt_set_log_callback(cd, cryptsetup_log_glue, NULL); + cryptsetup_enable_logging(cd); r = crypt_load(cd, CRYPT_LUKS, NULL); if (r < 0) @@ -1399,7 +1399,7 @@ static int verity_partition( if (r < 0) return r; - crypt_set_log_callback(cd, cryptsetup_log_glue, NULL); + cryptsetup_enable_logging(cd); r = crypt_load(cd, CRYPT_VERITY, NULL); if (r < 0) diff --git a/src/veritysetup/veritysetup.c b/src/veritysetup/veritysetup.c index e475402d9d..753777b6ad 100644 --- a/src/veritysetup/veritysetup.c +++ b/src/veritysetup/veritysetup.c @@ -73,7 +73,7 @@ static int run(int argc, char *argv[]) { if (r < 0) return log_error_errno(r, "Failed to open verity device %s: %m", argv[4]); - crypt_set_log_callback(cd, cryptsetup_log_glue, NULL); + cryptsetup_enable_logging(cd); status = crypt_status(cd, argv[2]); if (IN_SET(status, CRYPT_ACTIVE, CRYPT_BUSY)) { @@ -124,7 +124,7 @@ static int run(int argc, char *argv[]) { if (r < 0) return log_error_errno(r, "crypt_init_by_name() failed: %m"); - crypt_set_log_callback(cd, cryptsetup_log_glue, NULL); + cryptsetup_enable_logging(cd); r = crypt_deactivate(cd, argv[2]); if (r < 0) From ce5eef6530095961ad52e3b9974c8ad60579cacf Mon Sep 17 00:00:00 2001 From: Luca Boccassi Date: Fri, 14 Aug 2020 11:05:42 +0100 Subject: [PATCH 6/6] shared/udev-util: fix sd_device leak in device_wait_for_initialization If the caller doesn't pass a return pointer, or if sd_event_loop fails after the device was found and referenced, it never gets dereferenced. --- src/shared/udev-util.c | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/src/shared/udev-util.c b/src/shared/udev-util.c index eb79bbbcf0..8b27a6d0d0 100644 --- a/src/shared/udev-util.c +++ b/src/shared/udev-util.c @@ -138,6 +138,12 @@ struct DeviceMonitorData { sd_device *device; }; +static void device_monitor_data_free(struct DeviceMonitorData *d) { + assert(d); + + sd_device_unref(d->device); +} + static int device_monitor_handler(sd_device_monitor *monitor, sd_device *device, void *userdata) { struct DeviceMonitorData *data = userdata; const char *sysname; @@ -183,7 +189,7 @@ static int device_wait_for_initialization_internal( _cleanup_(sd_event_unrefp) sd_event *event = NULL; /* Ensure that if !_device && devlink, device gets unrefd on errors since it will be new */ _cleanup_(sd_device_unrefp) sd_device *device = sd_device_ref(_device); - struct DeviceMonitorData data = { + _cleanup_(device_monitor_data_free) struct DeviceMonitorData data = { .devlink = devlink, }; int r;