core: if the bootloader supports it, determine firmware and boot loader delay

This allows us to print simple performance data of all parts of the boot now:

- firmware
- boot loader
- kernel
- initrd
- userspace

This only works for bootloaders which support passing TSC data via EFI
variables. As of now that's only gummiboot.

8 files changed, 363 insertions, 1 deletions

diff --git a/.gitignore b/.gitignore
index af62f2acad..23c1b59799 100644
--- a/.gitignore
+++ b/.gitignore
@@ -79,8 +79,10 @@
 /test-calendarspec
 /test-catalog
 /test-cgroup
+/test-cgroup-util
 /test-daemon
 /test-date
+/test-efivars
 /test-engine
 /test-env-replace
 /test-hostname
diff --git a/Makefile.am b/Makefile.am
index c57ea0dce4..ba93db0d82 100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -747,6 +747,8 @@ libsystemd_shared_la_SOURCES = \
 	src/shared/util.h \
 	src/shared/virt.c \
 	src/shared/virt.h \
+	src/shared/efivars.c \
+	src/shared/efivars.h \
 	src/shared/path-util.c \
 	src/shared/path-util.h \
 	src/shared/time-util.c \
@@ -1181,7 +1183,8 @@ noinst_PROGRAMS += \
 	test-cgroup \
 	test-install \
 	test-watchdog \
-	test-log
+	test-log \
+	test-efivars
 
 noinst_tests += \
 	test-job-type \
@@ -1246,6 +1249,12 @@ test_hostname_SOURCES = \
 test_hostname_LDADD = \
 	libsystemd-core.la
 
+test_efivars_SOURCES = \
+	src/test/test-efivars.c
+
+test_efivars_LDADD = \
+	libsystemd-shared.la
+
 test_unit_name_SOURCES = \
 	src/test/test-unit-name.c
 
diff --git a/src/core/manager.c b/src/core/manager.c
index d4afc931f3..aaf66970cf 100644
--- a/src/core/manager.c
+++ b/src/core/manager.c
@@ -70,6 +70,7 @@
 #include "cgroup-util.h"
 #include "path-util.h"
 #include "audit-fd.h"
+#include "efivars.h"
 
 /* As soon as 16 units are in our GC queue, make sure to run a gc sweep */
 #define GC_QUEUE_ENTRIES_MAX 16
