diff --git a/src/update-utmp/update-utmp.c b/src/update-utmp/update-utmp.c index 4996272eb3..5651ec11da 100644 --- a/src/update-utmp/update-utmp.c +++ b/src/update-utmp/update-utmp.c @@ -20,11 +20,13 @@ #include "macro.h" #include "main-func.h" #include "process-util.h" +#include "random-util.h" #include "special.h" #include "stdio-util.h" #include "strv.h" #include "unit-name.h" #include "utmp-wtmp.h" +#include "verbs.h" typedef struct Context { sd_bus *bus; @@ -44,20 +46,23 @@ static void context_clear(Context *c) { #endif } -static usec_t get_startup_monotonic_time(Context *c) { +static int get_startup_monotonic_time(Context *c, usec_t *ret) { _cleanup_(sd_bus_error_free) sd_bus_error error = SD_BUS_ERROR_NULL; - usec_t t = 0; int r; assert(c); + assert(ret); - r = bus_get_property_trivial(c->bus, bus_systemd_mgr, "UserspaceTimestampMonotonic", &error, 't', &t); - if (r < 0) { - log_error_errno(r, "Failed to get timestamp: %s", bus_error_message(&error, r)); - return 0; - } + r = bus_get_property_trivial( + c->bus, + bus_systemd_mgr, + "UserspaceTimestampMonotonic", + &error, + 't', ret); + if (r < 0) + return log_warning_errno(r, "Failed to get timestamp, ignoring: %s", bus_error_message(&error, r)); - return t; + return 0; } static int get_current_runlevel(Context *c) { @@ -65,116 +70,129 @@ static int get_current_runlevel(Context *c) { const int runlevel; const char *special; } table[] = { - /* The first target of this list that is active or has - * a job scheduled wins. We prefer runlevels 5 and 3 - * here over the others, since these are the main - * runlevels used on Fedora. It might make sense to - * change the order on some distributions. */ + /* The first target of this list that is active or has a job scheduled wins. We prefer + * runlevels 5 and 3 here over the others, since these are the main runlevels used on Fedora. + * It might make sense to change the order on some distributions. */ { '5', SPECIAL_GRAPHICAL_TARGET }, { '3', SPECIAL_MULTI_USER_TARGET }, { '1', SPECIAL_RESCUE_TARGET }, }; - - _cleanup_(sd_bus_error_free) sd_bus_error error = SD_BUS_ERROR_NULL; int r; assert(c); - for (size_t i = 0; i < ELEMENTSOF(table); i++) { - _cleanup_free_ char *state = NULL, *path = NULL; + for (unsigned n_attempts = 0;;) { + FOREACH_ARRAY(e, table, ELEMENTSOF(table)) { + _cleanup_(sd_bus_error_free) sd_bus_error error = SD_BUS_ERROR_NULL; + _cleanup_free_ char *state = NULL, *path = NULL; - path = unit_dbus_path_from_name(table[i].special); - if (!path) - return log_oom(); + path = unit_dbus_path_from_name(e->special); + if (!path) + return log_oom(); - r = sd_bus_get_property_string( - c->bus, - "org.freedesktop.systemd1", - path, - "org.freedesktop.systemd1.Unit", - "ActiveState", - &error, - &state); + r = sd_bus_get_property_string( + c->bus, + "org.freedesktop.systemd1", + path, + "org.freedesktop.systemd1.Unit", + "ActiveState", + &error, + &state); + if ((r == -ENOTCONN || + sd_bus_error_has_names(&error, + SD_BUS_ERROR_NO_REPLY, + SD_BUS_ERROR_DISCONNECTED)) && + ++n_attempts < 64) { + + /* systemd might have dropped off momentarily, let's not make this an error, + * and wait some random time. Let's pick a random time in the range 0ms…250ms, + * linearly scaled by the number of failed attempts. */ + + usec_t usec = random_u64_range(UINT64_C(10) * USEC_PER_MSEC + + UINT64_C(240) * USEC_PER_MSEC * n_attempts/64); + log_debug_errno(r, "Failed to get state of %s, retrying after %s: %s", + e->special, FORMAT_TIMESPAN(usec, USEC_PER_MSEC), bus_error_message(&error, r)); + (void) usleep(usec); + goto reconnect; + } + if (r < 0) + return log_warning_errno(r, "Failed to get state of %s: %s", e->special, bus_error_message(&error, r)); + + if (STR_IN_SET(state, "active", "reloading")) + return e->runlevel; + } + + return 0; + +reconnect: + c->bus = sd_bus_flush_close_unref(c->bus); + r = bus_connect_system_systemd(&c->bus); if (r < 0) - return log_warning_errno(r, "Failed to get state: %s", bus_error_message(&error, r)); - - if (STR_IN_SET(state, "active", "reloading")) - return table[i].runlevel; + return log_error_errno(r, "Failed to reconnect to system bus: %m"); } - - return 0; } -static int on_reboot(Context *c) { - int r = 0, q; - usec_t t; - usec_t boottime; +static int on_reboot(int argc, char *argv[], void *userdata) { + Context *c = ASSERT_PTR(userdata); + usec_t t = 0, boottime; + int r, q = 0; - assert(c); - - /* We finished start-up, so let's write the utmp - * record and send the audit msg */ + /* We finished start-up, so let's write the utmp record and send the audit msg. */ #if HAVE_AUDIT if (c->audit_fd >= 0) if (audit_log_user_comm_message(c->audit_fd, AUDIT_SYSTEM_BOOT, "", "systemd-update-utmp", NULL, NULL, NULL, 1) < 0 && errno != EPERM) - r = log_error_errno(errno, "Failed to send audit message: %m"); + q = log_error_errno(errno, "Failed to send audit message: %m"); #endif - /* If this call fails it will return 0, which - * utmp_put_reboot() will then fix to the current time */ - t = get_startup_monotonic_time(c); + /* If this call fails, then utmp_put_reboot() will fix to the current time. */ + (void) get_startup_monotonic_time(c, &t); boottime = map_clock_usec(t, CLOCK_MONOTONIC, CLOCK_REALTIME); - /* We query the recorded monotonic time here (instead of the system clock CLOCK_REALTIME), - * even though we actually want the system clock time. That's because there's a likely - * chance that the system clock wasn't set right during early boot. By manually converting - * the monotonic clock to the system clock here we can compensate - * for incorrectly set clocks during early boot. */ + /* We query the recorded monotonic time here (instead of the system clock CLOCK_REALTIME), even + * though we actually want the system clock time. That's because there's a likely chance that the + * system clock wasn't set right during early boot. By manually converting the monotonic clock to the + * system clock here we can compensate for incorrectly set clocks during early boot. */ - q = utmp_put_reboot(boottime); - if (q < 0) - r = log_error_errno(q, "Failed to write utmp record: %m"); + r = utmp_put_reboot(boottime); + if (r < 0) + return log_error_errno(r, "Failed to write utmp record: %m"); - return r; + return q; } -static int on_shutdown(Context *c) { - int r = 0, q; +static int on_shutdown(int argc, char *argv[], void *userdata) { + int r, q = 0; - assert(c); - - /* We started shut-down, so let's write the utmp - * record and send the audit msg */ + /* We started shut-down, so let's write the utmp record and send the audit msg. */ #if HAVE_AUDIT + Context *c = ASSERT_PTR(userdata); + if (c->audit_fd >= 0) if (audit_log_user_comm_message(c->audit_fd, AUDIT_SYSTEM_SHUTDOWN, "", "systemd-update-utmp", NULL, NULL, NULL, 1) < 0 && errno != EPERM) - r = log_error_errno(errno, "Failed to send audit message: %m"); + q = log_error_errno(errno, "Failed to send audit message: %m"); #endif - q = utmp_put_shutdown(); - if (q < 0) - r = log_error_errno(q, "Failed to write utmp record: %m"); + r = utmp_put_shutdown(); + if (r < 0) + return log_error_errno(r, "Failed to write utmp record: %m"); - return r; + return q; } -static int on_runlevel(Context *c) { - int r = 0, q, previous, runlevel; +static int on_runlevel(int argc, char *argv[], void *userdata) { + Context *c = ASSERT_PTR(userdata); + int r, q = 0, previous, runlevel; - assert(c); - - /* We finished changing runlevel, so let's write the - * utmp record and send the audit msg */ + /* We finished changing runlevel, so let's write the utmp record and send the audit msg. */ /* First, get last runlevel */ - q = utmp_get_runlevel(&previous, NULL); - - if (q < 0) { - if (!IN_SET(q, -ESRCH, -ENOENT)) - return log_error_errno(q, "Failed to get current runlevel: %m"); + r = utmp_get_runlevel(&previous, NULL); + if (r < 0) { + if (!IN_SET(r, -ESRCH, -ENOENT)) + return log_error_errno(r, "Failed to get the last runlevel from utmp: %m"); previous = 0; } @@ -184,7 +202,7 @@ static int on_runlevel(Context *c) { if (runlevel < 0) return runlevel; if (runlevel == 0) { - log_warning("Failed to get new runlevel, utmp update skipped."); + log_warning("Failed to get the current runlevel, utmp update skipped."); return 0; } @@ -201,18 +219,25 @@ static int on_runlevel(Context *c) { if (audit_log_user_comm_message(c->audit_fd, AUDIT_SYSTEM_RUNLEVEL, s, "systemd-update-utmp", NULL, NULL, NULL, 1) < 0 && errno != EPERM) - r = log_error_errno(errno, "Failed to send audit message: %m"); + q = log_error_errno(errno, "Failed to send audit message: %m"); } #endif - q = utmp_put_runlevel(runlevel, previous); - if (q < 0 && !IN_SET(q, -ESRCH, -ENOENT)) - return log_error_errno(q, "Failed to write utmp record: %m"); + r = utmp_put_runlevel(runlevel, previous); + if (r < 0 && !IN_SET(r, -ESRCH, -ENOENT)) + return log_error_errno(r, "Failed to write utmp record: %m"); - return r; + return q; } static int run(int argc, char *argv[]) { + static const Verb verbs[] = { + { "reboot", 1, 1, 0, on_reboot }, + { "shutdown", 1, 1, 0, on_shutdown }, + { "runlevel", 1, 1, 0, on_runlevel }, + {} + }; + _cleanup_(context_clear) Context c = { #if HAVE_AUDIT .audit_fd = -EBADF, @@ -220,10 +245,6 @@ static int run(int argc, char *argv[]) { }; int r; - if (argc != 2) - return log_error_errno(SYNTHETIC_ERRNO(EINVAL), - "This program requires one argument."); - log_setup(); umask(0022); @@ -232,20 +253,14 @@ static int run(int argc, char *argv[]) { /* If the kernel lacks netlink or audit support, don't worry about it. */ c.audit_fd = audit_open(); if (c.audit_fd < 0) - log_full_errno(IN_SET(errno, EAFNOSUPPORT, EPROTONOSUPPORT) ? LOG_DEBUG : LOG_ERR, - errno, "Failed to connect to audit log: %m"); + log_full_errno(IN_SET(errno, EAFNOSUPPORT, EPROTONOSUPPORT) ? LOG_DEBUG : LOG_WARNING, + errno, "Failed to connect to audit log, ignoring: %m"); #endif r = bus_connect_system_systemd(&c.bus); if (r < 0) return log_error_errno(r, "Failed to get D-Bus connection: %m"); - if (streq(argv[1], "reboot")) - return on_reboot(&c); - if (streq(argv[1], "shutdown")) - return on_shutdown(&c); - if (streq(argv[1], "runlevel")) - return on_runlevel(&c); - return log_error_errno(SYNTHETIC_ERRNO(EINVAL), "Unknown command %s", argv[1]); + return dispatch_verb(argc, argv, verbs, &c); } DEFINE_MAIN_FUNCTION(run); diff --git a/test/units/testsuite-01.service b/test/units/testsuite-01.service index a55cc526a5..9074e0968f 100644 --- a/test/units/testsuite-01.service +++ b/test/units/testsuite-01.service @@ -1,10 +1,7 @@ # SPDX-License-Identifier: LGPL-2.1-or-later [Unit] Description=TEST-01-BASIC -# Order the test unit after systemd-update-utmp-runlevel.service, since -# the service doesn't play well with daemon-reexec -# See: https://github.com/systemd/systemd/issues/27167 -After=multi-user.target systemd-update-utmp-runlevel.service +After=multi-user.target Wants=systemd-resolved.service systemd-networkd.service [Service] diff --git a/test/units/testsuite-01.sh b/test/units/testsuite-01.sh index 91dd47ca14..475eaa2923 100755 --- a/test/units/testsuite-01.sh +++ b/test/units/testsuite-01.sh @@ -44,4 +44,17 @@ systemctl daemon-reload # of systemd-analyze blame. See issue #27187. systemd-analyze blame +# Test for 'systemd-update-utmp runlevel' vs 'systemctl daemon-reexec'. +# See issue #27163. +# shellcheck disable=SC2034 +for _ in {0..10}; do + systemctl daemon-reexec & + pid_reexec=$! + # shellcheck disable=SC2034 + for _ in {0..10}; do + SYSTEMD_LOG_LEVEL=debug /usr/lib/systemd/systemd-update-utmp runlevel + done + wait "$pid_reexec" +done + echo OK >/testok