src/analyze/systemd-analyze.in

   1 #!/usr/bin/python
   2
   3 import sys, os
   4 import argparse
   5 from gi.repository import Gio
   6 try:
   7         import cairo
   8 except ImportError:
   9         cairo = None
  10
  11 def acquire_time_data():
  12         manager = Gio.DBusProxy.new_for_bus_sync(bus, Gio.DBusProxyFlags.NONE,
  13                 None, 'org.freedesktop.systemd1', '/org/freedesktop/systemd1', 'org.freedesktop.systemd1.Manager', None)
  14         units = manager.ListUnits()
  15
  16         l = []
  17
  18         for i in units:
  19                 if i[5] != "":
  20                         continue
  21
  22                 properties = Gio.DBusProxy.new_for_bus_sync(bus, Gio.DBusProxyFlags.NONE,
  23                         None, 'org.freedesktop.systemd1', i[6], 'org.freedesktop.DBus.Properties', None)
  24
  25                 ixt = properties.Get('(ss)', 'org.freedesktop.systemd1.Unit', 'InactiveExitTimestampMonotonic')
  26                 aet = properties.Get('(ss)', 'org.freedesktop.systemd1.Unit', 'ActiveEnterTimestampMonotonic')
  27                 axt = properties.Get('(ss)', 'org.freedesktop.systemd1.Unit', 'ActiveExitTimestampMonotonic')
  28                 iet = properties.Get('(ss)', 'org.freedesktop.systemd1.Unit', 'InactiveEnterTimestampMonotonic')
  29
  30                 l.append((str(i[0]), ixt, aet, axt, iet))
  31
  32         return l
  33
  34 def acquire_start_time():
  35         properties = Gio.DBusProxy.new_for_bus_sync(bus, Gio.DBusProxyFlags.NONE,
  36                 None, 'org.freedesktop.systemd1', '/org/freedesktop/systemd1', 'org.freedesktop.DBus.Properties', None)
  37
  38         # Note that the firmware/loader times are returned as positive
  39         # values but are actually considered negative from the point
  40         # in time of kernel initialization. Also, the monotonic kernel
  41         # time will always be 0 since that's the epoch of the
  42         # monotonic clock. Since we want to know whether the kernel
  43         # timestamp is set at all we will instead ask for the realtime
  44         # clock for this timestamp.
  45
  46         firmware_time = properties.Get('(ss)', 'org.freedesktop.systemd1.Manager', 'FirmwareTimestampMonotonic')
  47         loader_time = properties.Get('(ss)', 'org.freedesktop.systemd1.Manager', 'LoaderTimestampMonotonic')
  48         kernel_time = properties.Get('(ss)', 'org.freedesktop.systemd1.Manager', 'KernelTimestamp')
  49         initrd_time = properties.Get('(ss)', 'org.freedesktop.systemd1.Manager', 'InitRDTimestampMonotonic')
  50         userspace_time = properties.Get('(ss)', 'org.freedesktop.systemd1.Manager', 'UserspaceTimestampMonotonic')
  51         finish_time = properties.Get('(ss)', 'org.freedesktop.systemd1.Manager', 'FinishTimestampMonotonic')
  52
  53         if finish_time == 0:
  54                 sys.exit("Bootup is not yet finished. Please try again later.")
  55
  56         assert firmware_time >= loader_time
  57         assert initrd_time <= userspace_time
  58         assert userspace_time <= finish_time
  59
  60         return firmware_time, loader_time, kernel_time, initrd_time, userspace_time, finish_time
  61
  62 def draw_box(context, j, k, l, m, r = 0, g = 0, b = 0):
  63         context.save()
  64         context.set_source_rgb(r, g, b)
  65         context.rectangle(j, k, l, m)
  66         context.fill()
  67         context.restore()
  68
  69 def draw_text(context, x, y, text, size = 12, r = 0, g = 0, b = 0, vcenter = 0.5, hcenter = 0.5):
  70         context.save()
  71
  72         context.set_source_rgb(r, g, b)
  73         context.select_font_face("Sans", cairo.FONT_SLANT_NORMAL, cairo.FONT_WEIGHT_NORMAL)
  74         context.set_font_size(size)
  75
  76         if vcenter or hcenter:
  77                 x_bearing, y_bearing, width, height = context.text_extents(text)[:4]
  78
  79                 if hcenter:
  80                         x = x - width*hcenter - x_bearing
  81
  82                 if vcenter:
  83                         y = y - height*vcenter - y_bearing
  84
  85         context.move_to(x, y)
  86         context.show_text(text)
  87
  88         context.restore()
  89
  90 def time():
  91
  92         firmware_time, loader_time, kernel_time, initrd_time, userspace_time, finish_time = acquire_start_time()
  93
  94         sys.stdout.write("Startup finished in ")
  95
  96         if firmware_time > 0:
  97                 sys.stdout.write("%lums (firmware) + " % ((firmware_time - loader_time) / 1000))
  98         if loader_time > 0:
  99                 sys.stdout.write("%lums (loader) + " % (loader_time / 1000))
 100         if initrd_time > 0:
 101                 sys.stdout.write("%lums (kernel) + %lums (initrd) + " % (initrd_time / 1000, (userspace_time - initrd_time) / 1000))
 102         elif kernel_time > 0:
 103                 sys.stdout.write("%lums (kernel) + " % (userspace_time  / 1000))
 104
 105         sys.stdout.write("%lums (userspace) " % ((finish_time - userspace_time) / 1000))
 106
 107         if kernel_time > 0:
 108                 sys.stdout.write("= %lums\n" % ((firmware_time + finish_time) / 1000))
 109         else:
 110                 sys.stdout.write("= %lums\n" % ((finish_time - userspace_time) / 1000))
 111
 112 def blame():
 113
 114         data = acquire_time_data()
 115         s = sorted(data, key = lambda i: i[2] - i[1], reverse = True)
 116
 117         for name, ixt, aet, axt, iet in s:
 118
 119                 if ixt <= 0 or aet <= 0:
 120                         continue
 121
 122                 if aet <= ixt:
 123                         continue
 124
 125                 sys.stdout.write("%6lums %s\n" % ((aet - ixt) / 1000, name))
 126
 127 def plot():
 128         if cairo is None:
 129                 sys.exit("Failed to initilize python-cairo required for 'plot' verb.")
 130         firmware_time, loader_time, kernel_time, initrd_time, userspace_time, finish_time = acquire_start_time()
 131         data = acquire_time_data()
 132         s = sorted(data, key = lambda i: i[1])
 133
 134         # Account for kernel and initramfs bars if they exist
 135         if initrd_time > 0:
 136                 count = 3
 137         else:
 138                 count = 2
 139
 140         for name, ixt, aet, axt, iet in s:
 141
 142                 if (ixt >= userspace_time and ixt <= finish_time) or \
 143                                 (aet >= userspace_time and aet <= finish_time) or \
 144                                 (axt >= userspace_time and axt <= finish_time):
 145                         count += 1
 146
 147         border = 100
 148         bar_height = 20
 149         bar_space = bar_height * 0.1
 150
 151         # 1000px = 10s, 1px = 10ms
 152         width = finish_time/10000 + border*2
 153         height = count * (bar_height + bar_space) + border * 2
 154
 155         if width < 1000:
 156                 width = 1000
 157
 158         surface = cairo.SVGSurface(sys.stdout, width, height)
 159         context = cairo.Context(surface)
 160
 161         draw_box(context, 0, 0, width, height, 1, 1, 1)
 162
 163         context.translate(border + 0.5, border + 0.5)
 164
 165         context.save()
 166         context.set_line_width(1)
 167         context.set_source_rgb(0.7, 0.7, 0.7)
 168
 169         for x in range(0, int(finish_time/10000) + 100, 100):
 170                 context.move_to(x, 0)
 171                 context.line_to(x, height-border*2)
 172
 173         context.move_to(0, 0)
 174         context.line_to(width-border*2, 0)
 175
 176         context.move_to(0, height-border*2)
 177         context.line_to(width-border*2, height-border*2)
 178
 179         context.stroke()
 180         context.restore()
 181
 182         osrel = "Linux"
 183         if os.path.exists("/etc/os-release"):
 184                 for line in open("/etc/os-release"):
 185                         if line.startswith('PRETTY_NAME='):
 186                                 osrel = line[12:]
 187                                 osrel = osrel.strip('\"\n')
 188                                 break
 189
 190         banner = "{} {} ({} {}) {}".format(osrel, *(os.uname()[1:5]))
 191         draw_text(context, 0, -15, banner, hcenter = 0, vcenter = 1)
 192
 193         for x in range(0, int(finish_time/10000) + 100, 100):
 194                 draw_text(context, x, -5, "%lus" % (x/100), vcenter = 0, hcenter = 0)
 195
 196         y = 0
 197
 198         # draw boxes for kernel and initramfs boot time
 199         if initrd_time > 0:
 200                 draw_box(context, 0, y, initrd_time/10000, bar_height, 0.7, 0.7, 0.7)
 201                 draw_text(context, 10, y + bar_height/2, "kernel", hcenter = 0)
 202                 y += bar_height + bar_space
 203
 204                 draw_box(context, initrd_time/10000, y, userspace_time/10000-initrd_time/10000, bar_height, 0.7, 0.7, 0.7)
 205                 draw_text(context, initrd_time/10000 + 10, y + bar_height/2, "initramfs", hcenter = 0)
 206                 y += bar_height + bar_space
 207
 208         else:
 209                 draw_box(context, 0, y, userspace_time/10000, bar_height, 0.6, 0.6, 0.6)
 210                 draw_text(context, 10, y + bar_height/2, "kernel", hcenter = 0)
 211                 y += bar_height + bar_space
 212
 213         draw_box(context, userspace_time/10000, y, finish_time/10000-userspace_time/10000, bar_height, 0.7, 0.7, 0.7)
 214         draw_text(context, userspace_time/10000 + 10, y + bar_height/2, "userspace", hcenter = 0)
 215         y += bar_height + bar_space
 216
 217         for name, ixt, aet, axt, iet in s:
 218
 219                 drawn = False
 220                 left = -1
 221
 222                 if ixt >= userspace_time and ixt <= finish_time:
 223
 224                         # Activating
 225                         a = ixt
 226                         b = min(filter(lambda x: x >= ixt, (aet, axt, iet, finish_time))) - ixt
 227
 228                         draw_box(context, a/10000, y, b/10000, bar_height, 1, 0, 0)
 229                         drawn = True
 230
 231                         if left < 0:
 232                                 left = a
 233
 234                 if aet >= userspace_time and aet <= finish_time:
 235
 236                         # Active
 237                         a = aet
 238                         b = min(filter(lambda x: x >= aet, (axt, iet, finish_time))) - aet
 239
 240                         draw_box(context, a/10000, y, b/10000, bar_height, .8, .6, .6)
 241                         drawn = True
 242
 243                         if left < 0:
 244                                 left = a
 245
 246                 if axt >= userspace_time and axt <= finish_time:
 247
 248                         # Deactivating
 249                         a = axt
 250                         b = min(filter(lambda x: x >= axt, (iet, finish_time))) - axt
 251
 252                         draw_box(context, a/10000, y, b/10000, bar_height, .6, .4, .4)
 253                         drawn = True
 254
 255                         if left < 0:
 256                                 left = a
 257
 258                 if drawn:
 259                         x = left/10000
 260
 261                         if x < width/2-border:
 262                                 draw_text(context, x + 10, y + bar_height/2, name, hcenter = 0)
 263                         else:
 264                                 draw_text(context, x - 10, y + bar_height/2, name, hcenter = 1)
 265
 266                         y += bar_height + bar_space
 267
 268         draw_text(context, 0, height-border*2, "Legend: Red = Activating; Pink = Active; Dark Pink = Deactivating", hcenter = 0, vcenter = -1)
 269
 270         if initrd_time > 0:
 271                 draw_text(context, 0, height-border*2 + bar_height, "Startup finished in %lums (kernel) + %lums (initramfs) + %lums (userspace) = %lums" % ( \
 272                         initrd_time/1000, \
 273                         (userspace_time - initrd_time)/1000, \
 274                         (finish_time - userspace_time)/1000, \
 275                         finish_time/1000), hcenter = 0, vcenter = -1)
 276         else:
 277                 draw_text(context, 0, height-border*2 + bar_height, "Startup finished in %lums (kernel) + %lums (userspace) = %lums" % ( \
 278                         userspace_time/1000, \
 279                         (finish_time - userspace_time)/1000, \
 280                         finish_time/1000), hcenter = 0, vcenter = -1)
 281
 282         surface.finish()
 283
 284 parser = argparse.ArgumentParser(formatter_class=argparse.RawDescriptionHelpFormatter,
 285                                  description='Process systemd profiling information',
 286                                  epilog='''\
 287 time - print time spent in the kernel before reaching userspace
 288 blame - print list of running units ordered by time to init
 289 plot - output SVG graphic showing service initialization
 290 ''')
 291
 292 parser.add_argument('action', choices=('time', 'blame', 'plot'),
 293                     default='time', nargs='?',
 294                     help='action to perform (default: time)')
 295 parser.add_argument('--user', action='store_true',
 296                     help='use the session bus')
 297
 298 args = parser.parse_args()
 299
 300 if args.user:
 301         bus = Gio.BusType.SESSION
 302 else:
 303         bus = Gio.BusType.SYSTEM
 304
 305 verb = {'time' : time,
 306         'blame': blame,
 307         'plot' : plot,
 308         }
 309 verb.get(args.action)()