systemd: record the timestamps as early as possible

The time for systemd initialization and selinux policy loading
is accounted to the initrd or the kernel, which is wrong.

Instead of:

Startup finished in 5.559s (firmware) + 36ms (loader) + 665ms (kernel) +
975ms (initrd) + 1.410s (userspace) = 8.647s

the more correct output is:

Startup finished in 5.559s (firmware) + 36ms (loader) + 665ms (kernel) +
475ms (initrd) + 1.910s (userspace) = 8.647s

2 files changed, 27 insertions, 16 deletions

diff --git a/src/core/main.c b/src/core/main.c
index 695e23251..22cec4ed1 100644
--- a/src/core/main.c
+++ b/src/core/main.c
@@ -69,6 +69,7 @@
 #include "ima-setup.h"
 #include "fileio.h"
 #include "smack-setup.h"
+#include "efivars.h"
 
 static enum {
         ACTION_RUN,
@@ -1236,6 +1237,10 @@ int main(int argc, char *argv[]) {
         bool reexecute = false;
         const char *shutdown_verb = NULL;
         dual_timestamp initrd_timestamp = { 0ULL, 0ULL };
+        dual_timestamp userspace_timestamp = { 0ULL, 0ULL };
+        dual_timestamp kernel_timestamp = { 0ULL, 0ULL };
+        dual_timestamp firmware_timestamp = { 0ULL, 0ULL };
+        dual_timestamp loader_timestamp = { 0ULL, 0ULL };
         static char systemd[] = "systemd";
         bool skip_setup = false;
         int j;
@@ -1257,6 +1262,9 @@ int main(int argc, char *argv[]) {
         }
 #endif
 
+        dual_timestamp_from_monotonic(&kernel_timestamp, 0);
+        dual_timestamp_get(&userspace_timestamp);
+
         /* Determine if this is a reexecution or normal bootup. We do
          * the full command line parsing much later, so let's just
          * have a quick peek here. */
@@ -1281,7 +1289,9 @@ int main(int argc, char *argv[]) {
         log_show_color(isatty(STDERR_FILENO) > 0);
 
         if (getpid() == 1 && detect_container(NULL) <= 0) {
-
+#ifdef ENABLE_EFI
+                efi_get_boot_timestamps(&userspace_timestamp, &firmware_timestamp, &loader_timestamp);
+#endif
                 /* Running outside of a container as PID 1 */
                 arg_running_as = SYSTEMD_SYSTEM;
                 make_null_stdio();
@@ -1291,7 +1301,7 @@ int main(int argc, char *argv[]) {
                 if (in_initrd()) {
                         char *rd_timestamp = NULL;
 
-                        dual_timestamp_get(&initrd_timestamp);
+                        initrd_timestamp = userspace_timestamp;
                         asprintf(&rd_timestamp, "%llu %llu",
                                  (unsigned long long) initrd_timestamp.realtime,
                                  (unsigned long long) initrd_timestamp.monotonic);
@@ -1351,7 +1361,6 @@ int main(int argc, char *argv[]) {
                 log_set_target(LOG_TARGET_JOURNAL_OR_KMSG);
 
         } else if (getpid() == 1) {
-
                 /* Running inside a container, as PID 1 */
                 arg_running_as = SYSTEMD_SYSTEM;
                 log_set_target(LOG_TARGET_CONSOLE);
@@ -1360,12 +1369,21 @@ int main(int argc, char *argv[]) {
                 /* For the later on, see above... */
                 log_set_target(LOG_TARGET_JOURNAL);
 
-        } else {
+                /* clear the kernel timestamp,
+                 * because we are in a container */
+                kernel_timestamp.monotonic = 0ULL;
+                kernel_timestamp.realtime = 0ULL;
 
+        } else {
                 /* Running as user instance */
                 arg_running_as = SYSTEMD_USER;
                 log_set_target(LOG_TARGET_AUTO);
                 log_open();
+
+                /* clear the kernel timestamp,
+                 * because we are not PID 1 */
+                kernel_timestamp.monotonic = 0ULL;
+                kernel_timestamp.realtime = 0ULL;
         }
 
         /* Initialize default unit */
@@ -1607,12 +1625,14 @@ int main(int argc, char *argv[]) {
         m->default_std_error = arg_default_std_error;
         m->runtime_watchdog = arg_runtime_watchdog;
         m->shutdown_watchdog = arg_shutdown_watchdog;
+        m->userspace_timestamp = userspace_timestamp;
+        m->kernel_timestamp = kernel_timestamp;
+        m->firmware_timestamp = firmware_timestamp;
+        m->loader_timestamp = loader_timestamp;
+        m->initrd_timestamp = initrd_timestamp;
 
         manager_set_default_rlimits(m, arg_default_rlimit);
 
-        if (dual_timestamp_is_set(&initrd_timestamp))
-                m->initrd_timestamp = initrd_timestamp;
-
         if (arg_default_controllers)
                 manager_set_default_controllers(m, arg_default_controllers);
 
diff --git a/src/core/manager.c b/src/core/manager.c
index b1a22890f..2265ef717 100644
--- a/src/core/manager.c
+++ b/src/core/manager.c
@@ -70,7 +70,6 @@
 #include "cgroup-util.h"
 #include "path-util.h"
 #include "audit-fd.h"
-#include "efivars.h"
 #include "env-util.h"
 
 /* As soon as 16 units are in our GC queue, make sure to run a gc sweep */
@@ -440,14 +439,6 @@ int manager_new(SystemdRunningAs running_as, Manager **_m) {
         if (!m)
                 return -ENOMEM;
 
-        dual_timestamp_get(&m->userspace_timestamp);
-        if (detect_container(NULL) <= 0) {
-                dual_timestamp_from_monotonic(&m->kernel_timestamp, 0);
-#ifdef ENABLE_EFI
-                efi_get_boot_timestamps(&m->userspace_timestamp, &m->firmware_timestamp, &m->loader_timestamp);
-#endif
-        }
-
         m->running_as = running_as;
         m->name_data_slot = m->conn_data_slot = m->subscribed_data_slot = -1;
         m->exit_code = _MANAGER_EXIT_CODE_INVALID;