path: root/src/analyze/systemd-analyze

#!/usr/bin/python

import sys, os
import argparse
from gi.repository import Gio
try:
        import cairo
except ImportError:
        cairo = None

def acquire_time_data():
        manager = Gio.DBusProxy.new_for_bus_sync(bus, Gio.DBusProxyFlags.NONE,
                None, 'org.freedesktop.systemd1', '/org/freedesktop/systemd1', 'org.freedesktop.systemd1.Manager', None)
        units = manager.ListUnits()

        l = []

        for i in units:
                if i[5] != "":
                        continue

                properties = Gio.DBusProxy.new_for_bus_sync(bus, Gio.DBusProxyFlags.NONE,
                        None, 'org.freedesktop.systemd1', i[6], 'org.freedesktop.DBus.Properties', None)

                ixt = properties.Get('(ss)', 'org.freedesktop.systemd1.Unit', 'InactiveExitTimestampMonotonic')
                aet = properties.Get('(ss)', 'org.freedesktop.systemd1.Unit', 'ActiveEnterTimestampMonotonic')
                axt = properties.Get('(ss)', 'org.freedesktop.systemd1.Unit', 'ActiveExitTimestampMonotonic')
                iet = properties.Get('(ss)', 'org.freedesktop.systemd1.Unit', 'InactiveEnterTimestampMonotonic')

                l.append((str(i[0]), ixt, aet, axt, iet))

        return l

def acquire_start_time():
        properties = Gio.DBusProxy.new_for_bus_sync(bus, Gio.DBusProxyFlags.NONE,
                None, 'org.freedesktop.systemd1', '/org/freedesktop/systemd1', 'org.freedesktop.DBus.Properties', None)

        # Note that the firmware/loader times are returned as positive
        # values but are atcually considered negative from the point
        # in time of kernel initialization. Also, the monotonic kernel
        # time will always be 0 since that's where the epoch of the
        # monotonic clock ist. Since we want to know whether the
        # kernel time stamp is set at all, we will thus ask for the
        # realtime clock for this timestamp, instead.

        firmware_time = properties.Get('(ss)', 'org.freedesktop.systemd1.Manager', 'FirmwareTimestampMonotonic')
        loader_time = properties.Get('(ss)', 'org.freedesktop.systemd1.Manager', 'LoaderTimestampMonotonic')
        kernel_time = properties.Get('(ss)', 'org.freedesktop.systemd1.Manager', 'KernelTimestamp')
        initrd_time = properties.Get('(ss)', 'org.freedesktop.systemd1.Manager', 'InitRDTimestampMonotonic')
        userspace_time = properties.Get('(ss)', 'org.freedesktop.systemd1.Manager', 'UserspaceTimestampMonotonic')
        finish_time = properties.Get('(ss)', 'org.freedesktop.systemd1.Manager', 'FinishTimestampMonotonic')

        if finish_time == 0:
                sys.stderr.write("Bootup is not yet finished. Please try again later.\n")
                sys.exit(1)

        assert firmware_time >= loader_time
        assert initrd_time <= userspace_time
        assert userspace_time <= finish_time

        return firmware_time, loader_time, kernel_time, initrd_time, userspace_time, finish_time

def draw_box(context, j, k, l, m, r = 0, g = 0, b = 0):
        context.save()
        context.set_source_rgb(r, g, b)
        context.rectangle(j, k, l, m)
        context.fill()
        context.restore()

def draw_text(context, x, y, text, size = 12, r = 0, g = 0, b = 0, vcenter = 0.5, hcenter = 0.5):
        context.save()

        context.set_source_rgb(r, g, b)
        context.select_font_face("Sans", cairo.FONT_SLANT_NORMAL, cairo.FONT_WEIGHT_NORMAL)
        context.set_font_size(size)

        if vcenter or hcenter:
                x_bearing, y_bearing, width, height = context.text_extents(text)[:4]

                if hcenter:
                        x = x - width*hcenter - x_bearing

                if vcenter:
                        y = y - height*vcenter - y_bearing

        context.move_to(x, y)
        context.show_text(text)

        context.restore()

