From 64695e53a0f425b831ba90d467f0e7a668c1b33c Mon Sep 17 00:00:00 2001 From: Lennart Poettering Date: Fri, 13 Apr 2012 13:34:09 +0200 Subject: build-sys: drop systemd- prefix from analyze dir --- src/analyze/systemd-analyze | 276 ++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 276 insertions(+) create mode 100755 src/analyze/systemd-analyze (limited to 'src/analyze/systemd-analyze') diff --git a/src/analyze/systemd-analyze b/src/analyze/systemd-analyze new file mode 100755 index 0000000000..a49fbb7eb0 --- /dev/null +++ b/src/analyze/systemd-analyze @@ -0,0 +1,276 @@ +#!/usr/bin/python + +import dbus, sys + +def acquire_time_data(): + + manager = dbus.Interface(bus.get_object('org.freedesktop.systemd1', '/org/freedesktop/systemd1'), 'org.freedesktop.systemd1.Manager') + units = manager.ListUnits() + + l = [] + + for i in units: + if i[5] != "": + continue + + properties = dbus.Interface(bus.get_object('org.freedesktop.systemd1', i[6]), 'org.freedesktop.DBus.Properties') + + ixt = int(properties.Get('org.freedesktop.systemd1.Unit', 'InactiveExitTimestampMonotonic')) + aet = int(properties.Get('org.freedesktop.systemd1.Unit', 'ActiveEnterTimestampMonotonic')) + axt = int(properties.Get('org.freedesktop.systemd1.Unit', 'ActiveExitTimestampMonotonic')) + iet = int(properties.Get('org.freedesktop.systemd1.Unit', 'InactiveEnterTimestampMonotonic')) + + l.append((str(i[0]), ixt, aet, axt, iet)) + + return l + +def acquire_start_time(): + properties = dbus.Interface(bus.get_object('org.freedesktop.systemd1', '/org/freedesktop/systemd1'), 'org.freedesktop.DBus.Properties') + + initrd_time = int(properties.Get('org.freedesktop.systemd1.Manager', 'InitRDTimestampMonotonic')) + startup_time = int(properties.Get('org.freedesktop.systemd1.Manager', 'StartupTimestampMonotonic')) + finish_time = int(properties.Get('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 initrd_time <= startup_time + assert startup_time <= finish_time + + return initrd_time, startup_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 help(): + sys.stdout.write("""systemd-analyze time +systemd-analyze blame +systemd-analyze plot + +Process systemd profiling information + + -h --help Show this help +""") + + +bus = dbus.SystemBus() + +if len(sys.argv) <= 1 or sys.argv[1] == 'time': + + initrd_time, start_time, finish_time = acquire_start_time() + + if initrd_time > 0: + print "Startup finished in %lums (kernel) + %lums (initramfs) + %lums (userspace) = %lums" % ( \ + initrd_time/1000, \ + (start_time - initrd_time)/1000, \ + (finish_time - start_time)/1000, \ + finish_time/1000) + else: + print "Startup finished in %lums (kernel) + %lums (userspace) = %lums" % ( \ + start_time/1000, \ + (finish_time - start_time)/1000, \ + finish_time/1000) + + +elif sys.argv[1] == '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)) + +elif sys.argv[1] == 'plot': + import cairo, os + + initrd_time, start_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 >= start_time and ixt <= finish_time) or \ + (aet >= start_time and aet <= finish_time) or \ + (axt >= start_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, 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, 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, start_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, start_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, start_time/10000, y, finish_time/10000-start_time/10000, bar_height, 0.7, 0.7, 0.7) + draw_text(context, start_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 >= start_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 >= start_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 >= start_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, \ + (start_time - initrd_time)/1000, \ + (finish_time - start_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" % ( \ + start_time/1000, \ + (finish_time - start_time)/1000, \ + finish_time/1000), hcenter = 0, vcenter = -1) + + surface.finish() +elif sys.argv[1] in ("help", "--help", "-h"): + help() +else: + sys.stderr.write("Unknown verb '%s'.\n" % sys.argv[1]) + sys.exit(1) -- cgit v1.2.3-54-g00ecf From 6fc08fc789cfccacc7741ba8feab849bc4f3c414 Mon Sep 17 00:00:00 2001 From: Patrick McCarty Date: Thu, 3 May 2012 13:42:45 -0700 Subject: systemd-analyze: add a --user option to support user instances --- src/analyze/systemd-analyze | 22 ++++++++++++++-------- 1 file changed, 14 insertions(+), 8 deletions(-) (limited to 'src/analyze/systemd-analyze') diff --git a/src/analyze/systemd-analyze b/src/analyze/systemd-analyze index a49fbb7eb0..ad7bd9ac6c 100755 --- a/src/analyze/systemd-analyze +++ b/src/analyze/systemd-analyze @@ -69,9 +69,9 @@ def draw_text(context, x, y, text, size = 12, r = 0, g = 0, b = 0, vcenter = 0.5 context.restore() def help(): - sys.stdout.write("""systemd-analyze time -systemd-analyze blame -systemd-analyze plot + sys.stdout.write("""systemd-analyze [--user] time +systemd-analyze [--user] blame +systemd-analyze [--user] plot Process systemd profiling information @@ -80,8 +80,14 @@ Process systemd profiling information bus = dbus.SystemBus() +command_index = 1 -if len(sys.argv) <= 1 or sys.argv[1] == 'time': +if len(sys.argv) > 1 and sys.argv[1] == '--user': + bus = dbus.SessionBus() + command_index = 2 + + +if len(sys.argv) <= command_index or sys.argv[command_index] == 'time': initrd_time, start_time, finish_time = acquire_start_time() @@ -98,7 +104,7 @@ if len(sys.argv) <= 1 or sys.argv[1] == 'time': finish_time/1000) -elif sys.argv[1] == 'blame': +elif sys.argv[command_index] == 'blame': data = acquire_time_data() s = sorted(data, key = lambda i: i[2] - i[1], reverse = True) @@ -113,7 +119,7 @@ elif sys.argv[1] == 'blame': sys.stdout.write("%6lums %s\n" % ((aet - ixt) / 1000, name)) -elif sys.argv[1] == 'plot': +elif sys.argv[command_index] == 'plot': import cairo, os initrd_time, start_time, finish_time = acquire_start_time() @@ -269,8 +275,8 @@ elif sys.argv[1] == 'plot': finish_time/1000), hcenter = 0, vcenter = -1) surface.finish() -elif sys.argv[1] in ("help", "--help", "-h"): +elif sys.argv[command_index] in ("help", "--help", "-h"): help() else: - sys.stderr.write("Unknown verb '%s'.\n" % sys.argv[1]) + sys.stderr.write("Unknown verb '%s'.\n" % sys.argv[command_index]) sys.exit(1) -- cgit v1.2.3-54-g00ecf From 927735238d1cfe9bd9d9db71025e801c391cb156 Mon Sep 17 00:00:00 2001 From: Shawn Landden Date: Thu, 3 May 2012 16:41:40 -0700 Subject: systemd-analyze: switch to python getopt for argument parsing this uses gnu style getopt, so you can put the opts at the end: (e.g.) systemd-analyze blame --user v4 --- src/analyze/systemd-analyze | 65 ++++++++++++++++++++++++++++++++------------- 1 file changed, 46 insertions(+), 19 deletions(-) (limited to 'src/analyze/systemd-analyze') diff --git a/src/analyze/systemd-analyze b/src/analyze/systemd-analyze index ad7bd9ac6c..5d451c35e5 100755 --- a/src/analyze/systemd-analyze +++ b/src/analyze/systemd-analyze @@ -1,6 +1,10 @@ #!/usr/bin/python -import dbus, sys +import getopt, dbus, sys, os +try: + import cairo +except ImportError: + cairo = None def acquire_time_data(): @@ -68,7 +72,7 @@ def draw_text(context, x, y, text, size = 12, r = 0, g = 0, b = 0, vcenter = 0.5 context.restore() -def help(): +def usage(): sys.stdout.write("""systemd-analyze [--user] time systemd-analyze [--user] blame systemd-analyze [--user] plot @@ -78,16 +82,11 @@ Process systemd profiling information -h --help Show this help """) +def help(): + usage() + sys.exit() -bus = dbus.SystemBus() -command_index = 1 - -if len(sys.argv) > 1 and sys.argv[1] == '--user': - bus = dbus.SessionBus() - command_index = 2 - - -if len(sys.argv) <= command_index or sys.argv[command_index] == 'time': +def time(): initrd_time, start_time, finish_time = acquire_start_time() @@ -104,7 +103,7 @@ if len(sys.argv) <= command_index or sys.argv[command_index] == 'time': finish_time/1000) -elif sys.argv[command_index] == 'blame': +def blame(): data = acquire_time_data() s = sorted(data, key = lambda i: i[2] - i[1], reverse = True) @@ -119,9 +118,10 @@ elif sys.argv[command_index] == 'blame': sys.stdout.write("%6lums %s\n" % ((aet - ixt) / 1000, name)) -elif sys.argv[command_index] == 'plot': - import cairo, os - +def plot(): + if cairo is None: + sys.stderr.write("Failed to initilize python-cairo required for 'plot' verb.\n") + sys.exit(1) initrd_time, start_time, finish_time = acquire_start_time() data = acquire_time_data() s = sorted(data, key = lambda i: i[1]) @@ -275,8 +275,35 @@ elif sys.argv[command_index] == 'plot': finish_time/1000), hcenter = 0, vcenter = -1) surface.finish() -elif sys.argv[command_index] in ("help", "--help", "-h"): - help() -else: - sys.stderr.write("Unknown verb '%s'.\n" % sys.argv[command_index]) + +def unknown_verb(): + sys.stderr.write("Unknown verb '%s'.\n" % args[0]) + usage() sys.exit(1) + +bus = dbus.SystemBus() + +try: + opts, args = getopt.gnu_getopt(sys.argv[1:], "h", ["help", "user"]) +except getopt.GetoptError, err: + print str(err) + usage() + sys.exit(2) +for o, a in opts: + if o in ("-h", "--help"): + help() + elif o == '--user': + bus = dbus.SessionBus() + else: + assert False, "unhandled option" + +verb = {'time' : time, + 'blame': blame, + 'plot' : plot, + 'help' : help, + } + +if len(args) == 0: + time() +else: + verb.get(args[0], unknown_verb)() -- cgit v1.2.3-54-g00ecf From e23637b64920309466481203285c8bf0d902eee3 Mon Sep 17 00:00:00 2001 From: Shawn Landden Date: Thu, 14 Jun 2012 15:08:19 -0700 Subject: analyze: Python 3 compatibility Plot verb doesn't currently work b/c Cairo bug sending to stdout in python 3. --- src/analyze/systemd-analyze | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) (limited to 'src/analyze/systemd-analyze') diff --git a/src/analyze/systemd-analyze b/src/analyze/systemd-analyze index 5d451c35e5..76eceee9f0 100755 --- a/src/analyze/systemd-analyze +++ b/src/analyze/systemd-analyze @@ -91,16 +91,16 @@ def time(): initrd_time, start_time, finish_time = acquire_start_time() if initrd_time > 0: - print "Startup finished in %lums (kernel) + %lums (initramfs) + %lums (userspace) = %lums" % ( \ + sys.stdout.write("Startup finished in %lums (kernel) + %lums (initramfs) + %lums (userspace) = %lums\n" % ( \ initrd_time/1000, \ (start_time - initrd_time)/1000, \ (finish_time - start_time)/1000, \ - finish_time/1000) + finish_time/1000)) else: - print "Startup finished in %lums (kernel) + %lums (userspace) = %lums" % ( \ + sys.stdout.write("Startup finished in %lums (kernel) + %lums (userspace) = %lums\n" % ( \ start_time/1000, \ (finish_time - start_time)/1000, \ - finish_time/1000) + finish_time/1000)) def blame(): @@ -161,7 +161,7 @@ def plot(): context.set_line_width(1) context.set_source_rgb(0.7, 0.7, 0.7) - for x in range(0, finish_time/10000 + 100, 100): + for x in range(0, int(finish_time/10000) + 100, 100): context.move_to(x, 0) context.line_to(x, height-border*2) @@ -185,7 +185,7 @@ def plot(): banner = "{} {} ({} {}) {}".format(osrel, *(os.uname()[1:5])) draw_text(context, 0, -15, banner, hcenter = 0, vcenter = 1) - for x in range(0, finish_time/10000 + 100, 100): + 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 @@ -285,8 +285,8 @@ bus = dbus.SystemBus() try: opts, args = getopt.gnu_getopt(sys.argv[1:], "h", ["help", "user"]) -except getopt.GetoptError, err: - print str(err) +except getopt.GetoptError as err: + sys.stdout.write(str(err) + "\n") usage() sys.exit(2) for o, a in opts: -- cgit v1.2.3-54-g00ecf From 915b375388231ed97cad2929ab948756bfc77c42 Mon Sep 17 00:00:00 2001 From: Lennart Poettering Date: Thu, 13 Sep 2012 18:54:32 +0200 Subject: manager: extend performance measurement interface to include firmware/loader times This only adds the fields to the D-Bus interfaces but doesn't fill them in with anything useful yet. Gummiboot exposes the necessary bits of information to use however and as soon as I get my fingers on a proper UEFI laptop I'll hook up the remaining bits. Since we want to stabilize the D-Bus interface soon and include it in the stability promise we should get the last fixes in, hence this change now. --- src/analyze/systemd-analyze | 8 ++++---- src/core/dbus-manager.c | 22 ++++++++++++++++---- src/core/dbus.c | 4 ++++ src/core/dbus.h | 2 +- src/core/manager.c | 49 ++++++++++++++++++++++++++++++--------------- src/core/manager.h | 5 ++++- src/core/timer.c | 2 +- 7 files changed, 65 insertions(+), 27 deletions(-) (limited to 'src/analyze/systemd-analyze') diff --git a/src/analyze/systemd-analyze b/src/analyze/systemd-analyze index 76eceee9f0..636fd7422b 100755 --- a/src/analyze/systemd-analyze +++ b/src/analyze/systemd-analyze @@ -32,17 +32,17 @@ def acquire_start_time(): properties = dbus.Interface(bus.get_object('org.freedesktop.systemd1', '/org/freedesktop/systemd1'), 'org.freedesktop.DBus.Properties') initrd_time = int(properties.Get('org.freedesktop.systemd1.Manager', 'InitRDTimestampMonotonic')) - startup_time = int(properties.Get('org.freedesktop.systemd1.Manager', 'StartupTimestampMonotonic')) + userspace_time = int(properties.Get('org.freedesktop.systemd1.Manager', 'UserspaceTimestampMonotonic')) finish_time = int(properties.Get('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 initrd_time <= startup_time - assert startup_time <= finish_time + assert initrd_time <= userspace_time + assert userspace_time <= finish_time - return initrd_time, startup_time, finish_time + return initrd_time, userspace_time, finish_time def draw_box(context, j, k, l, m, r = 0, g = 0, b = 0): context.save() diff --git a/src/core/dbus-manager.c b/src/core/dbus-manager.c index c341d36a6b..557b3e4763 100644 --- a/src/core/dbus-manager.c +++ b/src/core/dbus-manager.c @@ -214,6 +214,8 @@ " \n" \ " " \ " \n" \ + " \n" \ + " \n" \ " \n" \ " \n" \ " \n" \ @@ -226,10 +228,16 @@ " \n" \ " \n" \ " \n" \ + " \n" \ + " \n" \ + " \n" \ + " \n" \ + " \n" \ + " \n" \ " \n" \ " \n" \ - " \n" \ - " \n" \ + " \n" \ + " \n" \ " \n" \ " \n" \ " \n" \ @@ -520,10 +528,16 @@ static const BusProperty bus_systemd_properties[] = { static const BusProperty bus_manager_properties[] = { { "Tainted", bus_manager_append_tainted, "s", 0 }, + { "FirmwareTimestamp", bus_property_append_uint64, "t", offsetof(Manager, firmware_timestamp.realtime) }, + { "FirmwareTimestampMonotonic", bus_property_append_uint64,"t", offsetof(Manager, firmware_timestamp.monotonic)}, + { "LoaderTimestamp", bus_property_append_uint64, "t", offsetof(Manager, loader_timestamp.realtime) }, + { "LoaderTimestampMonotonic", bus_property_append_uint64, "t", offsetof(Manager, loader_timestamp.monotonic) }, + { "KernelTimestamp", bus_property_append_uint64, "t", offsetof(Manager, kernel_timestamp.realtime) }, + { "KernelTimestampMonotonic", bus_property_append_uint64, "t", offsetof(Manager, kernel_timestamp.monotonic) }, { "InitRDTimestamp", bus_property_append_uint64, "t", offsetof(Manager, initrd_timestamp.realtime) }, { "InitRDTimestampMonotonic", bus_property_append_uint64, "t", offsetof(Manager, initrd_timestamp.monotonic) }, - { "StartupTimestamp", bus_property_append_uint64, "t", offsetof(Manager, startup_timestamp.realtime) }, - { "StartupTimestampMonotonic", bus_property_append_uint64, "t", offsetof(Manager, startup_timestamp.monotonic) }, + { "UserspaceTimestamp", bus_property_append_uint64, "t", offsetof(Manager, userspace_timestamp.realtime)}, + { "UserspaceTimestampMonotonic", bus_property_append_uint64,"t",offsetof(Manager, userspace_timestamp.monotonic)}, { "FinishTimestamp", bus_property_append_uint64, "t", offsetof(Manager, finish_timestamp.realtime) }, { "FinishTimestampMonotonic", bus_property_append_uint64, "t", offsetof(Manager, finish_timestamp.monotonic) }, { "LogLevel", bus_manager_append_log_level, "s", 0, false, bus_manager_set_log_level }, diff --git a/src/core/dbus.c b/src/core/dbus.c index 1fc714823e..75773aaa49 100644 --- a/src/core/dbus.c +++ b/src/core/dbus.c @@ -1436,6 +1436,8 @@ int bus_fdset_add_all(Manager *m, FDSet *fds) { void bus_broadcast_finished( Manager *m, + usec_t firmware_usec, + usec_t loader_usec, usec_t kernel_usec, usec_t initrd_usec, usec_t userspace_usec, @@ -1453,6 +1455,8 @@ void bus_broadcast_finished( assert_cc(sizeof(usec_t) == sizeof(uint64_t)); if (!dbus_message_append_args(message, + DBUS_TYPE_UINT64, &firmware_usec, + DBUS_TYPE_UINT64, &loader_usec, DBUS_TYPE_UINT64, &kernel_usec, DBUS_TYPE_UINT64, &initrd_usec, DBUS_TYPE_UINT64, &userspace_usec, diff --git a/src/core/dbus.h b/src/core/dbus.h index 0502d7c251..c7a058e198 100644 --- a/src/core/dbus.h +++ b/src/core/dbus.h @@ -42,7 +42,7 @@ bool bus_connection_has_subscriber(Manager *m, DBusConnection *c); int bus_fdset_add_all(Manager *m, FDSet *fds); -void bus_broadcast_finished(Manager *m, usec_t kernel_usec, usec_t initrd_usec, usec_t userspace_usec, usec_t total_usec); +void bus_broadcast_finished(Manager *m, usec_t firmware_usec, usec_t loader_usec, usec_t kernel_usec, usec_t initrd_usec, usec_t userspace_usec, usec_t total_usec); #define BUS_CONNECTION_SUBSCRIBED(m, c) dbus_connection_get_data((c), (m)->subscribed_data_slot) #define BUS_PENDING_CALL_NAME(m, p) dbus_pending_call_get_data((p), (m)->name_data_slot) diff --git a/src/core/manager.c b/src/core/manager.c index 40b0c50851..23d8ca3d34 100644 --- a/src/core/manager.c +++ b/src/core/manager.c @@ -244,10 +244,11 @@ int manager_new(ManagerRunningAs running_as, Manager **_m) { assert(running_as >= 0); assert(running_as < _MANAGER_RUNNING_AS_MAX); - if (!(m = new0(Manager, 1))) + m = new0(Manager, 1); + if (!m) return -ENOMEM; - dual_timestamp_get(&m->startup_timestamp); + dual_timestamp_get(&m->userspace_timestamp); m->running_as = running_as; m->name_data_slot = m->conn_data_slot = m->subscribed_data_slot = -1; @@ -1741,10 +1742,13 @@ int manager_serialize(Manager *m, FILE *f, FDSet *fds, bool serialize_jobs) { fprintf(f, "n-installed-jobs=%u\n", m->n_installed_jobs); fprintf(f, "n-failed-jobs=%u\n", m->n_failed_jobs); + dual_timestamp_serialize(f, "firmware-timestamp", &m->firmware_timestamp); + dual_timestamp_serialize(f, "kernel-timestamp", &m->kernel_timestamp); + dual_timestamp_serialize(f, "loader-timestamp", &m->loader_timestamp); dual_timestamp_serialize(f, "initrd-timestamp", &m->initrd_timestamp); if (!in_initrd()) { - dual_timestamp_serialize(f, "startup-timestamp", &m->startup_timestamp); + dual_timestamp_serialize(f, "userspace-timestamp", &m->userspace_timestamp); dual_timestamp_serialize(f, "finish-timestamp", &m->finish_timestamp); } @@ -1836,10 +1840,16 @@ int manager_deserialize(Manager *m, FILE *f, FDSet *fds) { log_debug("Failed to parse taint /usr flag %s", l+10); else m->taint_usr = m->taint_usr || b; - } else if (startswith(l, "initrd-timestamp=")) + } else if (startswith(l, "firmware-timestamp=")) + dual_timestamp_deserialize(l+19, &m->firmware_timestamp); + else if (startswith(l, "loader-timestamp=")) + dual_timestamp_deserialize(l+17, &m->loader_timestamp); + else if (startswith(l, "kernel-timestamp=")) + dual_timestamp_deserialize(l+17, &m->kernel_timestamp); + else if (startswith(l, "initrd-timestamp=")) dual_timestamp_deserialize(l+17, &m->initrd_timestamp); - else if (startswith(l, "startup-timestamp=")) - dual_timestamp_deserialize(l+18, &m->startup_timestamp); + else if (startswith(l, "userspace-timestamp=")) + dual_timestamp_deserialize(l+20, &m->userspace_timestamp); else if (startswith(l, "finish-timestamp=")) dual_timestamp_deserialize(l+17, &m->finish_timestamp); else @@ -2003,8 +2013,8 @@ bool manager_unit_pending_inactive(Manager *m, const char *name) { } void manager_check_finished(Manager *m) { - char userspace[FORMAT_TIMESPAN_MAX], initrd[FORMAT_TIMESPAN_MAX], kernel[FORMAT_TIMESPAN_MAX], sum[FORMAT_TIMESPAN_MAX]; - usec_t kernel_usec, initrd_usec, userspace_usec, total_usec; + char firmware[FORMAT_TIMESPAN_MAX], loader[FORMAT_TIMESPAN_MAX], userspace[FORMAT_TIMESPAN_MAX], initrd[FORMAT_TIMESPAN_MAX], kernel[FORMAT_TIMESPAN_MAX], sum[FORMAT_TIMESPAN_MAX]; + usec_t firmware_usec, loader_usec, kernel_usec, initrd_usec, userspace_usec, total_usec; assert(m); @@ -2024,13 +2034,20 @@ void manager_check_finished(Manager *m) { if (m->running_as == MANAGER_SYSTEM && detect_container(NULL) <= 0) { - userspace_usec = m->finish_timestamp.monotonic - m->startup_timestamp.monotonic; - total_usec = m->finish_timestamp.monotonic; + /* Note that m->kernel_usec.monotonic is always at 0, + * and m->firmware_usec.monotonic and + * m->loader_usec.monotonic should be considered + * negative values. */ + + firmware_usec = m->firmware_usec.monotonic - m->loader_timestamp.monotonic; + loader_usec = m->loader_usec.monotonic - m->kernel_usec.monotonic; + userspace_usec = m->finish_timestamp.monotonic - m->userspace_timestamp.monotonic; + total_usec = m->firmware_usec.monotonic + m->finish_timestamp.monotonic; if (dual_timestamp_is_set(&m->initrd_timestamp)) { - kernel_usec = m->initrd_timestamp.monotonic; - initrd_usec = m->startup_timestamp.monotonic - m->initrd_timestamp.monotonic; + kernel_usec = m->initrd_timestamp.monotonic - m->kernel_timestamp.monotonic; + initrd_usec = m->userspace_timestamp.monotonic - m->initrd_timestamp.monotonic; if (!log_on_console()) log_struct(LOG_INFO, @@ -2045,7 +2062,7 @@ void manager_check_finished(Manager *m) { format_timespan(sum, sizeof(sum), total_usec), NULL); } else { - kernel_usec = m->startup_timestamp.monotonic; + kernel_usec = m->userspace_timestamp.monotonic - m->kernel_timestamp.monotonic; initrd_usec = 0; if (!log_on_console()) @@ -2060,8 +2077,8 @@ void manager_check_finished(Manager *m) { NULL); } } else { - initrd_usec = kernel_usec = 0; - total_usec = userspace_usec = m->finish_timestamp.monotonic - m->startup_timestamp.monotonic; + firmware_usec = loader_usec = initrd_usec = kernel_usec = 0; + total_usec = userspace_usec = m->finish_timestamp.monotonic - m->userspace_timestamp.monotonic; if (!log_on_console()) log_struct(LOG_INFO, @@ -2072,7 +2089,7 @@ void manager_check_finished(Manager *m) { NULL); } - bus_broadcast_finished(m, kernel_usec, initrd_usec, userspace_usec, total_usec); + bus_broadcast_finished(m, firmware_usec, loader_usec, kernel_usec, initrd_usec, userspace_usec, total_usec); sd_notifyf(false, "READY=1\nSTATUS=Startup finished in %s.", diff --git a/src/core/manager.h b/src/core/manager.h index 603c2dc318..653496ded0 100644 --- a/src/core/manager.h +++ b/src/core/manager.h @@ -146,8 +146,11 @@ struct Manager { usec_t runtime_watchdog; usec_t shutdown_watchdog; + dual_timestamp firmware_timestamp; + dual_timestamp loader_timestamp; + dual_timestamp kernel_timestamp; dual_timestamp initrd_timestamp; - dual_timestamp startup_timestamp; + dual_timestamp userspace_timestamp; dual_timestamp finish_timestamp; char *generator_unit_path; diff --git a/src/core/timer.c b/src/core/timer.c index 0b3c5ce077..03c9610eb6 100644 --- a/src/core/timer.c +++ b/src/core/timer.c @@ -222,7 +222,7 @@ static void timer_enter_waiting(Timer *t, bool initial) { break; case TIMER_STARTUP: - base = UNIT(t)->manager->startup_timestamp.monotonic; + base = UNIT(t)->manager->userspace_timestamp.monotonic; break; case TIMER_UNIT_ACTIVE: -- cgit v1.2.3-54-g00ecf From 4940c64240541e91411620b7dc0963e012aa6b91 Mon Sep 17 00:00:00 2001 From: Cosimo Cecchi Date: Fri, 2 Nov 2012 11:29:02 -0400 Subject: analyze: use GDBus instead of dbus-python --- src/analyze/systemd-analyze | 31 +++++++++++++++++-------------- 1 file changed, 17 insertions(+), 14 deletions(-) (limited to 'src/analyze/systemd-analyze') diff --git a/src/analyze/systemd-analyze b/src/analyze/systemd-analyze index 636fd7422b..87a83ddb81 100755 --- a/src/analyze/systemd-analyze +++ b/src/analyze/systemd-analyze @@ -1,14 +1,15 @@ #!/usr/bin/python -import getopt, dbus, sys, os +import getopt, sys, os +from gi.repository import Gio try: import cairo except ImportError: cairo = None def acquire_time_data(): - - manager = dbus.Interface(bus.get_object('org.freedesktop.systemd1', '/org/freedesktop/systemd1'), 'org.freedesktop.systemd1.Manager') + 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 = [] @@ -17,23 +18,25 @@ def acquire_time_data(): if i[5] != "": continue - properties = dbus.Interface(bus.get_object('org.freedesktop.systemd1', i[6]), 'org.freedesktop.DBus.Properties') + properties = Gio.DBusProxy.new_for_bus_sync(bus, Gio.DBusProxyFlags.NONE, + None, 'org.freedesktop.systemd1', i[6], 'org.freedesktop.DBus.Properties', None) - ixt = int(properties.Get('org.freedesktop.systemd1.Unit', 'InactiveExitTimestampMonotonic')) - aet = int(properties.Get('org.freedesktop.systemd1.Unit', 'ActiveEnterTimestampMonotonic')) - axt = int(properties.Get('org.freedesktop.systemd1.Unit', 'ActiveExitTimestampMonotonic')) - iet = int(properties.Get('org.freedesktop.systemd1.Unit', 'InactiveEnterTimestampMonotonic')) + 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 = dbus.Interface(bus.get_object('org.freedesktop.systemd1', '/org/freedesktop/systemd1'), 'org.freedesktop.DBus.Properties') + properties = Gio.DBusProxy.new_for_bus_sync(bus, Gio.DBusProxyFlags.NONE, + None, 'org.freedesktop.systemd1', '/org/freedesktop/systemd1', 'org.freedesktop.DBus.Properties', None) - initrd_time = int(properties.Get('org.freedesktop.systemd1.Manager', 'InitRDTimestampMonotonic')) - userspace_time = int(properties.Get('org.freedesktop.systemd1.Manager', 'UserspaceTimestampMonotonic')) - finish_time = int(properties.Get('org.freedesktop.systemd1.Manager', 'FinishTimestampMonotonic')) + 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") @@ -281,7 +284,7 @@ def unknown_verb(): usage() sys.exit(1) -bus = dbus.SystemBus() +bus = Gio.BusType.SYSTEM try: opts, args = getopt.gnu_getopt(sys.argv[1:], "h", ["help", "user"]) @@ -293,7 +296,7 @@ for o, a in opts: if o in ("-h", "--help"): help() elif o == '--user': - bus = dbus.SessionBus() + bus = Gio.BusType.SESSION else: assert False, "unhandled option" -- cgit v1.2.3-54-g00ecf From 0c0271841ab45595f71528c50bcf1904d4b841d5 Mon Sep 17 00:00:00 2001 From: Zbigniew Jędrzejewski-Szmek Date: Sat, 3 Nov 2012 18:26:28 +0100 Subject: systemd-analyze: use argparse instead of getopt Makes the output way nicer with shorter code. Also brings systemd-analyze behaviour more in line with other systemd-programs. Argparse is in Python since 2.6, and is available as a package for previous versions, if someone is stuck with very old Python. --- src/analyze/systemd-analyze | 60 ++++++++++++++++----------------------------- 1 file changed, 21 insertions(+), 39 deletions(-) (limited to 'src/analyze/systemd-analyze') diff --git a/src/analyze/systemd-analyze b/src/analyze/systemd-analyze index 87a83ddb81..88699d6728 100755 --- a/src/analyze/systemd-analyze +++ b/src/analyze/systemd-analyze @@ -1,6 +1,7 @@ #!/usr/bin/python -import getopt, sys, os +import sys, os +import argparse from gi.repository import Gio try: import cairo @@ -75,20 +76,6 @@ def draw_text(context, x, y, text, size = 12, r = 0, g = 0, b = 0, vcenter = 0.5 context.restore() -def usage(): - sys.stdout.write("""systemd-analyze [--user] time -systemd-analyze [--user] blame -systemd-analyze [--user] plot - -Process systemd profiling information - - -h --help Show this help -""") - -def help(): - usage() - sys.exit() - def time(): initrd_time, start_time, finish_time = acquire_start_time() @@ -279,34 +266,29 @@ def plot(): surface.finish() -def unknown_verb(): - sys.stderr.write("Unknown verb '%s'.\n" % args[0]) - usage() - sys.exit(1) +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 +''') -bus = Gio.BusType.SYSTEM +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') -try: - opts, args = getopt.gnu_getopt(sys.argv[1:], "h", ["help", "user"]) -except getopt.GetoptError as err: - sys.stdout.write(str(err) + "\n") - usage() - sys.exit(2) -for o, a in opts: - if o in ("-h", "--help"): - help() - elif o == '--user': - bus = Gio.BusType.SESSION - else: - assert False, "unhandled option" +args = parser.parse_args() + +if args.user: + bus = Gio.BusType.SESSION +else: + bus = Gio.BusType.SYSTEM verb = {'time' : time, 'blame': blame, 'plot' : plot, - 'help' : help, } - -if len(args) == 0: - time() -else: - verb.get(args[0], unknown_verb)() +verb.get(args.action)() -- cgit v1.2.3-54-g00ecf