SymbX/systemd
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

analyze: use shutdown timestamps in time verb

Browse Source 
[root@fedora ~]# systemd-analyze
 Startup finished in 486ms (stopping) + 48ms (exit) + 116ms (systemd-shutdown) + 774ms (kernel) + 1.939s (initrd) + 3.878s (userspace) = 7.243s
 graphical.target reached after 3.876s in userspace.
This commit is contained in:
Luca Boccassi
2026-06-30 10:21:18 +01:00
parent ec919e7ec1
commit 3a79aaea83
3 changed files with 64 additions and 23 deletions
Download Patch File Download Diff File Expand all files Collapse all files
man/systemd-analyze.xml
+10
View File
@@ -263,6 +263,16 @@
point where all system services have been spawned, but not necessarily until they fully finished
initialization or the disk is idle.</para>
<para>If the manager carried shutdown timestamps across a kexec-based live update (i.e. they were
restored from the previous boot through the Live Update Orchestrator), the previous boot's shutdown
phases are prepended to the chain, so the full shutdown plus bootup sequence is shown and summed into
the total: the time spent stopping units (<literal>(stopping)</literal>), the time the manager took to
hand off to
<citerefentry><refentrytitle>systemd-shutdown</refentrytitle><manvolnum>8</manvolnum></citerefentry>
(<literal>(exit)</literal>) and the time spent in <command>systemd-shutdown</command> itself
(<literal>(systemd-shutdown)</literal>) are added before the firmware/loader/kernel/initrd/userspace
phases.</para>
<example>
<title><command>Show how long the boot took</command></title>
src/analyze/analyze-time-data.c
+50 -23
View File
@@ -37,26 +37,30 @@ static int log_not_finished(usec_t finish_time) {
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) },
{ "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) },
{ "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) },
{ "SoftRebootsCount", "u", NULL, offsetof(BootTimes, soft_reboots_count) },
{ "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) },
{ "ShutdownStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, shutdown_start_time) },
{ "PreviousShutdownStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, previous_shutdown_start_time) },
{ "PreviousShutdownFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, previous_shutdown_finish_time) },
{ "PreviousShutdownLateStartTimestampMonotonic", "t", NULL, offsetof(BootTimes, previous_shutdown_late_start_time) },
{ "PreviousShutdownLateFinishTimestampMonotonic", "t", NULL, offsetof(BootTimes, previous_shutdown_late_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) },
{ "SoftRebootsCount", "u", NULL, offsetof(BootTimes, soft_reboots_count) },
{},
};
_cleanup_(sd_bus_error_free) sd_bus_error error = SD_BUS_ERROR_NULL;
@@ -204,6 +208,28 @@ int pretty_boot_time(sd_bus *bus, char **ret) {
if (!text)
return log_oom();
/* If the previous boot's shutdown timestamps are set (restored via LUO across a kexec-based live
* update), prepend them so the full shutdown + bootup chain is shown, and add their duration to the
* total below. */
usec_t shutdown_time = 0;
if (timestamp_is_set(t->previous_shutdown_start_time) &&
timestamp_is_set(t->previous_shutdown_finish_time) &&
timestamp_is_set(t->previous_shutdown_late_start_time) &&
timestamp_is_set(t->previous_shutdown_late_finish_time)) {
usec_t stopping = usec_sub_unsigned(t->previous_shutdown_finish_time, t->previous_shutdown_start_time);
usec_t exit_time = usec_sub_unsigned(t->previous_shutdown_late_start_time, t->previous_shutdown_finish_time);
usec_t systemd_shutdown = usec_sub_unsigned(t->previous_shutdown_late_finish_time, t->previous_shutdown_late_start_time);
shutdown_time = stopping + exit_time + systemd_shutdown;
if (!strextend(&text, FORMAT_TIMESPAN(stopping, USEC_PER_MSEC), " (stopping) + "))
return log_oom();
if (!strextend(&text, FORMAT_TIMESPAN(exit_time, USEC_PER_MSEC), " (exit) + "))
return log_oom();
if (!strextend(&text, FORMAT_TIMESPAN(systemd_shutdown, USEC_PER_MSEC), " (systemd-shutdown) + "))
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) + "))
@@ -219,7 +245,7 @@ int pretty_boot_time(sd_bus *bus, char **ret) {
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), " "))
if (!strextend(&text, "= ", FORMAT_TIMESPAN(shutdown_time + t->firmware_time + t->finish_time, USEC_PER_MSEC), " "))
return log_oom();
if (unit_id && timestamp_is_set(activated_time)) {
@@ -339,8 +365,9 @@ 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->shutdown_start_time) ||
(t->activating > 0 && t->activating < boot_times->shutdown_start_time))
if (boot_times->soft_reboots_count > 0 &&
((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);
src/analyze/analyze-time-data.h
+4
View File
@@ -13,6 +13,10 @@ typedef struct BootTimes {
usec_t userspace_time;
usec_t finish_time;
usec_t shutdown_start_time;
usec_t previous_shutdown_start_time;
usec_t previous_shutdown_finish_time;
usec_t previous_shutdown_late_start_time;
usec_t previous_shutdown_late_finish_time;
usec_t security_start_time;
usec_t security_finish_time;
usec_t generators_start_time;