chiark / gitweb /
systemd-analyze: rewrite in C.
[elogind.git] / src / analyze / systemd-analyze.c
1 /*-*- Mode: C; c-basic-offset: 8; indent-tabs-mode: nil -*-*/
2
3 /***
4   This file is part of systemd.
5
6   Copyright 2010 Lennart Poettering
7
8   systemd is free software; you can redistribute it and/or modify it
9   under the terms of the GNU Lesser General Public License as published by
10   the Free Software Foundation; either version 2.1 of the License, or
11   (at your option) any later version.
12
13   systemd is distributed in the hope that it will be useful, but
14   WITHOUT ANY WARRANTY; without even the implied warranty of
15   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
16   Lesser General Public License for more details.
17
18   You should have received a copy of the GNU Lesser General Public License
19   along with systemd; If not, see <http://www.gnu.org/licenses/>.
20 ***/
21
22 #include <stdio.h>
23 #include <stdlib.h>
24 #include <getopt.h>
25 #include <locale.h>
26 #include <sys/utsname.h>
27
28 #include "install.h"
29 #include "log.h"
30 #include "dbus-common.h"
31 #include "build.h"
32 #include "util.h"
33 #include "strxcpyx.h"
34
35 #define compare(a, b) (((a) > (b))? 1 : (((b) > (a))? -1 : 0))
36 #define svg(...) printf(__VA_ARGS__)
37 #define svg_bar(class, x1, x2, y) \
38         svg("  <rect class=\"%s\" x=\"%.03f\" y=\"%.03f\" width=\"%.03f\" height=\"%.03f\" />\n", \
39                         (class), \
40                         scale_x * (x1), scale_y * (y), \
41                         scale_x * ((x2) - (x1)), scale_y - 1.0)
42 #define svg_text(x, y, format, ...) do {\
43         svg("  <text x=\"%.03f\" y=\"%.03f\">", scale_x * (x) + 5.0, scale_y * (y) + 14.0); \
44         svg(format, ## __VA_ARGS__); \
45         svg("</text>\n"); \
46         } while(false)
47
48 static UnitFileScope arg_scope = UNIT_FILE_SYSTEM;
49
50 double scale_x = 0.1;   // pixels per ms
51 double scale_y = 20.0;
52
53 struct boot_times {
54         uint64_t firmware_time;
55         uint64_t loader_time;
56         uint64_t kernel_time;
57         uint64_t kernel_done_time;
58         uint64_t initrd_time;
59         uint64_t userspace_time;
60         uint64_t finish_time;
61 };
62 struct unit_times {
63         char *name;
64         uint64_t ixt;
65         uint64_t iet;
66         uint64_t axt;
67         uint64_t aet;
68         uint64_t time;
69 };
70
71 static int bus_get_uint64_property (DBusConnection *bus, const char *path, const char *interface, const char *property, uint64_t *val)
72 {
73         _cleanup_dbus_message_unref_ DBusMessage *reply = NULL;
74         int r;
75         DBusMessageIter iter, sub;
76
77         r = bus_method_call_with_reply (
78                         bus,
79                         "org.freedesktop.systemd1",
80                         path,
81                         "org.freedesktop.DBus.Properties",
82                         "Get",
83                         &reply,
84                         NULL,
85                         DBUS_TYPE_STRING, &interface,
86                         DBUS_TYPE_STRING, &property,
87                         DBUS_TYPE_INVALID);
88         if (r < 0)
89                 return r;
90
91         if (!dbus_message_iter_init(reply, &iter) ||
92             dbus_message_iter_get_arg_type(&iter) != DBUS_TYPE_VARIANT)  {
93                 log_error("Failed to parse reply.");
94                 return -EIO;
95         }
96
97         dbus_message_iter_recurse(&iter, &sub);
98
99         if (dbus_message_iter_get_arg_type(&sub) != DBUS_TYPE_UINT64)  {
100                 log_error("Failed to parse reply.");
101                 return -EIO;
102         }
103
104         dbus_message_iter_get_basic(&sub, val);
105
106         return 0;
107 }
108
109 static int compare_unit_time(const void *a, const void *b)
110 {
111         return compare(((struct unit_times *)b)->time,
112                        ((struct unit_times *)a)->time);
113 }
114
115 static int compare_unit_start(const void *a, const void *b)
116 {
117         return compare(((struct unit_times *)a)->ixt,
118                        ((struct unit_times *)b)->ixt);
119 }
120
121 static char *get_os_name(void)
122 {
123         char *n = NULL;
124
125         parse_env_file("/etc/os-release", NEWLINE, "PRETTY_NAME", &n, NULL);
126         return n;
127 }
128
129 static int acquire_time_data(DBusConnection *bus, struct unit_times **out)
130 {
131         _cleanup_dbus_message_unref_ DBusMessage *reply = NULL;
132         DBusMessageIter iter, sub;
133         int r, c = 0, n_units = 0;
134         struct unit_times *unit_times = NULL;
135
136         r = bus_method_call_with_reply (
137                         bus,
138                         "org.freedesktop.systemd1",
139                         "/org/freedesktop/systemd1",
140                         "org.freedesktop.systemd1.Manager",
141                         "ListUnits",
142                         &reply,
143                         NULL,
144                         DBUS_TYPE_INVALID);
145         if (r)
146                 goto fail;
147
148         if (!dbus_message_iter_init(reply, &iter) ||
149                         dbus_message_iter_get_arg_type(&iter) != DBUS_TYPE_ARRAY ||
150                         dbus_message_iter_get_element_type(&iter) != DBUS_TYPE_STRUCT)  {
151                 log_error("Failed to parse reply.");
152                 r = -EIO;
153                 goto fail;
154         }
155
156         for (dbus_message_iter_recurse(&iter, &sub);
157              dbus_message_iter_get_arg_type(&sub) != DBUS_TYPE_INVALID;
158              dbus_message_iter_next(&sub)) {
159                 struct unit_info u;
160                 struct unit_times *t;
161
162                 if (dbus_message_iter_get_arg_type(&sub) != DBUS_TYPE_STRUCT) {
163                         log_error("Failed to parse reply.");
164                         r = -EIO;
165                         goto fail;
166                 }
167
168                 if (c >= n_units) {
169                         struct unit_times *w;
170
171                         n_units = MAX(2*c, 16);
172                         w = realloc(unit_times, sizeof(struct unit_times) * n_units);
173
174                         if (!w) {
175                                 r = log_oom();
176                                 goto fail;
177                         }
178
179                         unit_times = w;
180                 }
181                 t = unit_times+c;
182                 t->name = NULL;
183
184                 r = bus_parse_unit_info(&sub, &u);
185                 if (r < 0)
186                         goto fail;
187
188                 if (bus_get_uint64_property(bus, u.unit_path,
189                                             "org.freedesktop.systemd1.Unit",
190                                             "InactiveExitTimestampMonotonic",
191                                             &t->ixt) < 0 ||
192                     bus_get_uint64_property(bus, u.unit_path,
193                                             "org.freedesktop.systemd1.Unit",
194                                             "ActiveEnterTimestampMonotonic",
195                                             &t->aet) < 0 ||
196                     bus_get_uint64_property(bus, u.unit_path,
197                                             "org.freedesktop.systemd1.Unit",
198                                             "ActiveExitTimestampMonotonic",
199                                             &t->axt) < 0 ||
200                     bus_get_uint64_property(bus, u.unit_path,
201                                             "org.freedesktop.systemd1.Unit",
202                                             "InactiveEnterTimestampMonotonic",
203                                             &t->iet) < 0) {
204                         r = -EIO;
205                         goto fail;
206                 }
207
208                 t->iet /= 1000;
209                 t->ixt /= 1000;
210                 t->aet /= 1000;
211                 t->axt /= 1000;
212
213                 if (t->aet >= t->ixt)
214                         t->time = t->aet - t->ixt;
215                 else if (t->iet >= t->ixt)
216                         t->time = t->iet - t->ixt;
217                 else
218                         t->time = 0;
219
220                 if (t->ixt == 0)
221                         continue;
222
223                 t->name = strdup(u.id);
224                 if (t->name == NULL) {
225                         r = log_oom();
226                         goto fail;
227                 }
228                 c++;
229         }
230
231         *out = unit_times;
232         return c;
233 fail:
234         for (; c >= 0; c--)
235                 free(unit_times[c].name);
236         free(unit_times);
237         return r;
238 }
239
240 static struct boot_times *acquire_boot_times(DBusConnection *bus)
241 {
242         static struct boot_times times;
243         static bool cached = false;
244         if (cached)
245                 return &times;
246
247         if (bus_get_uint64_property(bus,
248                                     "/org/freedesktop/systemd1",
249                                     "org.freedesktop.systemd1.Manager",
250                                     "FirmwareTimestampMonotonic",
251                                     &times.firmware_time) < 0 ||
252             bus_get_uint64_property(bus,
253                                     "/org/freedesktop/systemd1",
254                                     "org.freedesktop.systemd1.Manager",
255                                     "LoaderTimestampMonotonic",
256                                     &times.loader_time) < 0 ||
257             bus_get_uint64_property(bus,
258                                     "/org/freedesktop/systemd1",
259                                     "org.freedesktop.systemd1.Manager",
260                                     "KernelTimestamp",
261                                     &times.kernel_time) < 0 ||
262             bus_get_uint64_property(bus,
263                                     "/org/freedesktop/systemd1",
264                                     "org.freedesktop.systemd1.Manager",
265                                     "InitRDTimestampMonotonic",
266                                     &times.initrd_time) < 0 ||
267             bus_get_uint64_property(bus,
268                                     "/org/freedesktop/systemd1",
269                                     "org.freedesktop.systemd1.Manager",
270                                     "UserspaceTimestampMonotonic",
271                                     &times.userspace_time) < 0 ||
272             bus_get_uint64_property(bus,
273                                     "/org/freedesktop/systemd1",
274                                     "org.freedesktop.systemd1.Manager",
275                                     "FinishTimestampMonotonic",
276                                     &times.finish_time) < 0)
277                 return NULL;
278
279         if (!times.finish_time) {
280                 log_error("Bootup is not yet finished. Please try again later.");
281                 return NULL;
282         }
283
284         times.firmware_time /= 1000;
285         times.loader_time /= 1000;
286         times.initrd_time /= 1000;
287         times.userspace_time /= 1000;
288         times.finish_time /= 1000;
289
290         if (times.initrd_time)
291                 times.kernel_done_time = times.initrd_time;
292         else
293                 times.kernel_done_time = times.userspace_time;
294
295         cached = true;
296         return &times;
297 }
298
299 static char *pretty_boot_time(DBusConnection *bus)
300 {
301         struct boot_times *t;
302         size_t size = 4096;
303         static char buf[4096];
304         char *ptr = buf;
305
306         t = acquire_boot_times(bus);
307         if (!t)
308                 return NULL;
309
310         size = strpcpyf(&ptr, size, "Startup finished in ");
311         if (t->firmware_time)
312                 size = strpcpyf(&ptr, size, "%llums (firmware) + ", (unsigned long long)(t->firmware_time - t->loader_time));
313         if (t->loader_time)
314                 size = strpcpyf(&ptr, size, "%llums (loader) + ", (unsigned long long)t->loader_time);
315         if (t->kernel_time)
316                 size = strpcpyf(&ptr, size, "%llums (kernel) + ", (unsigned long long)t->kernel_done_time);
317         if (t->initrd_time > 0)
318                 size = strpcpyf(&ptr, size, "%llums (initrd) + ", (unsigned long long)(t->userspace_time - t->initrd_time));
319
320         size = strpcpyf(&ptr, size, "%llums (userspace) ", (unsigned long long)(t->finish_time - t->userspace_time));
321         if (t->kernel_time > 0)
322                 size = strpcpyf(&ptr, size, "= %llums", (unsigned long long)(t->firmware_time + t->finish_time));
323         else
324                 size = strpcpyf(&ptr, size, "= %llums", (unsigned long long)(t->finish_time - t->userspace_time));
325
326         return buf;
327 }
328
329 static void svg_graph_box(int height, int64_t begin, int64_t end)
330 {
331         /* outside box, fill */
332         svg("<rect class=\"box\" x=\"0\" y=\"0\" width=\"%.03f\" height=\"%.03f\" />\n",
333             scale_x * (end - begin), scale_y * height);
334
335         for (int i = (begin / 100) * 100; i <= end; i+=100) {
336                 /* lines for each second */
337                 if (i % 5000 == 0)
338                         svg("  <line class=\"sec5\" x1=\"%.03f\" y1=\"0\" x2=\"%.03f\" y2=\"%.03f\" />\n"
339                             "  <text class=\"sec\" x=\"%.03f\" y=\"%.03f\" >%.01fs</text>\n",
340                             scale_x * i, scale_x * i, scale_y * height, scale_x * i, -5.0, 0.001 * i);
341                 else if (i % 1000 == 0)
342                         svg("  <line class=\"sec1\" x1=\"%.03f\" y1=\"0\" x2=\"%.03f\" y2=\"%.03f\" />\n"
343                             "  <text class=\"sec\" x=\"%.03f\" y=\"%.03f\" >%.01fs</text>\n",
344                             scale_x * i, scale_x * i, scale_y * height, scale_x * i, -5.0, 0.001 * i);
345                 else
346                         svg("  <line class=\"sec01\" x1=\"%.03f\" y1=\"0\" x2=\"%.03f\" y2=\"%.03f\" />\n",
347                             scale_x * i, scale_x * i, scale_y * height);
348         }
349 }
350
351 static int analyze_plot(DBusConnection *bus)
352 {
353         struct unit_times *times;
354         struct boot_times *boot;
355         struct utsname name;
356         int n, m = 1, y=0;
357         double width;
358         char *osname;
359         char *pretty_times;
360
361         boot = acquire_boot_times(bus);
362         if (!boot)
363                 return -EIO;
364         pretty_times = pretty_boot_time(bus);
365         if (!pretty_times)
366                 return -EIO;
367
368         osname = get_os_name();
369
370         n = uname(&name);
371         if (n < 0) {
372                 log_error("Cannot get system name: %m");
373                 return -errno;
374         }
375
376         n = acquire_time_data(bus, &times);
377         if (n<=0)
378                 return n;
379
380         qsort(times, n, sizeof(struct unit_times), compare_unit_start);
381
382         width = scale_x * (boot->firmware_time + boot->finish_time);
383         if (width < 800.0)
384                 width = 800.0;
385
386         if (boot->firmware_time > boot->loader_time)
387                 m++;
388         if (boot->loader_time) {
389                 m++;
390                 if (width < 1000.0)
391                         width = 1000.0;
392         }
393         if (boot->initrd_time)
394                 m++;
395         if (boot->kernel_time)
396                 m++;
397
398         for (struct unit_times *u = times; u < times + n; u++) {
399                 double len;
400                 if (u->ixt < boot->userspace_time ||
401                     u->ixt > boot->finish_time) {
402                         free(u->name);
403                         u->name = NULL;
404                         continue;
405                 }
406                 len = ((boot->firmware_time + u->ixt) * scale_x)
407                         + (10.0 * strlen(u->name));
408                 if (len > width)
409                         width = len;
410
411                 if (u->iet > u->ixt && u->iet <= boot->finish_time
412                                 && u->aet == 0 && u->axt == 0)
413                         u->aet = u->axt = u->iet;
414                 if (u->aet < u->ixt || u->aet > boot->finish_time)
415                         u->aet = boot->finish_time;
416                 if (u->axt < u->aet || u->aet > boot->finish_time)
417                         u->axt = boot->finish_time;
418                 if (u->iet < u->axt || u->iet > boot->finish_time)
419                         u->iet = boot->finish_time;
420                 m++;
421         }
422
423         svg("<?xml version=\"1.0\" standalone=\"no\"?>\n"
424             "<!DOCTYPE svg PUBLIC \"-//W3C//DTD SVG 1.1//EN\" "
425             "\"http://www.w3.org/Graphics/SVG/1.1/DTD/svg11.dtd\">\n");
426
427         svg("<svg width=\"%.0fpx\" height=\"%.0fpx\" version=\"1.1\" "
428             "xmlns=\"http://www.w3.org/2000/svg\">\n\n",
429                         80.0 + width, 150.0 + (m * scale_y));
430
431         /* write some basic info as a comment, including some help */
432         svg("<!-- This file is a systemd-analyze SVG file. It is best rendered in a   -->\n"
433             "<!-- browser such as Chrome, Chromium or Firefox. Other applications     -->\n"
434             "<!-- that render these files properly but much slower are ImageMagick,   -->\n"
435             "<!-- gimp, inkscape, etc. To display the files on your system, just      -->\n"
436             "<!-- point your browser to this file.                                    -->\n\n"
437             "<!-- This plot was generated by systemd-analyze version %-16.16s -->\n\n", VERSION);
438
439         /* style sheet */
440         svg("<defs>\n  <style type=\"text/css\">\n    <![CDATA[\n"
441             "      rect       { stroke-width: 1; stroke-opacity: 0; }\n"
442             "      rect.activating   { fill: rgb(255,0,0); fill-opacity: 0.7; }\n"
443             "      rect.active       { fill: rgb(200,150,150); fill-opacity: 0.7; }\n"
444             "      rect.deactivating { fill: rgb(150,100,100); fill-opacity: 0.7; }\n"
445             "      rect.kernel       { fill: rgb(150,150,150); fill-opacity: 0.7; }\n"
446             "      rect.initrd       { fill: rgb(150,150,150); fill-opacity: 0.7; }\n"
447             "      rect.firmware     { fill: rgb(150,150,150); fill-opacity: 0.7; }\n"
448             "      rect.loader       { fill: rgb(150,150,150); fill-opacity: 0.7; }\n"
449             "      rect.userspace    { fill: rgb(150,150,150); fill-opacity: 0.7; }\n"
450             "      rect.box   { fill: rgb(240,240,240); stroke: rgb(192,192,192); }\n"
451             "      line       { stroke: rgb(64,64,64); stroke-width: 1; }\n"
452             "//    line.sec1  { }\n"
453             "      line.sec5  { stroke-width: 2; }\n"
454             "      line.sec01 { stroke: rgb(224,224,224); stroke-width: 1; }\n"
455             "      text       { font-family: Verdana, Helvetica; font-size: 10; }\n"
456             "      text.sec   { font-size: 8; }\n"
457             "    ]]>\n   </style>\n</defs>\n\n");
458
459         svg("<text x=\"20\" y=\"50\">%s</text>", pretty_times);
460         svg("<text x=\"20\" y=\"30\">%s %s (%s %s) %s</text>",
461             isempty(osname)? "Linux" : osname,
462             name.nodename, name.release, name.version, name.machine);
463         svg("<text x=\"20\" y=\"%.0f\">Legend: Red = Activating; Pink = Active; Dark Pink = Deactivating</text>",
464                         120.0 + (m *scale_y));
465
466         svg("<g transform=\"translate(%.3f,100)\">\n", 20.0 + (scale_x * boot->firmware_time));
467         svg_graph_box(m, -boot->firmware_time, boot->finish_time);
468
469         if (boot->firmware_time) {
470                 svg_bar("firmware", -(int64_t) boot->firmware_time, -(int64_t) boot->loader_time, y);
471                 svg_text(-(int64_t) boot->firmware_time, y, "firmware");
472                 y++;
473         }
474         if (boot->loader_time) {
475                 svg_bar("loader", -(int64_t) boot->loader_time, 0, y);
476                 svg_text(-(int64_t) boot->loader_time, y, "loader");
477                 y++;
478         }
479         if (boot->kernel_time) {
480                 svg_bar("kernel", 0, boot->kernel_done_time, y);
481                 svg_text(0, y, "kernel");
482                 y++;
483         }
484         if (boot->initrd_time) {
485                 svg_bar("initrd", boot->initrd_time, boot->userspace_time, y);
486                 svg_text(boot->initrd_time, y, "initrd");
487                 y++;
488         }
489         svg_bar("userspace", boot->userspace_time, boot->finish_time, y);
490         svg_text(boot->userspace_time, y, "userspace");
491         y++;
492
493         for (struct unit_times *u = times; u < times + n; u++) {
494                 if (!u->name)
495                         continue;
496                 svg_bar("activating",   u->ixt, u->aet, y);
497                 svg_bar("active",       u->aet, u->axt, y);
498                 svg_bar("deactivating", u->axt, u->iet, y);
499                 svg_text(u->ixt, y, u->time? "%s (%llums)" : "%s", u->name, (unsigned long long)u->time);
500                 y++;
501         }
502         svg("</g>\n\n");
503
504         svg("</svg>");
505         return 0;
506 }
507
508 static int analyze_blame(DBusConnection *bus)
509 {
510         struct unit_times *times;
511         int n = acquire_time_data(bus, &times);
512         if (n<=0)
513                 return n;
514
515         qsort(times, n, sizeof(struct unit_times), compare_unit_time);
516
517         for (int i = 0; i < n; i++) {
518                 if (times[i].time)
519                         printf("%6llums %s\n", (unsigned long long)times[i].time, times[i].name);
520         }
521         return 0;
522 }
523
524 static int analyze_time(DBusConnection *bus)
525 {
526         char *buf;
527         buf = pretty_boot_time(bus);
528         if (!buf)
529                 return -EIO;
530         if (puts(buf) == EOF)
531                 return -errno;
532         return 0;
533 }
534
535 static void analyze_help(void)
536 {
537         printf("%s [OPTIONS...] {COMMAND} ...\n\n"
538                "Process systemd profiling information\n\n"
539                "  -h --help           Show this help\n"
540                "     --version        Show package version\n"
541                "     --system         Connect to system manager\n"
542                "     --user           Connect to user service manager\n\n"
543                "Commands:\n"
544                "  time      print time spent in the kernel before reaching userspace\n"
545                "  blame     print list of running units ordered by time to init\n"
546                "  plot      output SVG graphic showing service initialization\n\n",
547                program_invocation_short_name);
548 }
549
550 static int parse_argv(int argc, char *argv[])
551 {
552         enum {
553                 ARG_VERSION = 0x100,
554                 ARG_USER,
555                 ARG_SYSTEM
556         };
557
558         static const struct option options[] = {
559                 { "help",      no_argument,       NULL, 'h'           },
560                 { "version",   no_argument,       NULL, ARG_VERSION   },
561                 { "user",      no_argument,       NULL, ARG_USER      },
562                 { "system",    no_argument,       NULL, ARG_SYSTEM    },
563                 { NULL,        0,                 NULL, 0             }
564         };
565
566         assert(argc >= 0);
567         assert(argv);
568
569         while (true) {
570                 switch (getopt_long(argc, argv, "h", options, NULL)) {
571                         case 'h':
572                                 analyze_help();
573                                 return 0;
574                         case ARG_VERSION:
575                                 puts(PACKAGE_STRING "\n" SYSTEMD_FEATURES);
576                                 return 0;
577                         case ARG_USER:
578                                 arg_scope = UNIT_FILE_USER;
579                                 break;
580                         case ARG_SYSTEM:
581                                 arg_scope = UNIT_FILE_SYSTEM;
582                                 break;
583                         case -1:
584                                 return 1;
585                         case '?':
586                                 return -EINVAL;
587                         default:
588                                 assert_not_reached("Unhandled option");
589                 }
590         }
591 }
592
593 int main(int argc, char *argv[]) {
594         int r;
595         DBusConnection *bus = NULL;
596
597         setlocale(LC_ALL, "");
598         log_parse_environment();
599         log_open();
600
601         r = parse_argv(argc, argv);
602         if (r == 0)
603                 return 0;
604         if (r < 0)
605                 return 1;
606
607         bus = dbus_bus_get(arg_scope == UNIT_FILE_SYSTEM ? DBUS_BUS_SYSTEM : DBUS_BUS_SESSION, NULL);
608         if (!bus)
609                 return 1;
610
611         if (!argv[optind] || streq(argv[optind], "time"))
612                 r = analyze_time(bus);
613         else if (streq(argv[optind], "blame"))
614                 r = analyze_blame(bus);
615         else if (streq(argv[optind], "plot"))
616                 r = analyze_plot(bus);
617         else
618                 log_error("Unknown operation '%s'.", argv[optind]);
619
620         dbus_connection_unref(bus);
621         if (r)
622                 return 1;
623         return 0;
624 }