core/shutdown: add more shutdown timestamps

We already record when shutdown.target is initiated (ShutdownStart).
This adds a few more measuring points during shutdown: when
shutdown.target completes (i.e., all units stopped), when the shutdown
binary starts executing, and immediately before it hands off to the
kernel.

Obviously these are immediately lost upon reboot. But they will later
be wired in LUO so they get preserved on kexec, and can be inspected,
which is very useful for performance measurements.
This commit is contained in:
Luca Boccassi
2026-06-30 10:21:18 +01:00
parent 00b295aca9
commit 42411a19f8
4 changed files with 58 additions and 23 deletions
+8 -3
View File
@@ -2340,9 +2340,14 @@ static int invoke_main_loop(
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);
MANAGER_POWEROFF)) {
dual_timestamp ts;
dual_timestamp_now(&ts);
if (!dual_timestamp_is_set(m->timestamps + MANAGER_TIMESTAMP_SHUTDOWN_START))
m->timestamps[MANAGER_TIMESTAMP_SHUTDOWN_START] = ts;
m->timestamps[MANAGER_TIMESTAMP_SHUTDOWN_FINISH] = ts;
}
switch (objective) {
+25 -20
View File
@@ -5577,26 +5577,31 @@ static const char* const manager_objective_table[_MANAGER_OBJECTIVE_MAX] = {
DEFINE_STRING_TABLE_LOOKUP(manager_objective, ManagerObjective);
static const char* const manager_timestamp_table[_MANAGER_TIMESTAMP_MAX] = {
[MANAGER_TIMESTAMP_FIRMWARE] = "firmware",
[MANAGER_TIMESTAMP_LOADER] = "loader",
[MANAGER_TIMESTAMP_KERNEL] = "kernel",
[MANAGER_TIMESTAMP_INITRD] = "initrd",
[MANAGER_TIMESTAMP_USERSPACE] = "userspace",
[MANAGER_TIMESTAMP_FINISH] = "finish",
[MANAGER_TIMESTAMP_SECURITY_START] = "security-start",
[MANAGER_TIMESTAMP_SECURITY_FINISH] = "security-finish",
[MANAGER_TIMESTAMP_GENERATORS_START] = "generators-start",
[MANAGER_TIMESTAMP_GENERATORS_FINISH] = "generators-finish",
[MANAGER_TIMESTAMP_UNITS_LOAD_START] = "units-load-start",
[MANAGER_TIMESTAMP_UNITS_LOAD_FINISH] = "units-load-finish",
[MANAGER_TIMESTAMP_UNITS_LOAD] = "units-load",
[MANAGER_TIMESTAMP_INITRD_SECURITY_START] = "initrd-security-start",
[MANAGER_TIMESTAMP_INITRD_SECURITY_FINISH] = "initrd-security-finish",
[MANAGER_TIMESTAMP_INITRD_GENERATORS_START] = "initrd-generators-start",
[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",
[MANAGER_TIMESTAMP_FIRMWARE] = "firmware",
[MANAGER_TIMESTAMP_LOADER] = "loader",
[MANAGER_TIMESTAMP_KERNEL] = "kernel",
[MANAGER_TIMESTAMP_INITRD] = "initrd",
[MANAGER_TIMESTAMP_USERSPACE] = "userspace",
[MANAGER_TIMESTAMP_FINISH] = "finish",
[MANAGER_TIMESTAMP_SECURITY_START] = "security-start",
[MANAGER_TIMESTAMP_SECURITY_FINISH] = "security-finish",
[MANAGER_TIMESTAMP_GENERATORS_START] = "generators-start",
[MANAGER_TIMESTAMP_GENERATORS_FINISH] = "generators-finish",
[MANAGER_TIMESTAMP_UNITS_LOAD_START] = "units-load-start",
[MANAGER_TIMESTAMP_UNITS_LOAD_FINISH] = "units-load-finish",
[MANAGER_TIMESTAMP_UNITS_LOAD] = "units-load",
[MANAGER_TIMESTAMP_INITRD_SECURITY_START] = "initrd-security-start",
[MANAGER_TIMESTAMP_INITRD_SECURITY_FINISH] = "initrd-security-finish",
[MANAGER_TIMESTAMP_INITRD_GENERATORS_START] = "initrd-generators-start",
[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",
[MANAGER_TIMESTAMP_SHUTDOWN_FINISH] = "shutdown-finish",
[MANAGER_TIMESTAMP_PREVIOUS_SHUTDOWN_START] = "previous-shutdown-start",
[MANAGER_TIMESTAMP_PREVIOUS_SHUTDOWN_FINISH] = "previous-shutdown-finish",
[MANAGER_TIMESTAMP_PREVIOUS_SHUTDOWN_LATE_START] = "previous-shutdown-late-start",
[MANAGER_TIMESTAMP_PREVIOUS_SHUTDOWN_LATE_FINISH] = "previous-shutdown-late-finish",
};
DEFINE_STRING_TABLE_LOOKUP(manager_timestamp, ManagerTimestamp);
+16
View File
@@ -78,6 +78,16 @@ typedef enum ManagerObjective {
* 6. TIMESTAMP_USERSPACE is the timestamp of when the manager was started.
*
* 7. TIMESTAMP_INITRD_* are set only when the system is booted with an initrd.
*
* 8. TIMESTAMP_SHUTDOWN_START and TIMESTAMP_SHUTDOWN_FINISH bracket the unit-stopping phase during the
* current shutdown (the latter is also propagated across soft-reboot).
*
* 9. TIMESTAMP_PREVIOUS_SHUTDOWN_START, TIMESTAMP_PREVIOUS_SHUTDOWN_FINISH,
* TIMESTAMP_PREVIOUS_SHUTDOWN_LATE_START and TIMESTAMP_PREVIOUS_SHUTDOWN_LATE_FINISH describe the
* shutdown of the *previous* boot, restored from the LUO payload after a kexec-based live update
* (the LATE_* ones are taken by systemd-shutdown). Like TIMESTAMP_FIRMWARE/LOADER/KERNEL they refer
* to events before the current systemd cycle took over, hence they are kept distinct from the
* current cycle's SHUTDOWN_START/FINISH instead of overwriting them.
*/
typedef enum ManagerTimestamp {
@@ -104,6 +114,12 @@ typedef enum ManagerTimestamp {
MANAGER_TIMESTAMP_INITRD_UNITS_LOAD_FINISH,
MANAGER_TIMESTAMP_SHUTDOWN_START,
MANAGER_TIMESTAMP_SHUTDOWN_FINISH,
MANAGER_TIMESTAMP_PREVIOUS_SHUTDOWN_START,
MANAGER_TIMESTAMP_PREVIOUS_SHUTDOWN_FINISH,
MANAGER_TIMESTAMP_PREVIOUS_SHUTDOWN_LATE_START,
MANAGER_TIMESTAMP_PREVIOUS_SHUTDOWN_LATE_FINISH,
_MANAGER_TIMESTAMP_MAX,
_MANAGER_TIMESTAMP_INVALID = -EINVAL,
+9
View File
@@ -374,9 +374,13 @@ int main(int argc, char *argv[]) {
_cleanup_close_ int luo_session_fd = -EBADF;
_cleanup_free_ int *luo_fds = NULL;
_cleanup_free_ char *cgroup = NULL;
dual_timestamp shutdown_late_start;
size_t n_luo_fds = 0;
int cmd, r;
/* LUO will preserve these across kexec */
dual_timestamp_now(&shutdown_late_start);
/* If PID 1 passed us an LUO serialization fd, parse it first so we know which fds to keep open. */
(void) luo_parse_serialization(&luo_serialization, &luo_fds, &n_luo_fds);
@@ -642,6 +646,11 @@ int main(int argc, char *argv[]) {
sleep_until_minimum_uptime();
/* This is conceptually where shutdown is complete and only the final syscall to bring the machine
* down is left, so record the late shutdown timestamp here. */
dual_timestamp shutdown_late_finish;
dual_timestamp_now(&shutdown_late_finish);
if (streq(arg_verb, "exit")) {
if (in_container) {
log_info("Exiting container.");