diff --git a/man/org.freedesktop.systemd1.xml b/man/org.freedesktop.systemd1.xml index 25b98c7ace..6e90662fa9 100644 --- a/man/org.freedesktop.systemd1.xml +++ b/man/org.freedesktop.systemd1.xml @@ -340,9 +340,9 @@ node /org/freedesktop/systemd1 { @org.freedesktop.DBus.Property.EmitsChangedSignal("const") readonly t FinishTimestampMonotonic = ...; @org.freedesktop.DBus.Property.EmitsChangedSignal("const") - readonly t SoftRebootStartTimestamp = ...; + readonly t ShutdownStartTimestamp = ...; @org.freedesktop.DBus.Property.EmitsChangedSignal("const") - readonly t SoftRebootStartTimestampMonotonic = ...; + readonly t ShutdownStartTimestampMonotonic = ...; @org.freedesktop.DBus.Property.EmitsChangedSignal("const") readonly t SecurityStartTimestamp = ...; @org.freedesktop.DBus.Property.EmitsChangedSignal("const") @@ -1039,9 +1039,9 @@ node /org/freedesktop/systemd1 { - + - + @@ -1746,12 +1746,11 @@ node /org/freedesktop/systemd1 { InitRDTimestamp, InitRDTimestampMonotonic, UserspaceTimestamp, UserspaceTimestampMonotonic, FinishTimestamp, FinishTimestampMonotonic, - SoftRebootStartTimestamp and SoftRebootStartTimestampMonotonic + ShutdownStartTimestamp and ShutdownStartTimestampMonotonic encode CLOCK_REALTIME and CLOCK_MONOTONIC microsecond timestamps taken when the firmware first began execution, when the boot loader first began execution, when the kernel first began execution, when the initrd first began execution, when the main systemd - instance began execution, when all queued startup jobs finished execution and finally, when a - systemd-soft-reboot.service8 + instance began execution, when all queued startup jobs finished execution and finally, when a shutdown operation first began execution. These values are useful for determining boot-time performance. Note that as monotonic time begins with the kernel startup, the KernelTimestampMonotonic timestamp will always be 0 and FirmwareTimestampMonotonic and @@ -12000,8 +11999,8 @@ $ gdbus introspect --system --dest org.freedesktop.systemd1 \ SoftReboot(), and DumpUnitFileDescriptorStore() were added in version 254. StartAuxiliaryScope(), - SoftRebootStartTimestamp, - SoftRebootStartTimestampMonotonic and + ShutdownStartTimestamp, + ShutdownStartTimestampMonotonic and SoftRebootsCount were added in version 256. diff --git a/src/analyze/analyze-plot.c b/src/analyze/analyze-plot.c index 797f23ae85..e271296b68 100644 --- a/src/analyze/analyze-plot.c +++ b/src/analyze/analyze-plot.c @@ -316,7 +316,7 @@ static int produce_plot_as_svg( strempty(host->virtualization)); svg("\n", 20.0 + (SCALE_X * boot->firmware_time)); - if (timestamp_is_set(boot->softreboot_start_time)) + if (boot->soft_reboots_count > 0) svg_graph_box(m, 0, boot->finish_time); else svg_graph_box(m, -(double) boot->firmware_time, boot->finish_time); @@ -347,7 +347,7 @@ static int produce_plot_as_svg( svg_text(true, boot->initrd_time, y, "initrd"); y++; } - if (timestamp_is_set(boot->softreboot_start_time)) { + if (boot->soft_reboots_count > 0) { svg_bar("soft-reboot", 0, boot->userspace_time, y); svg_text(true, 0, y, "soft-reboot"); y++; diff --git a/src/analyze/analyze-time-data.c b/src/analyze/analyze-time-data.c index 94f6031893..62e055dda4 100644 --- a/src/analyze/analyze-time-data.c +++ b/src/analyze/analyze-time-data.c @@ -38,7 +38,7 @@ int acquire_boot_times(sd_bus *bus, bool require_finished, BootTimes **ret) { { "FinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, finish_time) }, { "SecurityStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, security_start_time) }, { "SecurityFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, security_finish_time) }, - { "SoftRebootStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, softreboot_start_time) }, + { "ShutdownStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, shutdown_start_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) }, @@ -83,13 +83,13 @@ int acquire_boot_times(sd_bus *bus, bool require_finished, BootTimes **ret) { if (require_finished && times.finish_time <= 0) return log_not_finished(times.finish_time); - if (arg_runtime_scope == RUNTIME_SCOPE_SYSTEM && timestamp_is_set(times.softreboot_start_time)) { + if (arg_runtime_scope == RUNTIME_SCOPE_SYSTEM && times.soft_reboots_count > 0) { /* On soft-reboot ignore kernel/firmware/initrd times as they are from the previous boot */ times.firmware_time = times.loader_time = times.kernel_time = times.initrd_time = times.initrd_security_start_time = times.initrd_security_finish_time = times.initrd_generators_start_time = times.initrd_generators_finish_time = times.initrd_unitsload_start_time = times.initrd_unitsload_finish_time = 0; - times.reverse_offset = times.softreboot_start_time; + times.reverse_offset = times.shutdown_start_time; /* Clamp all timestamps to avoid showing huge graphs */ if (timestamp_is_set(times.finish_time)) @@ -203,7 +203,7 @@ int pretty_boot_time(sd_bus *bus, char **ret) { 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 (timestamp_is_set(t->softreboot_start_time) && strextendf(&text, "%s (soft reboot #%" PRIu64 ") + ", FORMAT_TIMESPAN(t->userspace_time, USEC_PER_MSEC), t->soft_reboots_count) < 0) + if (t->soft_reboots_count > 0 && strextendf(&text, "%s (soft reboot #%" PRIu64 ") + ", FORMAT_TIMESPAN(t->userspace_time, USEC_PER_MSEC), t->soft_reboots_count) < 0) return log_oom(); if (!strextend(&text, FORMAT_TIMESPAN(t->finish_time - t->userspace_time, USEC_PER_MSEC), " (userspace) ")) @@ -217,7 +217,7 @@ int pretty_boot_time(sd_bus *bus, char **ret) { usec_t base; /* On soft-reboot times are clamped to avoid showing huge graphs */ - if (timestamp_is_set(t->softreboot_start_time) && timestamp_is_set(t->userspace_time)) + if (t->soft_reboots_count > 0 && timestamp_is_set(t->userspace_time)) base = t->userspace_time + t->reverse_offset; else base = timestamp_is_set(t->userspace_time) ? t->userspace_time : t->reverse_offset; @@ -328,15 +328,15 @@ int acquire_time_data(sd_bus *bus, bool require_finished, UnitTimes **out) { u.id, bus_error_message(&error, r)); /* Activated in the previous soft-reboot iteration? Ignore it, we want new activations */ - if ((t->activated > 0 && t->activated < boot_times->softreboot_start_time) || - (t->activating > 0 && t->activating < boot_times->softreboot_start_time)) + if ((t->activated > 0 && t->activated < boot_times->shutdown_start_time) || + (t->activating > 0 && t->activating < boot_times->shutdown_start_time)) continue; subtract_timestamp(&t->activating, boot_times->reverse_offset); subtract_timestamp(&t->activated, boot_times->reverse_offset); /* If the last deactivation was in the previous soft-reboot, ignore it */ - if (timestamp_is_set(boot_times->softreboot_start_time)) { + if (boot_times->soft_reboots_count > 0) { if (t->deactivating < boot_times->reverse_offset) t->deactivating = 0; else diff --git a/src/analyze/analyze-time-data.h b/src/analyze/analyze-time-data.h index 1932d59c3d..e7ffd8549d 100644 --- a/src/analyze/analyze-time-data.h +++ b/src/analyze/analyze-time-data.h @@ -14,7 +14,7 @@ typedef struct BootTimes { usec_t initrd_time; usec_t userspace_time; usec_t finish_time; - usec_t softreboot_start_time; + usec_t shutdown_start_time; usec_t security_start_time; usec_t security_finish_time; usec_t generators_start_time; diff --git a/src/core/dbus-manager.c b/src/core/dbus-manager.c index 7077d44723..397919dd30 100644 --- a/src/core/dbus-manager.c +++ b/src/core/dbus-manager.c @@ -3052,7 +3052,7 @@ const sd_bus_vtable bus_manager_vtable[] = { BUS_PROPERTY_DUAL_TIMESTAMP("InitRDTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_INITRD]), SD_BUS_VTABLE_PROPERTY_CONST), BUS_PROPERTY_DUAL_TIMESTAMP("UserspaceTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_USERSPACE]), SD_BUS_VTABLE_PROPERTY_CONST), BUS_PROPERTY_DUAL_TIMESTAMP("FinishTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_FINISH]), SD_BUS_VTABLE_PROPERTY_CONST), - BUS_PROPERTY_DUAL_TIMESTAMP("SoftRebootStartTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_SOFTREBOOT_START]), SD_BUS_VTABLE_PROPERTY_CONST), + BUS_PROPERTY_DUAL_TIMESTAMP("ShutdownStartTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_SHUTDOWN_START]), SD_BUS_VTABLE_PROPERTY_CONST), BUS_PROPERTY_DUAL_TIMESTAMP("SecurityStartTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_SECURITY_START]), SD_BUS_VTABLE_PROPERTY_CONST), BUS_PROPERTY_DUAL_TIMESTAMP("SecurityFinishTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_SECURITY_FINISH]), SD_BUS_VTABLE_PROPERTY_CONST), BUS_PROPERTY_DUAL_TIMESTAMP("GeneratorsStartTimestamp", offsetof(Manager, timestamps[MANAGER_TIMESTAMP_GENERATORS_START]), SD_BUS_VTABLE_PROPERTY_CONST), diff --git a/src/core/job.c b/src/core/job.c index 595fbce93a..c6b48035a7 100644 --- a/src/core/job.c +++ b/src/core/job.c @@ -1387,10 +1387,13 @@ void job_shutdown_magic(Job *j) { if (j->type != JOB_START) return; - if (!MANAGER_IS_SYSTEM(j->unit->manager)) + if (!unit_has_name(j->unit, SPECIAL_SHUTDOWN_TARGET)) return; - if (!unit_has_name(j->unit, SPECIAL_SHUTDOWN_TARGET)) + /* This is the very beginning of the shutdown phase, so take the timestamp here */ + dual_timestamp_now(ASSERT_PTR(j->manager)->timestamps + MANAGER_TIMESTAMP_SHUTDOWN_START); + + if (!MANAGER_IS_SYSTEM(j->manager)) return; /* In case messages on console has been disabled on boot */ diff --git a/src/core/main.c b/src/core/main.c index 8c8cf8b4a7..83a2b5b661 100644 --- a/src/core/main.c +++ b/src/core/main.c @@ -2041,6 +2041,16 @@ static int invoke_main_loop( "MESSAGE_ID=" SD_MESSAGE_CORE_MAINLOOP_FAILED_STR); } + /* Ensure shutdown timestamp is taken even when bypassing the job engine */ + if (IN_SET(objective, + MANAGER_SOFT_REBOOT, + MANAGER_REBOOT, + MANAGER_KEXEC, + MANAGER_HALT, + MANAGER_POWEROFF) && + !dual_timestamp_is_set(m->timestamps + MANAGER_TIMESTAMP_SHUTDOWN_START)) + dual_timestamp_now(m->timestamps + MANAGER_TIMESTAMP_SHUTDOWN_START); + switch (objective) { case MANAGER_RELOAD: { @@ -2129,8 +2139,6 @@ static int invoke_main_loop( manager_send_reloading(m); manager_set_switching_root(m, true); - dual_timestamp_now(m->timestamps + MANAGER_TIMESTAMP_SOFTREBOOT_START); - r = prepare_reexecute(m, &arg_serialization, ret_fds, /* switching_root= */ true); if (r < 0) { *ret_error_message = "Failed to prepare for reexecution"; @@ -3192,11 +3200,6 @@ int main(int argc, char *argv[]) { goto finish; } - /* If we got a SoftRebootStart timestamp during deserialization, then we are in a new soft-reboot - * iteration, so bump the counter now before starting units, so that they can reliably read it. */ - if (dual_timestamp_is_set(&m->timestamps[MANAGER_TIMESTAMP_SOFTREBOOT_START])) - m->soft_reboots_count++; - /* This will close all file descriptors that were opened, but not claimed by any unit. */ fds = fdset_free(fds); arg_serialization = safe_fclose(arg_serialization); diff --git a/src/core/manager-serialize.c b/src/core/manager-serialize.c index 884332b324..6008e5655e 100644 --- a/src/core/manager-serialize.c +++ b/src/core/manager-serialize.c @@ -158,6 +158,9 @@ int manager_serialize( (void) serialize_ratelimit(f, "dump-ratelimit", &m->dump_ratelimit); (void) serialize_ratelimit(f, "reload-reexec-ratelimit", &m->reload_reexec_ratelimit); + if (m->objective >= 0 && m->objective < _MANAGER_OBJECTIVE_MAX) + (void) serialize_item_format(f, "previous-objective", "%u", (unsigned) m->objective); + bus_track_serialize(m->subscribed, f, "subscribed"); r = dynamic_user_serialize(m, f, fds); @@ -529,6 +532,14 @@ int manager_deserialize(Manager *m, FILE *f, FDSet *fds) { log_notice("Failed to parse soft reboots counter '%s', ignoring.", val); else m->soft_reboots_count = n; + } else if ((val = startswith(l, "previous-objective="))) { + unsigned n; + + if (safe_atou(val, &n) < 0 || n >= _MANAGER_OBJECTIVE_MAX) + log_notice("Failed to parse objective '%s', ignoring.", val); + else + m->previous_objective = n; + } else { ManagerTimestamp q; diff --git a/src/core/manager.c b/src/core/manager.c index 52f5e72e11..3ffe0f87c0 100644 --- a/src/core/manager.c +++ b/src/core/manager.c @@ -882,6 +882,7 @@ int manager_new(RuntimeScope runtime_scope, ManagerTestRunFlags test_run_flags, *m = (Manager) { .runtime_scope = runtime_scope, .objective = _MANAGER_OBJECTIVE_INVALID, + .previous_objective = _MANAGER_OBJECTIVE_INVALID, .status_unit_format = STATUS_UNIT_FORMAT_DEFAULT, @@ -1973,6 +1974,11 @@ int manager_startup(Manager *m, FILE *serialization, FDSet *fds, const char *roo return log_error_errno(r, "Deserialization failed: %m"); } + /* If we are in a new soft-reboot iteration bump the counter now before starting units, so + * that they can reliably read it. We get the previous objective from serialized state. */ + if (m->previous_objective == MANAGER_SOFT_REBOOT) + m->soft_reboots_count++; + /* Any fds left? Find some unit which wants them. This is useful to allow container managers to pass * some file descriptors to us pre-initialized. This enables socket-based activation of entire * containers. */ @@ -3689,10 +3695,10 @@ static void manager_notify_finished(Manager *m) { if (MANAGER_IS_TEST_RUN(m)) return; - if (MANAGER_IS_SYSTEM(m) && dual_timestamp_is_set(&m->timestamps[MANAGER_TIMESTAMP_SOFTREBOOT_START])) { + if (MANAGER_IS_SYSTEM(m) && m->soft_reboots_count > 0) { /* The soft-reboot case, where we only report data for the last reboot */ firmware_usec = loader_usec = initrd_usec = kernel_usec = 0; - total_usec = userspace_usec = usec_sub_unsigned(m->timestamps[MANAGER_TIMESTAMP_FINISH].monotonic, m->timestamps[MANAGER_TIMESTAMP_SOFTREBOOT_START].monotonic); + total_usec = userspace_usec = usec_sub_unsigned(m->timestamps[MANAGER_TIMESTAMP_FINISH].monotonic, m->timestamps[MANAGER_TIMESTAMP_SHUTDOWN_START].monotonic); log_struct(LOG_INFO, "MESSAGE_ID=" SD_MESSAGE_STARTUP_FINISHED_STR, @@ -5046,7 +5052,6 @@ static const char *const manager_timestamp_table[_MANAGER_TIMESTAMP_MAX] = { [MANAGER_TIMESTAMP_INITRD] = "initrd", [MANAGER_TIMESTAMP_USERSPACE] = "userspace", [MANAGER_TIMESTAMP_FINISH] = "finish", - [MANAGER_TIMESTAMP_SOFTREBOOT_START] = "softreboot-start", [MANAGER_TIMESTAMP_SECURITY_START] = "security-start", [MANAGER_TIMESTAMP_SECURITY_FINISH] = "security-finish", [MANAGER_TIMESTAMP_GENERATORS_START] = "generators-start", @@ -5060,6 +5065,7 @@ static const char *const manager_timestamp_table[_MANAGER_TIMESTAMP_MAX] = { [MANAGER_TIMESTAMP_INITRD_GENERATORS_FINISH] = "initrd-generators-finish", [MANAGER_TIMESTAMP_INITRD_UNITS_LOAD_START] = "initrd-units-load-start", [MANAGER_TIMESTAMP_INITRD_UNITS_LOAD_FINISH] = "initrd-units-load-finish", + [MANAGER_TIMESTAMP_SHUTDOWN_START] = "shutdown-start", }; DEFINE_STRING_TABLE_LOOKUP(manager_timestamp, ManagerTimestamp); diff --git a/src/core/manager.h b/src/core/manager.h index 9541a5e0b4..70ae78aa84 100644 --- a/src/core/manager.h +++ b/src/core/manager.h @@ -121,7 +121,7 @@ typedef enum ManagerTimestamp { MANAGER_TIMESTAMP_INITRD_UNITS_LOAD_START, MANAGER_TIMESTAMP_INITRD_UNITS_LOAD_FINISH, - MANAGER_TIMESTAMP_SOFTREBOOT_START, + MANAGER_TIMESTAMP_SHUTDOWN_START, _MANAGER_TIMESTAMP_MAX, _MANAGER_TIMESTAMP_INVALID = -EINVAL, @@ -379,6 +379,8 @@ struct Manager { bool etc_localtime_accessible; ManagerObjective objective; + /* Objective as it was before serialization, mostly to detect soft-reboots */ + ManagerObjective previous_objective; /* Flags */ bool dispatching_load_queue;