def time():

        firmware_time, loader_time, kernel_time, initrd_time, userspace_time, finish_time = acquire_start_time()

        sys.stdout.write("Startup finished in ")

        if firmware_time > 0:
                sys.stdout.write("%lums (firmware) + " % ((firmware_time - loader_time) / 1000))
        if loader_time > 0:
                sys.stdout.write("%lums (loader) + " % (loader_time / 1000))
        if initrd_time > 0:
                sys.stdout.write("%lums (kernel) + %lums (initrd) + " % (initrd_time / 1000, (userspace_time - initrd_time) / 1000))
        elif kernel_time > 0:
                sys.stdout.write("%lums (kernel) + " % (userspace_time  / 1000))

        sys.stdout.write("%lums (userspace) " % ((finish_time - userspace_time) / 1000))

        if kernel_time > 0:
                sys.stdout.write("= %lums\n" % ((firmware_time + finish_time) / 1000))
        else:
                sys.stdout.write("= %lums\n" % ((finish_time - userspace_time) / 1000))

def blame():

        data = acquire_time_data()
        s = sorted(data, key = lambda i: i[2] - i[1], reverse = True)

        for name, ixt, aet, axt, iet in s:

                if ixt <= 0 or aet <= 0:
                        continue

                if aet <= ixt:
                        continue

                sys.stdout.write("%6lums %s\n" % ((aet - ixt) / 1000, name))

