diff options
Diffstat (limited to 'src/analyze/analyze-time-data.c')
| -rw-r--r-- | src/analyze/analyze-time-data.c | 331 |
1 files changed, 331 insertions, 0 deletions
diff --git a/src/analyze/analyze-time-data.c b/src/analyze/analyze-time-data.c new file mode 100644 index 0000000..741cab3 --- /dev/null +++ b/src/analyze/analyze-time-data.c @@ -0,0 +1,331 @@ +/* SPDX-License-Identifier: LGPL-2.1-or-later */ + +#include "analyze-time-data.h" +#include "analyze.h" +#include "bus-error.h" +#include "bus-locator.h" +#include "bus-map-properties.h" +#include "bus-unit-util.h" +#include "memory-util.h" +#include "special.h" +#include "strv.h" + +static void subtract_timestamp(usec_t *a, usec_t b) { + assert(a); + + if (*a > 0) { + assert(*a >= b); + *a -= b; + } +} + +static int log_not_finished(usec_t finish_time) { + return log_error_errno(SYNTHETIC_ERRNO(EINPROGRESS), + "Bootup is not yet finished (org.freedesktop.systemd1.Manager.FinishTimestampMonotonic=%"PRIu64").\n" + "Please try again later.\n" + "Hint: Use 'systemctl%s list-jobs' to see active jobs", + finish_time, + arg_runtime_scope == RUNTIME_SCOPE_SYSTEM ? "" : " --user"); +} + +int acquire_boot_times(sd_bus *bus, bool require_finished, BootTimes **ret) { + static const struct bus_properties_map property_map[] = { + { "FirmwareTimestampMonotonic", "t", NULL, offsetof(BootTimes, firmware_time) }, + { "LoaderTimestampMonotonic", "t", NULL, offsetof(BootTimes, loader_time) }, + { "KernelTimestamp", "t", NULL, offsetof(BootTimes, kernel_time) }, + { "InitRDTimestampMonotonic", "t", NULL, offsetof(BootTimes, initrd_time) }, + { "UserspaceTimestampMonotonic", "t", NULL, offsetof(BootTimes, userspace_time) }, + { "FinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, finish_time) }, + { "SecurityStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, security_start_time) }, + { "SecurityFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, security_finish_time) }, + { "GeneratorsStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, generators_start_time) }, + { "GeneratorsFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, generators_finish_time) }, + { "UnitsLoadStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, unitsload_start_time) }, + { "UnitsLoadFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, unitsload_finish_time) }, + { "InitRDSecurityStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, initrd_security_start_time) }, + { "InitRDSecurityFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, initrd_security_finish_time) }, + { "InitRDGeneratorsStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, initrd_generators_start_time) }, + { "InitRDGeneratorsFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, initrd_generators_finish_time) }, + { "InitRDUnitsLoadStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, initrd_unitsload_start_time) }, + { "InitRDUnitsLoadFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, initrd_unitsload_finish_time) }, + {}, + }; + _cleanup_(sd_bus_error_free) sd_bus_error error = SD_BUS_ERROR_NULL; + static BootTimes times; + static bool cached = false; + int r; + + if (cached) { + if (require_finished && times.finish_time <= 0) + return log_not_finished(times.finish_time); + + if (ret) + *ret = × + return 0; + } + + assert_cc(sizeof(usec_t) == sizeof(uint64_t)); + + r = bus_map_all_properties( + bus, + "org.freedesktop.systemd1", + "/org/freedesktop/systemd1", + property_map, + BUS_MAP_STRDUP, + &error, + NULL, + ×); + if (r < 0) + return log_error_errno(r, "Failed to get timestamp properties: %s", bus_error_message(&error, r)); + + if (require_finished && times.finish_time <= 0) + return log_not_finished(times.finish_time); + + if (arg_runtime_scope == RUNTIME_SCOPE_SYSTEM && times.security_start_time > 0) { + /* security_start_time is set when systemd is not running under container environment. */ + if (times.initrd_time > 0) + times.kernel_done_time = times.initrd_time; + else + times.kernel_done_time = times.userspace_time; + } else { + /* + * User-instance-specific or container-system-specific timestamps processing + * (see comment to reverse_offset in BootTimes). + */ + times.reverse_offset = times.userspace_time; + + times.firmware_time = times.loader_time = times.kernel_time = times.initrd_time = + times.userspace_time = times.security_start_time = times.security_finish_time = 0; + + if (times.finish_time > 0) + subtract_timestamp(×.finish_time, times.reverse_offset); + + subtract_timestamp(×.generators_start_time, times.reverse_offset); + subtract_timestamp(×.generators_finish_time, times.reverse_offset); + + subtract_timestamp(×.unitsload_start_time, times.reverse_offset); + subtract_timestamp(×.unitsload_finish_time, times.reverse_offset); + } + + cached = true; + + if (ret) + *ret = × + return 0; +} + +static int bus_get_uint64_property(sd_bus *bus, const char *path, const char *interface, const char *property, uint64_t *val) { + _cleanup_(sd_bus_error_free) sd_bus_error error = SD_BUS_ERROR_NULL; + int r; + + assert(bus); + assert(path); + assert(interface); + assert(property); + assert(val); + + r = sd_bus_get_property_trivial( + bus, + "org.freedesktop.systemd1", + path, + interface, + property, + &error, + 't', val); + if (r < 0) + return log_error_errno(r, "Failed to parse reply: %s", bus_error_message(&error, r)); + + return 0; +} + +int pretty_boot_time(sd_bus *bus, char **ret) { + _cleanup_(sd_bus_error_free) sd_bus_error error = SD_BUS_ERROR_NULL; + _cleanup_free_ char *path = NULL, *unit_id = NULL, *text = NULL; + usec_t activated_time = USEC_INFINITY; + BootTimes *t; + int r; + + r = acquire_boot_times(bus, /* require_finished = */ true, &t); + if (r < 0) + return r; + + path = unit_dbus_path_from_name(SPECIAL_DEFAULT_TARGET); + if (!path) + return log_oom(); + + r = sd_bus_get_property_string( + bus, + "org.freedesktop.systemd1", + path, + "org.freedesktop.systemd1.Unit", + "Id", + &error, + &unit_id); + if (r < 0) + log_warning_errno(r, "default.target doesn't seem to exist, ignoring: %s", bus_error_message(&error, r)); + + r = bus_get_uint64_property(bus, path, + "org.freedesktop.systemd1.Unit", + "ActiveEnterTimestampMonotonic", + &activated_time); + if (r < 0) + log_warning_errno(r, "Could not get time to reach default.target, ignoring: %m"); + + text = strdup("Startup finished in "); + if (!text) + return log_oom(); + + if (timestamp_is_set(t->firmware_time) && !strextend(&text, FORMAT_TIMESPAN(t->firmware_time - t->loader_time, USEC_PER_MSEC), " (firmware) + ")) + return log_oom(); + if (timestamp_is_set(t->loader_time) && !strextend(&text, FORMAT_TIMESPAN(t->loader_time, USEC_PER_MSEC), " (loader) + ")) + return log_oom(); + if (timestamp_is_set(t->kernel_done_time) && !strextend(&text, FORMAT_TIMESPAN(t->kernel_done_time, USEC_PER_MSEC), " (kernel) + ")) + return log_oom(); + if (timestamp_is_set(t->initrd_time) && !strextend(&text, FORMAT_TIMESPAN(t->userspace_time - t->initrd_time, USEC_PER_MSEC), " (initrd) + ")) + return log_oom(); + + if (!strextend(&text, FORMAT_TIMESPAN(t->finish_time - t->userspace_time, USEC_PER_MSEC), " (userspace) ")) + return log_oom(); + + if (timestamp_is_set(t->kernel_done_time)) + if (!strextend(&text, "= ", FORMAT_TIMESPAN(t->firmware_time + t->finish_time, USEC_PER_MSEC), " ")) + return log_oom(); + + if (unit_id && timestamp_is_set(activated_time)) { + usec_t base = timestamp_is_set(t->userspace_time) ? t->userspace_time : t->reverse_offset; + + if (!strextend(&text, "\n", unit_id, " reached after ", FORMAT_TIMESPAN(activated_time - base, USEC_PER_MSEC), " in userspace.")) + return log_oom(); + + } else if (unit_id && activated_time == 0) { + + if (!strextend(&text, "\n", unit_id, " was never reached.")) + return log_oom(); + + } else if (unit_id && activated_time == USEC_INFINITY) { + + if (!strextend(&text, "\nCould not get time to reach ", unit_id, ".")) + return log_oom(); + + } else if (!unit_id) { + + if (!strextend(&text, "\ncould not find default.target.")) + return log_oom(); + } + + *ret = TAKE_PTR(text); + return 0; +} + +void unit_times_clear(UnitTimes *t) { + if (!t) + return; + + FOREACH_ARRAY(d, t->deps, ELEMENTSOF(t->deps)) + *d = strv_free(*d); + + t->name = mfree(t->name); +} + +UnitTimes* unit_times_free_array(UnitTimes *t) { + if (!t) + return NULL; + + for (UnitTimes *p = t; p->has_data; p++) + unit_times_clear(p); + + return mfree(t); +} + +DEFINE_TRIVIAL_CLEANUP_FUNC_FULL(UnitTimes*, unit_times_clear, NULL); + +int acquire_time_data(sd_bus *bus, bool require_finished, UnitTimes **out) { + static const struct bus_properties_map property_map[] = { + { "InactiveExitTimestampMonotonic", "t", NULL, offsetof(UnitTimes, activating) }, + { "ActiveEnterTimestampMonotonic", "t", NULL, offsetof(UnitTimes, activated) }, + { "ActiveExitTimestampMonotonic", "t", NULL, offsetof(UnitTimes, deactivating) }, + { "InactiveEnterTimestampMonotonic", "t", NULL, offsetof(UnitTimes, deactivated) }, + { "After", "as", NULL, offsetof(UnitTimes, deps[UNIT_AFTER]) }, + { "Before", "as", NULL, offsetof(UnitTimes, deps[UNIT_BEFORE]) }, + { "Requires", "as", NULL, offsetof(UnitTimes, deps[UNIT_REQUIRES]) }, + { "Requisite", "as", NULL, offsetof(UnitTimes, deps[UNIT_REQUISITE]) }, + { "Wants", "as", NULL, offsetof(UnitTimes, deps[UNIT_WANTS]) }, + { "Conflicts", "as", NULL, offsetof(UnitTimes, deps[UNIT_CONFLICTS]) }, + { "Upholds", "as", NULL, offsetof(UnitTimes, deps[UNIT_UPHOLDS]) }, + {}, + }; + _cleanup_(sd_bus_message_unrefp) sd_bus_message *reply = NULL; + _cleanup_(sd_bus_error_free) sd_bus_error error = SD_BUS_ERROR_NULL; + _cleanup_(unit_times_free_arrayp) UnitTimes *unit_times = NULL; + BootTimes *boot_times; + size_t c = 0; + UnitInfo u; + int r; + + r = acquire_boot_times(bus, require_finished, &boot_times); + if (r < 0) + return r; + + r = bus_call_method(bus, bus_systemd_mgr, "ListUnits", &error, &reply, NULL); + if (r < 0) + return log_error_errno(r, "Failed to list units: %s", bus_error_message(&error, r)); + + r = sd_bus_message_enter_container(reply, SD_BUS_TYPE_ARRAY, "(ssssssouso)"); + if (r < 0) + return bus_log_parse_error(r); + + while ((r = bus_parse_unit_info(reply, &u)) > 0) { + _cleanup_(unit_times_clearp) UnitTimes *t = NULL; + + if (!GREEDY_REALLOC0(unit_times, c + 2)) + return log_oom(); + + /* t initially has pointers zeroed by the allocation, and unit_times_clearp will have zeroed + * them if the entry is being reused. */ + t = &unit_times[c]; + + assert_cc(sizeof(usec_t) == sizeof(uint64_t)); + + r = bus_map_all_properties( + bus, + "org.freedesktop.systemd1", + u.unit_path, + property_map, + BUS_MAP_STRDUP, + &error, + NULL, + t); + if (r < 0) + return log_error_errno(r, "Failed to get timestamp properties of unit %s: %s", + u.id, bus_error_message(&error, r)); + + subtract_timestamp(&t->activating, boot_times->reverse_offset); + subtract_timestamp(&t->activated, boot_times->reverse_offset); + subtract_timestamp(&t->deactivating, boot_times->reverse_offset); + subtract_timestamp(&t->deactivated, boot_times->reverse_offset); + + if (t->activated >= t->activating) + t->time = t->activated - t->activating; + else if (t->deactivated >= t->activating) + t->time = t->deactivated - t->activating; + else + t->time = 0; + + if (t->activating == 0) + continue; + + t->name = strdup(u.id); + if (!t->name) + return log_oom(); + + t->has_data = true; + /* Prevent destructor from running on t reference. */ + TAKE_PTR(t); + c++; + } + if (r < 0) + return bus_log_parse_error(r); + + *out = TAKE_PTR(unit_times); + return c; +} |