@@ -302,6 +303,7 @@ int manager_new(SystemdRunningAs running_as, Manager **_m) {
 
         dual_timestamp_get(&m->userspace_timestamp);
         dual_timestamp_from_monotonic(&m->kernel_timestamp, 0);
+        efi_get_boot_timestamps(&m->userspace_timestamp, &m->firmware_timestamp, &m->loader_timestamp);
 
         m->running_as = running_as;
         m->name_data_slot = m->conn_data_slot = m->subscribed_data_slot = -1;
diff --git a/src/shared/efivars.c b/src/shared/efivars.c
new file mode 100644
index 0000000000..3bd47b8868
--- /dev/null
+++ b/src/shared/efivars.c
@@ -0,0 +1,233 @@
+/*-*- Mode: C; c-basic-offset: 8; indent-tabs-mode: nil -*-*/
+
+/***
+  This file is part of systemd.
+
+  Copyright 2013 Lennart Poettering
+
+  systemd is free software; you can redistribute it and/or modify it
+  under the terms of the GNU Lesser General Public License as published by
+  the Free Software Foundation; either version 2.1 of the License, or
+  (at your option) any later version.
+
+  systemd is distributed in the hope that it will be useful, but
+  WITHOUT ANY WARRANTY; without even the implied warranty of
+  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
+  Lesser General Public License for more details.
+
+  You should have received a copy of the GNU Lesser General Public License
+  along with systemd; If not, see <http://www.gnu.org/licenses/>.
+***/
+
+#include <unistd.h>
+#include <fcntl.h>
+
+#include "util.h"
+#include "utf8.h"
+#include "efivars.h"
+
+#define EFI_VENDOR_LOADER SD_ID128_MAKE(4a,67,b0,82,0a,4c,41,cf,b6,c7,44,0b,29,bb,8c,4f)
+
+int efi_get_variable(sd_id128_t vendor, const char *name, uint32_t *attribute, void **value, size_t *size) {
+        _cleanup_close_ int fd = -1;
+        _cleanup_free_ char *p = NULL;
+        uint32_t a;
+        ssize_t n;
+        struct stat st;
+        void *r;
+
+        assert(name);
+        assert(value);
+        assert(size);
+
+        if (asprintf(&p,
+                     "/sys/firmware/efi/efivars/%s-%02x%02x%02x%02x-%02x%02x-%02x%02x-%02x%02x-%02x%02x%02x%02x%02x%02x",
+                     name, SD_ID128_FORMAT_VAL(vendor)) < 0)
+                return -ENOMEM;
+
+        fd = open(p, O_RDONLY|O_NOCTTY|O_CLOEXEC);
+        if (fd < 0)
+                return -errno;
+
+        if (fstat(fd, &st) < 0)
+                return -errno;
+        if (st.st_size < 4)
+                return -EIO;
+        if (st.st_size > 4*1024*1024 + 4)
+                return -E2BIG;
+
+        n = read(fd, &a, sizeof(a));
+        if (n < 0)
+                return (int) n;
+        if (n != sizeof(a))
+                return -EIO;
+
+        r = malloc(st.st_size - 4 + 2);
+        if (!r)
+                return -ENOMEM;
+
+        n = read(fd, r, (size_t) st.st_size - 4);
+        if (n < 0) {
+                free(r);
+                return (int) -n;
+        }
+        if (n != (ssize_t) st.st_size - 4) {
+                free(r);
+                return -EIO;
+        }
+
+        /* Always NUL terminate (2 bytes, to protect UTF-16) */
+        ((char*) r)[st.st_size - 4] = 0;
+        ((char*) r)[st.st_size - 4 + 1] = 0;
+
+        *value = r;
+        *size = (size_t) st.st_size;
+
+        if (attribute)
+                *attribute = a;
+
+        return 0;
+}
+
+static int read_bogomips(unsigned long *u) {
+        _cleanup_fclose_ FILE *f = NULL;
+
+        f = fopen("/proc/cpuinfo", "re");
+        if (!f)
+                return -errno;
+
+        while (!feof(f)) {
+                char line[LINE_MAX];
+                char *x;
+                unsigned long a, b;
+
+                if (!fgets(line, sizeof(line), f))
+                        return -EIO;
+
+                char_array_0(line);
+                truncate_nl(line);
+
+                if (!startswith(line, "bogomips"))
+                        continue;
+
+                x = line + 8;
+                x += strspn(x, WHITESPACE);
+                if (*x != ':')
+                        continue;
+                x++;
+                x += strspn(x, WHITESPACE);
+
+                if (sscanf(x, "%lu.%lu", &a, &b) != 2)
+                        continue;
+
+                *u = a * 1000000L + b * 10000L;
+                return 0;
+        }
+
+        return -EIO;
+}
+
+static int read_ticks(sd_id128_t vendor, const char *name, unsigned long speed, usec_t *u) {
+        _cleanup_free_ void *i = NULL;
+        _cleanup_free_ char *j = NULL;
+        size_t is;
+        int r;
+        uint64_t x;
+
+        assert(name);
+        assert(u);
+
+        r = efi_get_variable(EFI_VENDOR_LOADER, name, NULL, &i, &is);
+        if (r < 0)
+                return r;
+
+        j = utf16_to_utf8(i, is);
+        if (!j)
+                return -ENOMEM;
+
+        r = safe_atou64(j, &x);
+        if (r < 0)
+                return r;
+
+        *u = USEC_PER_SEC * x / speed;
+        return 0;
+}
+
+static int get_boot_usec(usec_t *firmware, usec_t *loader) {
+        uint64_t x, y;
+        int r;
+        unsigned long bogomips;
+
+        assert(firmware);
+        assert(loader);
+
+        /* Returns the usec after the CPU was turned on. The two
+         * timestamps are: the firmware finished, and the boot loader
+         * finished. */
+
+        /* We assume that the kernel's bogomips value is calibrated to
+         * twice the CPU frequency, and use this to convert the TSC
+         * ticks into usec. Of course, bogomips are only vaguely
+         * defined. If this breaks one day we can come up with
+         * something better. However, for now this saves us from doing
+         * a local calibration loop. */
+
+        r = read_bogomips(&bogomips);
+        if (r < 0)
+                return r;
+
+        r = read_ticks(EFI_VENDOR_LOADER, "LoaderTicksInit", bogomips / 2, &x);
+        if (r < 0)
+                return r;
+
+        r = read_ticks(EFI_VENDOR_LOADER, "LoaderTicksExec", bogomips / 2, &y);
+        if (r < 0)
+                return r;
+
+        if (y == 0 || y < x)
+                return -EIO;
+
+        if (y > USEC_PER_HOUR)
+                return -EIO;
+
+        *firmware = x;
+        *loader = y;
+
+        return 0;
+}
+
+int efi_get_boot_timestamps(const dual_timestamp *n, dual_timestamp *firmware, dual_timestamp *loader) {
+        usec_t x, y, a;
+        int r;
+        dual_timestamp _n;
+
+        assert(firmware);
+        assert(loader);
+
+        if (!n) {
+                dual_timestamp_get(&_n);
+                n = &_n;
+        }
+
+        r = get_boot_usec(&x, &y);
+        if (r < 0)
+                return r;
+
+        /* Let's convert this to timestamps where the firmware
+         * began/loader began working. To make this more confusing:
+         * since usec_t is unsigned and the kernel's monotonic clock
+         * begins at kernel initialization we'll actually initialize
+         * the monotonic timestamps here as negative of the actual
+         * value. */
+
+        firmware->monotonic = y;
+        loader->monotonic = y - x;
+
+        a = n->monotonic + firmware->monotonic;
+        firmware->realtime = n->realtime > a ? n->realtime - a : 0;
+
+        a = n->monotonic + loader->monotonic;
+        loader->realtime = n->realtime > a ? n->realtime - a : 0;
+
+        return 0;
+}
diff --git a/src/shared/efivars.h b/src/shared/efivars.h
new file mode 100644
index 0000000000..7b65c9264e
--- /dev/null
+++ b/src/shared/efivars.h
@@ -0,0 +1,30 @@
+/*-*- Mode: C; c-basic-offset: 8; indent-tabs-mode: nil -*-*/
+
+#pragma once
+
+/***
+  This file is part of systemd.
+
+  Copyright 2013 Lennart Poettering
+
+  systemd is free software; you can redistribute it and/or modify it
+  under the terms of the GNU Lesser General Public License as published by
+  the Free Software Foundation; either version 2.1 of the License, or
+  (at your option) any later version.
+
+  systemd is distributed in the hope that it will be useful, but
+  WITHOUT ANY WARRANTY; without even the implied warranty of
+  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
+  Lesser General Public License for more details.
+
+  You should have received a copy of the GNU Lesser General Public License
+  along with systemd; If not, see <http://www.gnu.org/licenses/>.
+***/
+
+#include <sys/types.h>
+#include <inttypes.h>
+
+#include "sd-id128.h"
+
+int efi_get_variable(sd_id128_t vendor, const char *name, uint32_t *attribute, void **value, size_t *size);
+int efi_get_boot_timestamps(const dual_timestamp *n, dual_timestamp *firmware, dual_timestamp *loader);
diff --git a/src/shared/utf8.c b/src/shared/utf8.c
index 62e2803919..7ec8cb620d 100644
--- a/src/shared/utf8.c
+++ b/src/shared/utf8.c
@@ -49,6 +49,7 @@
 #include <stdbool.h>
 
 #include "utf8.h"
+#include "util.h"
 
 #define FILTER_CHAR '_'
 
@@ -283,3 +284,39 @@ char *ascii_filter(const char *str) {
 
         return r;
 }
+
+char *utf16_to_utf8(const void *s, size_t length) {
+        char *r;
+        const uint8_t *f;
+        uint8_t *t;
+
+        r = new(char, (length*3+1)/2 + 1);
+        if (!r)
+                return NULL;
+
+        t = (uint8_t*) r;
+
+        for (f = s; f < (const uint8_t*) s + length; f += 2) {
+                uint16_t c;
+
+                c = (f[1] << 8) | f[0];
+
+                if (c == 0) {
+                        *t = 0;
+                        return r;
+                } else if (c < 0x80) {
+                        *(t++) = (uint8_t) c;
+                } else if (c < 0x800) {
+                        *(t++) = (uint8_t) (0xc0 | (c >> 6));
+                        *(t++) = (uint8_t) (0x80 | (c & 0x3f));
+                } else {
+                        *(t++) = (uint8_t) (0xe0 | (c >> 12));
+                        *(t++) = (uint8_t) (0x80 | ((c >> 6) & 0x3f));
+                        *(t++) = (uint8_t) (0x80 | (c & 0x3f));
+                }
+        }
+
+        *t = 0;
+        return r;
+
+}
diff --git a/src/shared/utf8.h b/src/shared/utf8.h
index 13d2f6a980..794ae15ab9 100644
--- a/src/shared/utf8.h
+++ b/src/shared/utf8.h
@@ -30,3 +30,5 @@ char *utf8_is_printable_n(const char* str, size_t length) _pure_;
 
 char *utf8_filter(const char *s);
 char *ascii_filter(const char *s);
+
+char *utf16_to_utf8(const void *s, size_t length);
diff --git a/src/test/test-efivars.c b/src/test/test-efivars.c
new file mode 100644
index 0000000000..e54a83665a
--- /dev/null
+++ b/src/test/test-efivars.c
@@ -0,0 +1,47 @@
+/*-*- Mode: C; c-basic-offset: 8; indent-tabs-mode: nil -*-*/
+
+/***
+  This file is part of systemd.
+
+  Copyright 2013 Lennart Poettering
+
+  systemd is free software; you can redistribute it and/or modify it
+  under the terms of the GNU Lesser General Public License as published by
+  the Free Software Foundation; either version 2.1 of the License, or
+  (at your option) any later version.
+
+  systemd is distributed in the hope that it will be useful, but
+  WITHOUT ANY WARRANTY; without even the implied warranty of
+  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
+  Lesser General Public License for more details.
+
+  You should have received a copy of the GNU Lesser General Public License
+  along with systemd; If not, see <http://www.gnu.org/licenses/>.
+***/
+
+#include "util.h"
+#include "log.h"
+#include "efivars.h"
+
+int main(int argc, char* argv[]) {
+        char s[MAX(FORMAT_TIMESPAN_MAX, FORMAT_TIMESTAMP_MAX)];
+        int r;
+        dual_timestamp fw, l, k;
+
+        dual_timestamp_from_monotonic(&k, 0);
+
+        r = efi_get_boot_timestamps(NULL, &fw, &l);
+        if (r < 0) {
+                log_error("Failed to read variables: %s", strerror(-r));
+                return 1;
+        }
+
+        log_info("Firmware began %s before kernel.", format_timespan(s, sizeof(s), fw.monotonic));
+        log_info("Loader began %s before kernel.", format_timespan(s, sizeof(s), l.monotonic));
+
+        log_info("Firmware began %s.", format_timestamp(s, sizeof(s), fw.realtime));
+        log_info("Loader began %s.", format_timestamp(s, sizeof(s), l.realtime));
+        log_info("Kernel began %s.", format_timestamp(s, sizeof(s), k.realtime));
+
+        return 0;
+}