def plot():
        if cairo is None:
                sys.stderr.write("Failed to initilize python-cairo required for 'plot' verb.\n")
                sys.exit(1)
        firmware_time, loader_time, kernel_time, initrd_time, userspace_time, finish_time = acquire_start_time()
        data = acquire_time_data()
        s = sorted(data, key = lambda i: i[1])

        # Account for kernel and initramfs bars if they exist
        if initrd_time > 0:
                count = 3
        else:
                count = 2

        for name, ixt, aet, axt, iet in s:

                if (ixt >= userspace_time and ixt <= finish_time) or \
                                (aet >= userspace_time and aet <= finish_time) or \
                                (axt >= userspace_time and axt <= finish_time):
                        count += 1

        border = 100
        bar_height = 20
        bar_space = bar_height * 0.1

        # 1000px = 10s, 1px = 10ms
        width = finish_time/10000 + border*2
        height = count * (bar_height + bar_space) + border * 2

        if width < 1000:
                width = 1000

        surface = cairo.SVGSurface(sys.stdout, width, height)
        context = cairo.Context(surface)

        draw_box(context, 0, 0, width, height, 1, 1, 1)

        context.translate(border + 0.5, border + 0.5)

        context.save()
        context.set_line_width(1)
        context.set_source_rgb(0.7, 0.7, 0.7)

        for x in range(0, int(finish_time/10000) + 100, 100):
                context.move_to(x, 0)
                context.line_to(x, height-border*2)

        context.move_to(0, 0)
        context.line_to(width-border*2, 0)

        context.move_to(0, height-border*2)
        context.line_to(width-border*2, height-border*2)

        context.stroke()
        context.restore()

        osrel = "Linux"
        if os.path.exists("/etc/os-release"):
                for line in open("/etc/os-release"):
                        if line.startswith('PRETTY_NAME='):
                                osrel = line[12:]
                                osrel = osrel.strip('\"\n')
                                break

        banner = "{} {} ({} {}) {}".format(osrel, *(os.uname()[1:5]))
        draw_text(context, 0, -15, banner, hcenter = 0, vcenter = 1)

        for x in range(0, int(finish_time/10000) + 100, 100):
                draw_text(context, x, -5, "%lus" % (x/100), vcenter = 0, hcenter = 0)

        y = 0

        # draw boxes for kernel and initramfs boot time
        if initrd_time > 0:
                draw_box(context, 0, y, initrd_time/10000, bar_height, 0.7, 0.7, 0.7)
                draw_text(context, 10, y + bar_height/2, "kernel", hcenter = 0)
                y += bar_height + bar_space

                draw_box(context, initrd_time/10000, y, userspace_time/10000-initrd_time/10000, bar_height, 0.7, 0.7, 0.7)
                draw_text(context, initrd_time/10000 + 10, y + bar_height/2, "initramfs", hcenter = 0)
                y += bar_height + bar_space

        else:
                draw_box(context, 0, y, userspace_time/10000, bar_height, 0.6, 0.6, 0.6)
                draw_text(context, 10, y + bar_height/2, "kernel", hcenter = 0)
                y += bar_height + bar_space

        draw_box(context, userspace_time/10000, y, finish_time/10000-userspace_time/10000, bar_height, 0.7, 0.7, 0.7)
        draw_text(context, userspace_time/10000 + 10, y + bar_height/2, "userspace", hcenter = 0)
        y += bar_height + bar_space

        for name, ixt, aet, axt, iet in s:

                drawn = False
                left = -1

                if ixt >= userspace_time and ixt <= finish_time:

                        # Activating
                        a = ixt
                        b = min(filter(lambda x: x >= ixt, (aet, axt, iet, finish_time))) - ixt

                        draw_box(context, a/10000, y, b/10000, bar_height, 1, 0, 0)
                        drawn = True

                        if left < 0:
                                left = a

                if aet >= userspace_time and aet <= finish_time:

                        # Active
                        a = aet
                        b = min(filter(lambda x: x >= aet, (axt, iet, finish_time))) - aet

                        draw_box(context, a/10000, y, b/10000, bar_height, .8, .6, .6)
                        drawn = True

                        if left < 0:
                                left = a

                if axt >= userspace_time and axt <= finish_time:

                        # Deactivating
                        a = axt
                        b = min(filter(lambda x: x >= axt, (iet, finish_time))) - axt

                        draw_box(context, a/10000, y, b/10000, bar_height, .6, .4, .4)
                        drawn = True

                        if left < 0:
                                left = a

                if drawn:
                        x = left/10000

                        if x < width/2-border:
                                draw_text(context, x + 10, y + bar_height/2, name, hcenter = 0)
                        else:
                                draw_text(context, x - 10, y + bar_height/2, name, hcenter = 1)

                        y += bar_height + bar_space

        draw_text(context, 0, height-border*2, "Legend: Red = Activating; Pink = Active; Dark Pink = Deactivating", hcenter = 0, vcenter = -1)

        if initrd_time > 0:
                draw_text(context, 0, height-border*2 + bar_height, "Startup finished in %lums (kernel) + %lums (initramfs) + %lums (userspace) = %lums" % ( \
                        initrd_time/1000, \
                        (userspace_time - initrd_time)/1000, \
                        (finish_time - userspace_time)/1000, \
                        finish_time/1000), hcenter = 0, vcenter = -1)
        else:
                draw_text(context, 0, height-border*2 + bar_height, "Startup finished in %lums (kernel) + %lums (userspace) = %lums" % ( \
                        userspace_time/1000, \
                        (finish_time - userspace_time)/1000, \
                        finish_time/1000), hcenter = 0, vcenter = -1)

        surface.finish()

parser = argparse.ArgumentParser(formatter_class=argparse.RawDescriptionHelpFormatter,
                                 description='Process systemd profiling information',
                                 epilog='''\
time - print time spent in the kernel before reaching userspace
blame - print list of running units ordered by time to init
plot - output SVG graphic showing service initialization
''')

parser.add_argument('action', choices=('time', 'blame', 'plot'),
                    default='time', nargs='?',
                    help='action to perform (default: time)')
parser.add_argument('--user', action='store_true',
                    help='use the session bus')

args = parser.parse_args()

if args.user:
        bus = Gio.BusType.SESSION
else:
        bus = Gio.BusType.SYSTEM

verb = {'time' : time,
	'blame': blame,
	'plot' : plot,
	}
verb.get(args.action)()