chiark / gitweb /
util: make time formatting a bit smarter
[elogind.git] / src / analyze / systemd-analyze.c
index 7603cc0de4884022a335c7a2d6218769683ac886..029ce9c9ebd3b1ababca458fa8f86137c9042de9 100644 (file)
@@ -3,7 +3,8 @@
 /***
   This file is part of systemd.
 
-  Copyright 2010 Lennart Poettering
+  Copyright 2010-2013 Lennart Poettering
+  Copyright 2013 Simon Peeters
 
   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
 #include "strxcpyx.h"
 #include "fileio.h"
 
+#define SCALE_X (0.1 / 1000.0)   /* pixels per us */
+#define SCALE_Y 20.0
+
 #define compare(a, b) (((a) > (b))? 1 : (((b) > (a))? -1 : 0))
+
 #define svg(...) printf(__VA_ARGS__)
-#define svg_bar(class, x1, x2, y) \
+
+#define svg_bar(class, x1, x2, y)                                       \
         svg("  <rect class=\"%s\" x=\"%.03f\" y=\"%.03f\" width=\"%.03f\" height=\"%.03f\" />\n", \
-                        (class), \
-                        scale_x * (x1), scale_y * (y), \
-                        scale_x * ((x2) - (x1)), scale_y - 1.0)
-#define svg_text(x, y, format, ...) do {\
-        svg("  <text x=\"%.03f\" y=\"%.03f\">", scale_x * (x) + 5.0, scale_y * (y) + 14.0); \
-        svg(format, ## __VA_ARGS__); \
-        svg("</text>\n"); \
+            (class),                                                    \
+            SCALE_X * (x1), SCALE_Y * (y),                              \
+            SCALE_X * ((x2) - (x1)), SCALE_Y - 1.0)
+
+#define svg_text(b, x, y, format, ...)                                  \
+        do {                                                            \
+                svg("  <text class=\"%s\" x=\"%.03f\" y=\"%.03f\">", (b) ? "left" : "right", SCALE_X * (x) + (b ? 5.0 : -5.0), SCALE_Y * (y) + 14.0); \
+                svg(format, ## __VA_ARGS__);                            \
+                svg("</text>\n");                                       \
         } while(false)
 
 static UnitFileScope arg_scope = UNIT_FILE_SYSTEM;
@@ -53,34 +61,30 @@ static enum dot {
         DEP_REQUIRE
 } arg_dot = DEP_ALL;
 
-double scale_x = 0.1;   // pixels per ms
-double scale_y = 20.0;
-
 struct boot_times {
-        uint64_t firmware_time;
-        uint64_t loader_time;
-        uint64_t kernel_time;
-        uint64_t kernel_done_time;
-        uint64_t initrd_time;
-        uint64_t userspace_time;
-        uint64_t finish_time;
+        usec_t firmware_time;
+        usec_t loader_time;
+        usec_t kernel_time;
+        usec_t kernel_done_time;
+        usec_t initrd_time;
+        usec_t userspace_time;
+        usec_t finish_time;
 };
 struct unit_times {
         char *name;
-        uint64_t ixt;
-        uint64_t iet;
-        uint64_t axt;
-        uint64_t aet;
-        uint64_t time;
+        usec_t ixt;
+        usec_t iet;
+        usec_t axt;
+        usec_t aet;
+        usec_t time;
 };
 
-static int bus_get_uint64_property (DBusConnection *bus, const char *path, const char *interface, const char *property, uint64_t *val)
-{
+static int bus_get_uint64_property(DBusConnection *bus, const char *path, const char *interface, const char *property, uint64_t *val) {
         _cleanup_dbus_message_unref_ DBusMessage *reply = NULL;
-        int r;
         DBusMessageIter iter, sub;
+        int r;
 
-        r = bus_method_call_with_reply (
+        r = bus_method_call_with_reply(
                         bus,
                         "org.freedesktop.systemd1",
                         path,
@@ -112,34 +116,47 @@ static int bus_get_uint64_property (DBusConnection *bus, const char *path, const
         return 0;
 }
 
-static int compare_unit_time(const void *a, const void *b)
-{
+static int compare_unit_time(const void *a, const void *b) {
         return compare(((struct unit_times *)b)->time,
                        ((struct unit_times *)a)->time);
 }
 
-static int compare_unit_start(const void *a, const void *b)
-{
+static int compare_unit_start(const void *a, const void *b) {
         return compare(((struct unit_times *)a)->ixt,
                        ((struct unit_times *)b)->ixt);
 }
 
-static char *get_os_name(void)
-{
+static int get_os_name(char **_n) {
         char *n = NULL;
+        int r;
+
+        r = parse_env_file("/etc/os-release", NEWLINE, "PRETTY_NAME", &n, NULL);
+        if (r < 0)
+                return r;
+
+        if (!n)
+                return -ENOENT;
 
-        parse_env_file("/etc/os-release", NEWLINE, "PRETTY_NAME", &n, NULL);
-        return n;
+        *_n = n;
+        return 0;
 }
 
-static int acquire_time_data(DBusConnection *bus, struct unit_times **out)
-{
+static void free_unit_times(struct unit_times *t, unsigned n) {
+        struct unit_times *p;
+
+        for (p = t; p < t + n; p++)
+                free(p->name);
+
+        free(t);
+}
+
+static int acquire_time_data(DBusConnection *bus, struct unit_times **out) {
         _cleanup_dbus_message_unref_ DBusMessage *reply = NULL;
         DBusMessageIter iter, sub;
         int r, c = 0, n_units = 0;
         struct unit_times *unit_times = NULL;
 
-        r = bus_method_call_with_reply (
+        r = bus_method_call_with_reply(
                         bus,
                         "org.freedesktop.systemd1",
                         "/org/freedesktop/systemd1",
@@ -148,7 +165,7 @@ static int acquire_time_data(DBusConnection *bus, struct unit_times **out)
                         &reply,
                         NULL,
                         DBUS_TYPE_INVALID);
-        if (r)
+        if (r < 0)
                 goto fail;
 
         if (!dbus_message_iter_init(reply, &iter) ||
@@ -191,6 +208,8 @@ static int acquire_time_data(DBusConnection *bus, struct unit_times **out)
                 if (r < 0)
                         goto fail;
 
+                assert_cc(sizeof(usec_t) == sizeof(uint64_t));
+
                 if (bus_get_uint64_property(bus, u.unit_path,
                                             "org.freedesktop.systemd1.Unit",
                                             "InactiveExitTimestampMonotonic",
@@ -211,11 +230,6 @@ static int acquire_time_data(DBusConnection *bus, struct unit_times **out)
                         goto fail;
                 }
 
-                t->iet /= 1000;
-                t->ixt /= 1000;
-                t->aet /= 1000;
-                t->axt /= 1000;
-
                 if (t->aet >= t->ixt)
                         t->time = t->aet - t->ixt;
                 else if (t->iet >= t->ixt)
@@ -236,21 +250,20 @@ static int acquire_time_data(DBusConnection *bus, struct unit_times **out)
 
         *out = unit_times;
         return c;
+
 fail:
-        if (unit_times) {
-                for (; c >= 0; c--)
-                        free(unit_times[c].name);
-                free(unit_times);
-        }
+        free_unit_times(unit_times, (unsigned) c);
         return r;
 }
 
-static struct boot_times *acquire_boot_times(DBusConnection *bus)
-{
+static int acquire_boot_times(DBusConnection *bus, struct boot_times **bt) {
         static struct boot_times times;
         static bool cached = false;
+
         if (cached)
-                return &times;
+                goto finish;
+
+        assert_cc(sizeof(usec_t) == sizeof(uint64_t));
 
         if (bus_get_uint64_property(bus,
                                     "/org/freedesktop/systemd1",
@@ -282,112 +295,114 @@ static struct boot_times *acquire_boot_times(DBusConnection *bus)
                                     "org.freedesktop.systemd1.Manager",
                                     "FinishTimestampMonotonic",
                                     &times.finish_time) < 0)
-                return NULL;
+                return -EIO;
 
-        if (!times.finish_time) {
+        if (times.finish_time <= 0) {
                 log_error("Bootup is not yet finished. Please try again later.");
-                return NULL;
+                return -EAGAIN;
         }
 
-        times.firmware_time /= 1000;
-        times.loader_time /= 1000;
-        times.initrd_time /= 1000;
-        times.userspace_time /= 1000;
-        times.finish_time /= 1000;
-
         if (times.initrd_time)
                 times.kernel_done_time = times.initrd_time;
         else
                 times.kernel_done_time = times.userspace_time;
 
         cached = true;
-        return &times;
+
+finish:
+        *bt = &times;
+        return 0;
 }
 
-static char *pretty_boot_time(DBusConnection *bus)
-{
+static int pretty_boot_time(DBusConnection *bus, char **_buf) {
+        char ts[FORMAT_TIMESPAN_MAX];
         struct boot_times *t;
-        size_t size = 4096;
         static char buf[4096];
-        char *ptr = buf;
+        size_t size;
+        char *ptr;
+        int r;
 
-        t = acquire_boot_times(bus);
-        if (!t)
-                return NULL;
+        r = acquire_boot_times(bus, &t);
+        if (r < 0)
+                return r;
+
+        ptr = buf;
+        size = sizeof(buf);
 
         size = strpcpyf(&ptr, size, "Startup finished in ");
         if (t->firmware_time)
-                size = strpcpyf(&ptr, size, "%llums (firmware) + ", (unsigned long long)(t->firmware_time - t->loader_time));
+                size = strpcpyf(&ptr, size, "%s (firmware) + ", format_timespan(ts, sizeof(ts), t->firmware_time - t->loader_time, USEC_PER_MSEC));
         if (t->loader_time)
-                size = strpcpyf(&ptr, size, "%llums (loader) + ", (unsigned long long)t->loader_time);
+                size = strpcpyf(&ptr, size, "%s (loader) + ", format_timespan(ts, sizeof(ts), t->loader_time, USEC_PER_MSEC));
         if (t->kernel_time)
-                size = strpcpyf(&ptr, size, "%llums (kernel) + ", (unsigned long long)t->kernel_done_time);
+                size = strpcpyf(&ptr, size, "%s (kernel) + ", format_timespan(ts, sizeof(ts), t->kernel_done_time, USEC_PER_MSEC));
         if (t->initrd_time > 0)
-                size = strpcpyf(&ptr, size, "%llums (initrd) + ", (unsigned long long)(t->userspace_time - t->initrd_time));
+                size = strpcpyf(&ptr, size, "%s (initrd) + ", format_timespan(ts, sizeof(ts), t->userspace_time - t->initrd_time, USEC_PER_MSEC));
 
-        size = strpcpyf(&ptr, size, "%llums (userspace) ", (unsigned long long)(t->finish_time - t->userspace_time));
+        size = strpcpyf(&ptr, size, "%s (userspace) ", format_timespan(ts, sizeof(ts), t->finish_time - t->userspace_time, USEC_PER_MSEC));
         if (t->kernel_time > 0)
-                size = strpcpyf(&ptr, size, "= %llums", (unsigned long long)(t->firmware_time + t->finish_time));
+                size = strpcpyf(&ptr, size, "= %s", format_timespan(ts, sizeof(ts), t->firmware_time + t->finish_time, USEC_PER_MSEC));
         else
-                size = strpcpyf(&ptr, size, "= %llums", (unsigned long long)(t->finish_time - t->userspace_time));
+                size = strpcpyf(&ptr, size, "= %s", format_timespan(ts, sizeof(ts), t->finish_time - t->userspace_time, USEC_PER_MSEC));
+
+        ptr = strdup(buf);
+        if (!ptr)
+                return log_oom();
 
-        return buf;
+        *_buf = ptr;
+        return 0;
 }
 
-static void svg_graph_box(int height, int64_t begin, int64_t end)
-{
+static void svg_graph_box(double height, double begin, double end) {
+        long long i;
+
         /* outside box, fill */
         svg("<rect class=\"box\" x=\"0\" y=\"0\" width=\"%.03f\" height=\"%.03f\" />\n",
-            scale_x * (end - begin), scale_y * height);
+            SCALE_X * (end - begin), SCALE_Y * height);
 
-        for (int i = (begin / 100) * 100; i <= end; i+=100) {
+        for (i = ((long long) (begin / 100000)) * 100000; i <= end; i+=100000) {
                 /* lines for each second */
-                if (i % 5000 == 0)
+                if (i % 5000000 == 0)
                         svg("  <line class=\"sec5\" x1=\"%.03f\" y1=\"0\" x2=\"%.03f\" y2=\"%.03f\" />\n"
                             "  <text class=\"sec\" x=\"%.03f\" y=\"%.03f\" >%.01fs</text>\n",
-                            scale_x * i, scale_x * i, scale_y * height, scale_x * i, -5.0, 0.001 * i);
-                else if (i % 1000 == 0)
+                            SCALE_X * i, SCALE_X * i, SCALE_Y * height, SCALE_X * i, -5.0, 0.000001 * i);
+                else if (i % 1000000 == 0)
                         svg("  <line class=\"sec1\" x1=\"%.03f\" y1=\"0\" x2=\"%.03f\" y2=\"%.03f\" />\n"
                             "  <text class=\"sec\" x=\"%.03f\" y=\"%.03f\" >%.01fs</text>\n",
-                            scale_x * i, scale_x * i, scale_y * height, scale_x * i, -5.0, 0.001 * i);
+                            SCALE_X * i, SCALE_X * i, SCALE_Y * height, SCALE_X * i, -5.0, 0.000001 * i);
                 else
                         svg("  <line class=\"sec01\" x1=\"%.03f\" y1=\"0\" x2=\"%.03f\" y2=\"%.03f\" />\n",
-                            scale_x * i, scale_x * i, scale_y * height);
+                            SCALE_X * i, SCALE_X * i, SCALE_Y * height);
         }
 }
 
-static int analyze_plot(DBusConnection *bus)
-{
+static int analyze_plot(DBusConnection *bus) {
         struct unit_times *times;
         struct boot_times *boot;
         struct utsname name;
         int n, m = 1, y=0;
         double width;
-        char *osname;
-        char *pretty_times;
+        _cleanup_free_ char *pretty_times = NULL, *osname = NULL;
+        struct unit_times *u;
 
-        boot = acquire_boot_times(bus);
-        if (!boot)
-                return -EIO;
-        pretty_times = pretty_boot_time(bus);
-        if (!pretty_times)
-                return -EIO;
+        n = acquire_boot_times(bus, &boot);
+        if (n < 0)
+                return n;
 
-        osname = get_os_name();
+        n = pretty_boot_time(bus, &pretty_times);
+        if (n < 0)
+                return n;
 
-        n = uname(&name);
-        if (n < 0) {
-                log_error("Cannot get system name: %m");
-                return -errno;
-        }
+        get_os_name(&osname);
+        assert_se(uname(&name) >= 0);
 
         n = acquire_time_data(bus, &times);
-        if (n<=0)
+        if (n <= 0)
                 return n;
 
         qsort(times, n, sizeof(struct unit_times), compare_unit_start);
 
-        width = scale_x * (boot->firmware_time + boot->finish_time);
+        width = SCALE_X * (boot->firmware_time + boot->finish_time);
         if (width < 800.0)
                 width = 800.0;
 
@@ -403,15 +418,16 @@ static int analyze_plot(DBusConnection *bus)
         if (boot->kernel_time)
                 m++;
 
-        for (struct unit_times *u = times; u < times + n; u++) {
+        for (u = times; u < times + n; u++) {
                 double len;
+
                 if (u->ixt < boot->userspace_time ||
                     u->ixt > boot->finish_time) {
                         free(u->name);
                         u->name = NULL;
                         continue;
                 }
-                len = ((boot->firmware_time + u->ixt) * scale_x)
+                len = ((boot->firmware_time + u->ixt) * SCALE_X)
                         + (10.0 * strlen(u->name));
                 if (len > width)
                         width = len;
@@ -434,7 +450,7 @@ static int analyze_plot(DBusConnection *bus)
 
         svg("<svg width=\"%.0fpx\" height=\"%.0fpx\" version=\"1.1\" "
             "xmlns=\"http://www.w3.org/2000/svg\">\n\n",
-                        80.0 + width, 150.0 + (m * scale_y));
+                        80.0 + width, 150.0 + (m * SCALE_Y));
 
         /* write some basic info as a comment, including some help */
         svg("<!-- This file is a systemd-analyze SVG file. It is best rendered in a   -->\n"
@@ -461,82 +477,104 @@ static int analyze_plot(DBusConnection *bus)
             "      line.sec5  { stroke-width: 2; }\n"
             "      line.sec01 { stroke: rgb(224,224,224); stroke-width: 1; }\n"
             "      text       { font-family: Verdana, Helvetica; font-size: 10; }\n"
+            "      text.left  { font-family: Verdana, Helvetica; font-size: 10; text-anchor: start; }\n"
+            "      text.right { font-family: Verdana, Helvetica; font-size: 10; text-anchor: end; }\n"
             "      text.sec   { font-size: 8; }\n"
             "    ]]>\n   </style>\n</defs>\n\n");
 
         svg("<text x=\"20\" y=\"50\">%s</text>", pretty_times);
         svg("<text x=\"20\" y=\"30\">%s %s (%s %s) %s</text>",
-            isempty(osname)? "Linux" : osname,
+            isempty(osname) ? "Linux" : osname,
             name.nodename, name.release, name.version, name.machine);
         svg("<text x=\"20\" y=\"%.0f\">Legend: Red = Activating; Pink = Active; Dark Pink = Deactivating</text>",
-                        120.0 + (m *scale_y));
+                        120.0 + (m *SCALE_Y));
 
-        svg("<g transform=\"translate(%.3f,100)\">\n", 20.0 + (scale_x * boot->firmware_time));
+        svg("<g transform=\"translate(%.3f,100)\">\n", 20.0 + (SCALE_X * boot->firmware_time));
         svg_graph_box(m, -boot->firmware_time, boot->finish_time);
 
         if (boot->firmware_time) {
-                svg_bar("firmware", -(int64_t) boot->firmware_time, -(int64_t) boot->loader_time, y);
-                svg_text(-(int64_t) boot->firmware_time, y, "firmware");
+                svg_bar("firmware", -(double) boot->firmware_time, -(double) boot->loader_time, y);
+                svg_text(true, -(double) boot->firmware_time, y, "firmware");
                 y++;
         }
         if (boot->loader_time) {
-                svg_bar("loader", -(int64_t) boot->loader_time, 0, y);
-                svg_text(-(int64_t) boot->loader_time, y, "loader");
+                svg_bar("loader", -(double) boot->loader_time, 0, y);
+                svg_text(true, -(double) boot->loader_time, y, "loader");
                 y++;
         }
         if (boot->kernel_time) {
                 svg_bar("kernel", 0, boot->kernel_done_time, y);
-                svg_text(0, y, "kernel");
+                svg_text(true, 0, y, "kernel");
                 y++;
         }
         if (boot->initrd_time) {
                 svg_bar("initrd", boot->initrd_time, boot->userspace_time, y);
-                svg_text(boot->initrd_time, y, "initrd");
+                svg_text(true, boot->initrd_time, y, "initrd");
                 y++;
         }
         svg_bar("userspace", boot->userspace_time, boot->finish_time, y);
-        svg_text(boot->userspace_time, y, "userspace");
+        svg_text("left", boot->userspace_time, y, "userspace");
         y++;
 
-        for (struct unit_times *u = times; u < times + n; u++) {
+        for (u = times; u < times + n; u++) {
+                char ts[FORMAT_TIMESPAN_MAX];
+                bool b;
+
                 if (!u->name)
                         continue;
+
                 svg_bar("activating",   u->ixt, u->aet, y);
                 svg_bar("active",       u->aet, u->axt, y);
                 svg_bar("deactivating", u->axt, u->iet, y);
-                svg_text(u->ixt, y, u->time? "%s (%llums)" : "%s", u->name, (unsigned long long)u->time);
+
+                b = u->ixt * SCALE_X > width * 2 / 3;
+                if (u->time)
+                        svg_text(b, u->ixt, y, "%s (%s)",
+                                 u->name, format_timespan(ts, sizeof(ts), u->time, USEC_PER_MSEC));
+                else
+                        svg_text(b, u->ixt, y, "%s", u->name);
                 y++;
         }
         svg("</g>\n\n");
 
         svg("</svg>");
+
+        free_unit_times(times, (unsigned) n);
+
         return 0;
 }
 
-static int analyze_blame(DBusConnection *bus)
-{
+static int analyze_blame(DBusConnection *bus) {
         struct unit_times *times;
-        int n = acquire_time_data(bus, &times);
-        if (n<=0)
+        unsigned i;
+        int n;
+
+        n = acquire_time_data(bus, &times);
+        if (n <= 0)
                 return n;
 
         qsort(times, n, sizeof(struct unit_times), compare_unit_time);
 
-        for (int i = 0; i < n; i++) {
-                if (times[i].time)
-                        printf("%6llums %s\n", (unsigned long long)times[i].time, times[i].name);
+        for (i = 0; i < (unsigned) n; i++) {
+                char ts[FORMAT_TIMESPAN_MAX];
+
+                if (times[i].time > 0)
+                        printf("%16s %s\n", format_timespan(ts, sizeof(ts), times[i].time, USEC_PER_MSEC), times[i].name);
         }
+
+        free_unit_times(times, (unsigned) n);
         return 0;
 }
 
-static int analyze_time(DBusConnection *bus)
-{
-        char *buf;
-        buf = pretty_boot_time(bus);
-        if (!buf)
-                return -EIO;
-        if (puts(buf) == EOF)
-                return -errno;
+static int analyze_time(DBusConnection *bus) {
+        _cleanup_free_ char *buf = NULL;
+        int r;
+
+        r = pretty_boot_time(bus, &buf);
+        if (r < 0)
+                return r;
+
+        puts(buf);
         return 0;
 }
 
@@ -741,32 +779,41 @@ static int parse_argv(int argc, char *argv[])
         assert(argc >= 0);
         assert(argv);
 
-        while (true) {
+        for (;;) {
                 switch (getopt_long(argc, argv, "h", options, NULL)) {
-                        case 'h':
-                                analyze_help();
-                                return 0;
-                        case ARG_VERSION:
-                                puts(PACKAGE_STRING "\n" SYSTEMD_FEATURES);
-                                return 0;
-                        case ARG_USER:
-                                arg_scope = UNIT_FILE_USER;
-                                break;
-                        case ARG_SYSTEM:
-                                arg_scope = UNIT_FILE_SYSTEM;
-                                break;
-                        case ARG_ORDER:
-                                arg_dot = DEP_ORDER;
-                                break;
-                        case ARG_REQUIRE:
-                                arg_dot = DEP_REQUIRE;
-                                break;
-                        case -1:
-                                return 1;
-                        case '?':
-                                return -EINVAL;
-                        default:
-                                assert_not_reached("Unhandled option");
+
+                case 'h':
+                        analyze_help();
+                        return 0;
+
+                case ARG_VERSION:
+                        puts(PACKAGE_STRING "\n" SYSTEMD_FEATURES);
+                        return 0;
+
+                case ARG_USER:
+                        arg_scope = UNIT_FILE_USER;
+                        break;
+
+                case ARG_SYSTEM:
+                        arg_scope = UNIT_FILE_SYSTEM;
+                        break;
+
+                case ARG_ORDER:
+                        arg_dot = DEP_ORDER;
+                        break;
+
+                case ARG_REQUIRE:
+                        arg_dot = DEP_REQUIRE;
+                        break;
+
+                case -1:
+                        return 1;
+
+                case '?':
+                        return -EINVAL;
+
+                default:
+                        assert_not_reached("Unhandled option");
                 }
         }
 }
@@ -776,18 +823,19 @@ int main(int argc, char *argv[]) {
         DBusConnection *bus = NULL;
 
         setlocale(LC_ALL, "");
+        setlocale(LC_NUMERIC, "C"); /* we want to format/parse floats in C style */
         log_parse_environment();
         log_open();
 
         r = parse_argv(argc, argv);
-        if (r == 0)
-                return 0;
         if (r < 0)
-                return 1;
+                return EXIT_FAILURE;
+        else if (r <= 0)
+                return EXIT_SUCCESS;
 
         bus = dbus_bus_get(arg_scope == UNIT_FILE_SYSTEM ? DBUS_BUS_SYSTEM : DBUS_BUS_SESSION, NULL);
         if (!bus)
-                return 1;
+                return EXIT_FAILURE;
 
         if (!argv[optind] || streq(argv[optind], "time"))
                 r = analyze_time(bus);
@@ -801,7 +849,6 @@ int main(int argc, char *argv[]) {
                 log_error("Unknown operation '%s'.", argv[optind]);
 
         dbus_connection_unref(bus);
-        if (r)
-                return 1;
-        return 0;
+
+        return r < 0 ? EXIT_FAILURE : EXIT_SUCCESS;
 }