/*-*- Mode: C; c-basic-offset: 8; indent-tabs-mode: nil -*-*/ /*** This file is part of systemd. Copyright 2010 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 . ***/ #include #include #include #include #include #include "install.h" #include "log.h" #include "dbus-common.h" #include "build.h" #include "util.h" #include "strxcpyx.h" #define compare(a, b) (((a) > (b))? 1 : (((b) > (a))? -1 : 0)) #define svg(...) printf(__VA_ARGS__) #define svg_bar(class, x1, x2, y) \ svg(" \n", \ (class), \ scale_x * (x1), scale_y * (y), \ scale_x * ((x2) - (x1)), scale_y - 1.0) #define svg_text(x, y, format, ...) do {\ svg(" ", scale_x * (x) + 5.0, scale_y * (y) + 14.0); \ svg(format, ## __VA_ARGS__); \ svg("\n"); \ } while(false) static UnitFileScope arg_scope = UNIT_FILE_SYSTEM; 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; }; struct unit_times { char *name; uint64_t ixt; uint64_t iet; uint64_t axt; uint64_t aet; uint64_t time; }; 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; r = bus_method_call_with_reply ( bus, "org.freedesktop.systemd1", path, "org.freedesktop.DBus.Properties", "Get", &reply, NULL, DBUS_TYPE_STRING, &interface, DBUS_TYPE_STRING, &property, DBUS_TYPE_INVALID); if (r < 0) return r; if (!dbus_message_iter_init(reply, &iter) || dbus_message_iter_get_arg_type(&iter) != DBUS_TYPE_VARIANT) { log_error("Failed to parse reply."); return -EIO; } dbus_message_iter_recurse(&iter, &sub); if (dbus_message_iter_get_arg_type(&sub) != DBUS_TYPE_UINT64) { log_error("Failed to parse reply."); return -EIO; } dbus_message_iter_get_basic(&sub, val); return 0; } 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) { return compare(((struct unit_times *)a)->ixt, ((struct unit_times *)b)->ixt); } static char *get_os_name(void) { char *n = NULL; parse_env_file("/etc/os-release", NEWLINE, "PRETTY_NAME", &n, NULL); return n; } 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 ( bus, "org.freedesktop.systemd1", "/org/freedesktop/systemd1", "org.freedesktop.systemd1.Manager", "ListUnits", &reply, NULL, DBUS_TYPE_INVALID); if (r) goto fail; if (!dbus_message_iter_init(reply, &iter) || dbus_message_iter_get_arg_type(&iter) != DBUS_TYPE_ARRAY || dbus_message_iter_get_element_type(&iter) != DBUS_TYPE_STRUCT) { log_error("Failed to parse reply."); r = -EIO; goto fail; } for (dbus_message_iter_recurse(&iter, &sub); dbus_message_iter_get_arg_type(&sub) != DBUS_TYPE_INVALID; dbus_message_iter_next(&sub)) { struct unit_info u; struct unit_times *t; if (dbus_message_iter_get_arg_type(&sub) != DBUS_TYPE_STRUCT) { log_error("Failed to parse reply."); r = -EIO; goto fail; } if (c >= n_units) { struct unit_times *w; n_units = MAX(2*c, 16); w = realloc(unit_times, sizeof(struct unit_times) * n_units); if (!w) { r = log_oom(); goto fail; } unit_times = w; } t = unit_times+c; t->name = NULL; r = bus_parse_unit_info(&sub, &u); if (r < 0) goto fail; if (bus_get_uint64_property(bus, u.unit_path, "org.freedesktop.systemd1.Unit", "InactiveExitTimestampMonotonic", &t->ixt) < 0 || bus_get_uint64_property(bus, u.unit_path, "org.freedesktop.systemd1.Unit", "ActiveEnterTimestampMonotonic", &t->aet) < 0 || bus_get_uint64_property(bus, u.unit_path, "org.freedesktop.systemd1.Unit", "ActiveExitTimestampMonotonic", &t->axt) < 0 || bus_get_uint64_property(bus, u.unit_path, "org.freedesktop.systemd1.Unit", "InactiveEnterTimestampMonotonic", &t->iet) < 0) { r = -EIO; 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) t->time = t->iet - t->ixt; else t->time = 0; if (t->ixt == 0) continue; t->name = strdup(u.id); if (t->name == NULL) { r = log_oom(); goto fail; } c++; } *out = unit_times; return c; fail: for (; c >= 0; c--) free(unit_times[c].name); free(unit_times); return r; } static struct boot_times *acquire_boot_times(DBusConnection *bus) { static struct boot_times times; static bool cached = false; if (cached) return × if (bus_get_uint64_property(bus, "/org/freedesktop/systemd1", "org.freedesktop.systemd1.Manager", "FirmwareTimestampMonotonic", ×.firmware_time) < 0 || bus_get_uint64_property(bus, "/org/freedesktop/systemd1", "org.freedesktop.systemd1.Manager", "LoaderTimestampMonotonic", ×.loader_time) < 0 || bus_get_uint64_property(bus, "/org/freedesktop/systemd1", "org.freedesktop.systemd1.Manager", "KernelTimestamp", ×.kernel_time) < 0 || bus_get_uint64_property(bus, "/org/freedesktop/systemd1", "org.freedesktop.systemd1.Manager", "InitRDTimestampMonotonic", ×.initrd_time) < 0 || bus_get_uint64_property(bus, "/org/freedesktop/systemd1", "org.freedesktop.systemd1.Manager", "UserspaceTimestampMonotonic", ×.userspace_time) < 0 || bus_get_uint64_property(bus, "/org/freedesktop/systemd1", "org.freedesktop.systemd1.Manager", "FinishTimestampMonotonic", ×.finish_time) < 0) return NULL; if (!times.finish_time) { log_error("Bootup is not yet finished. Please try again later."); return NULL; } 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 × } static char *pretty_boot_time(DBusConnection *bus) { struct boot_times *t; size_t size = 4096; static char buf[4096]; char *ptr = buf; t = acquire_boot_times(bus); if (!t) return NULL; 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)); if (t->loader_time) size = strpcpyf(&ptr, size, "%llums (loader) + ", (unsigned long long)t->loader_time); if (t->kernel_time) size = strpcpyf(&ptr, size, "%llums (kernel) + ", (unsigned long long)t->kernel_done_time); if (t->initrd_time > 0) size = strpcpyf(&ptr, size, "%llums (initrd) + ", (unsigned long long)(t->userspace_time - t->initrd_time)); size = strpcpyf(&ptr, size, "%llums (userspace) ", (unsigned long long)(t->finish_time - t->userspace_time)); if (t->kernel_time > 0) size = strpcpyf(&ptr, size, "= %llums", (unsigned long long)(t->firmware_time + t->finish_time)); else size = strpcpyf(&ptr, size, "= %llums", (unsigned long long)(t->finish_time - t->userspace_time)); return buf; } static void svg_graph_box(int height, int64_t begin, int64_t end) { /* outside box, fill */ svg("\n", scale_x * (end - begin), scale_y * height); for (int i = (begin / 100) * 100; i <= end; i+=100) { /* lines for each second */ if (i % 5000 == 0) svg(" \n" " %.01fs\n", scale_x * i, scale_x * i, scale_y * height, scale_x * i, -5.0, 0.001 * i); else if (i % 1000 == 0) svg(" \n" " %.01fs\n", scale_x * i, scale_x * i, scale_y * height, scale_x * i, -5.0, 0.001 * i); else svg(" \n", scale_x * i, scale_x * i, scale_y * height); } } 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; boot = acquire_boot_times(bus); if (!boot) return -EIO; pretty_times = pretty_boot_time(bus); if (!pretty_times) return -EIO; osname = get_os_name(); n = uname(&name); if (n < 0) { log_error("Cannot get system name: %m"); return -errno; } n = acquire_time_data(bus, ×); if (n<=0) return n; qsort(times, n, sizeof(struct unit_times), compare_unit_start); width = scale_x * (boot->firmware_time + boot->finish_time); if (width < 800.0) width = 800.0; if (boot->firmware_time > boot->loader_time) m++; if (boot->loader_time) { m++; if (width < 1000.0) width = 1000.0; } if (boot->initrd_time) m++; if (boot->kernel_time) m++; for (struct unit_times *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) + (10.0 * strlen(u->name)); if (len > width) width = len; if (u->iet > u->ixt && u->iet <= boot->finish_time && u->aet == 0 && u->axt == 0) u->aet = u->axt = u->iet; if (u->aet < u->ixt || u->aet > boot->finish_time) u->aet = boot->finish_time; if (u->axt < u->aet || u->aet > boot->finish_time) u->axt = boot->finish_time; if (u->iet < u->axt || u->iet > boot->finish_time) u->iet = boot->finish_time; m++; } svg("\n" "\n"); svg("\n\n", 80.0 + width, 150.0 + (m * scale_y)); /* write some basic info as a comment, including some help */ svg("\n" "\n" "\n" "\n" "\n\n" "\n\n", VERSION); /* style sheet */ svg("\n \n\n\n"); svg("%s", pretty_times); svg("%s %s (%s %s) %s", isempty(osname)? "Linux" : osname, name.nodename, name.release, name.version, name.machine); svg("Legend: Red = Activating; Pink = Active; Dark Pink = Deactivating", 120.0 + (m *scale_y)); svg("\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"); y++; } if (boot->loader_time) { svg_bar("loader", -(int64_t) boot->loader_time, 0, y); svg_text(-(int64_t) boot->loader_time, y, "loader"); y++; } if (boot->kernel_time) { svg_bar("kernel", 0, boot->kernel_done_time, y); svg_text(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"); y++; } svg_bar("userspace", boot->userspace_time, boot->finish_time, y); svg_text(boot->userspace_time, y, "userspace"); y++; for (struct unit_times *u = times; u < times + n; u++) { 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); y++; } svg("\n\n"); svg(""); return 0; } static int analyze_blame(DBusConnection *bus) { struct unit_times *times; int n = acquire_time_data(bus, ×); 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); } 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; return 0; } static void analyze_help(void) { printf("%s [OPTIONS...] {COMMAND} ...\n\n" "Process systemd profiling information\n\n" " -h --help Show this help\n" " --version Show package version\n" " --system Connect to system manager\n" " --user Connect to user service manager\n\n" "Commands:\n" " time print time spent in the kernel before reaching userspace\n" " blame print list of running units ordered by time to init\n" " plot output SVG graphic showing service initialization\n\n", program_invocation_short_name); } static int parse_argv(int argc, char *argv[]) { enum { ARG_VERSION = 0x100, ARG_USER, ARG_SYSTEM }; static const struct option options[] = { { "help", no_argument, NULL, 'h' }, { "version", no_argument, NULL, ARG_VERSION }, { "user", no_argument, NULL, ARG_USER }, { "system", no_argument, NULL, ARG_SYSTEM }, { NULL, 0, NULL, 0 } }; assert(argc >= 0); assert(argv); while (true) { 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 -1: return 1; case '?': return -EINVAL; default: assert_not_reached("Unhandled option"); } } } int main(int argc, char *argv[]) { int r; DBusConnection *bus = NULL; setlocale(LC_ALL, ""); log_parse_environment(); log_open(); r = parse_argv(argc, argv); if (r == 0) return 0; if (r < 0) return 1; bus = dbus_bus_get(arg_scope == UNIT_FILE_SYSTEM ? DBUS_BUS_SYSTEM : DBUS_BUS_SESSION, NULL); if (!bus) return 1; if (!argv[optind] || streq(argv[optind], "time")) r = analyze_time(bus); else if (streq(argv[optind], "blame")) r = analyze_blame(bus); else if (streq(argv[optind], "plot")) r = analyze_plot(bus); else log_error("Unknown operation '%s'.", argv[optind]); dbus_connection_unref(bus); if (r) return 1; return 0; }