analyze: use shutdown timestamps in time verb

 [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.

diff --git a/man/systemd-analyze.xml b/man/systemd-analyze.xml
index 4f3057f725d24dbc252a5cba57f9f4eef2d1c692..a7f438343f66a8f284bb620e1f853f5715791ea1 100644 (file)
--- a/man/systemd-analyze.xml
+++ b/man/systemd-analyze.xml
@@ -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>
 

diff --git a/src/analyze/analyze-time-data.c b/src/analyze/analyze-time-data.c
index 54f9acbbff93e6c6d3907f02bb745fe23164a9ae..744de87c6d036b6c7d1af79521e52274c4706479 100644 (file)
--- a/src/analyze/analyze-time-data.c
+++ b/src/analyze/analyze-time-data.c
@@ -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);

diff --git a/src/analyze/analyze-time-data.h b/src/analyze/analyze-time-data.h
index 1924409556994c8bcd52e19bb6bf82f6a2f60e88..7b4af3dc8c52352859cff15f70c27368fe2a91f3 100644 (file)
--- a/src/analyze/analyze-time-data.h
+++ b/src/analyze/analyze-time-data.h
@@ -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;