summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorLennart Poettering <lennart@poettering.net>2011-04-07 21:35:37 +0200
committerLennart Poettering <lennart@poettering.net>2011-04-07 21:35:37 +0200
commitb21a0ef8fc3d78ca3cc9d08e8ec8e41705d9902e (patch)
tree1b1083c4f456d18a702d69b8921345b7b6ba07ef
parentf1d19aa412b34fe025dfd48a5c79d34fdd0f9528 (diff)
dbus: expose monotonic timestamps on the bus
-rw-r--r--TODO2
-rw-r--r--src/dbus-execute.c2
-rw-r--r--src/dbus-execute.h6
-rw-r--r--src/dbus-manager.c6
-rw-r--r--src/dbus-unit.h16
-rw-r--r--src/systemctl.c6
-rwxr-xr-xsrc/systemd-analyze40
7 files changed, 60 insertions, 18 deletions
diff --git a/TODO b/TODO
index 5a3944fe0c..e16fdeef7e 100644
--- a/TODO
+++ b/TODO
@@ -32,8 +32,6 @@ Features:
* show enablement status in systemctl status
-* expose monotonic timestamps on the bus and make systemd-analyze use it
-
* write blog stories about:
- chroot, nspawn and friends
- the blame game: systemd-analyze
diff --git a/src/dbus-execute.c b/src/dbus-execute.c
index 35e6d377ee..3cb09c2dbf 100644
--- a/src/dbus-execute.c
+++ b/src/dbus-execute.c
@@ -346,7 +346,9 @@ int bus_execute_append_command(Manager *m, DBusMessageIter *i, const char *prope
if (!dbus_message_iter_close_container(&sub2, &sub3) ||
!dbus_message_iter_append_basic(&sub2, DBUS_TYPE_BOOLEAN, &c->ignore) ||
!dbus_message_iter_append_basic(&sub2, DBUS_TYPE_UINT64, &c->exec_status.start_timestamp.realtime) ||
+ !dbus_message_iter_append_basic(&sub2, DBUS_TYPE_UINT64, &c->exec_status.start_timestamp.monotonic) ||
!dbus_message_iter_append_basic(&sub2, DBUS_TYPE_UINT64, &c->exec_status.exit_timestamp.realtime) ||
+ !dbus_message_iter_append_basic(&sub2, DBUS_TYPE_UINT64, &c->exec_status.exit_timestamp.monotonic) ||
!dbus_message_iter_append_basic(&sub2, DBUS_TYPE_UINT32, &pid) ||
!dbus_message_iter_append_basic(&sub2, DBUS_TYPE_INT32, &code) ||
!dbus_message_iter_append_basic(&sub2, DBUS_TYPE_INT32, &status))
diff --git a/src/dbus-execute.h b/src/dbus-execute.h
index 8bfaaaf120..548738a756 100644
--- a/src/dbus-execute.h
+++ b/src/dbus-execute.h
@@ -28,7 +28,9 @@
#define BUS_EXEC_STATUS_INTERFACE(prefix) \
" <property name=\"" prefix "StartTimestamp\" type=\"t\" access=\"read\"/>\n" \
+ " <property name=\"" prefix "StartTimestampMonotonic\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"" prefix "ExitTimestamp\" type=\"t\" access=\"read\"/>\n" \
+ " <property name=\"" prefix "ExitTimestampMonotonic\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"" prefix "PID\" type=\"u\" access=\"read\"/>\n" \
" <property name=\"" prefix "Code\" type=\"i\" access=\"read\"/>\n" \
" <property name=\"" prefix "Status\" type=\"i\" access=\"read\"/>\n"
@@ -149,13 +151,15 @@
#define BUS_EXEC_STATUS_PROPERTIES(interface, estatus, prefix) \
{ interface, prefix "StartTimestamp", bus_property_append_usec, "t", &(estatus).start_timestamp.realtime }, \
+ { interface, prefix "StartTimestampMonotonic",bus_property_append_usec, "t", &(estatus).start_timestamp.monotonic }, \
{ interface, prefix "ExitTimestamp", bus_property_append_usec, "t", &(estatus).start_timestamp.realtime }, \
+ { interface, prefix "ExitTimestampMonotonic", bus_property_append_usec, "t", &(estatus).start_timestamp.monotonic }, \
{ interface, prefix "PID", bus_property_append_pid, "u", &(estatus).pid }, \
{ interface, prefix "Code", bus_property_append_int, "i", &(estatus).code }, \
{ interface, prefix "Status", bus_property_append_int, "i", &(estatus).status }
#define BUS_EXEC_COMMAND_PROPERTY(interface, command, name) \
- { interface, name, bus_execute_append_command, "a(sasbttuii)", (command) }
+ { interface, name, bus_execute_append_command, "a(sasbttttuii)", (command) }
int bus_execute_append_output(Manager *m, DBusMessageIter *i, const char *property, void *data);
int bus_execute_append_input(Manager *m, DBusMessageIter *i, const char *property, void *data);
diff --git a/src/dbus-manager.c b/src/dbus-manager.c
index 5b5bda2119..e1bf9fd28c 100644
--- a/src/dbus-manager.c
+++ b/src/dbus-manager.c
@@ -155,8 +155,11 @@
" <property name=\"Tainted\" type=\"s\" access=\"read\"/>\n" \
" <property name=\"RunningAs\" type=\"s\" access=\"read\"/>\n" \
" <property name=\"InitRDTimestamp\" type=\"t\" access=\"read\"/>\n" \
+ " <property name=\"InitRDTimestampMonotonic\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"StartupTimestamp\" type=\"t\" access=\"read\"/>\n" \
+ " <property name=\"StartupTimestampMonotonic\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"FinishTimestamp\" type=\"t\" access=\"read\"/>\n" \
+ " <property name=\"FinishTimestampMonotonic\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"LogLevel\" type=\"s\" access=\"readwrite\"/>\n" \
" <property name=\"LogTarget\" type=\"s\" access=\"readwrite\"/>\n" \
" <property name=\"NNames\" type=\"u\" access=\"read\"/>\n" \
@@ -369,8 +372,11 @@ static DBusHandlerResult bus_manager_message_handler(DBusConnection *connection,
{ "org.freedesktop.systemd1.Manager", "RunningAs", bus_manager_append_running_as, "s", &m->running_as },
{ "org.freedesktop.systemd1.Manager", "Tainted", bus_manager_append_tainted, "s", m },
{ "org.freedesktop.systemd1.Manager", "InitRDTimestamp", bus_property_append_uint64, "t", &m->initrd_timestamp.realtime },
+ { "org.freedesktop.systemd1.Manager", "InitRDTimestampMonotonic", bus_property_append_uint64, "t", &m->initrd_timestamp.monotonic },
{ "org.freedesktop.systemd1.Manager", "StartupTimestamp", bus_property_append_uint64, "t", &m->startup_timestamp.realtime },
+ { "org.freedesktop.systemd1.Manager", "StartupTimestampMonotonic", bus_property_append_uint64, "t", &m->startup_timestamp.monotonic },
{ "org.freedesktop.systemd1.Manager", "FinishTimestamp", bus_property_append_uint64, "t", &m->finish_timestamp.realtime },
+ { "org.freedesktop.systemd1.Manager", "FinishTimestampMonotonic", bus_property_append_uint64, "t",&m->finish_timestamp.monotonic },
{ "org.freedesktop.systemd1.Manager", "LogLevel", bus_manager_append_log_level, "s", NULL, bus_manager_set_log_level},
{ "org.freedesktop.systemd1.Manager", "LogTarget", bus_manager_append_log_target, "s", NULL, bus_manager_set_log_target},
{ "org.freedesktop.systemd1.Manager", "NNames", bus_manager_append_n_names, "u", NULL },
diff --git a/src/dbus-unit.h b/src/dbus-unit.h
index dfbc82c0c5..b9f0895525 100644
--- a/src/dbus-unit.h
+++ b/src/dbus-unit.h
@@ -86,9 +86,13 @@
" <property name=\"SubState\" type=\"s\" access=\"read\"/>\n" \
" <property name=\"FragmentPath\" type=\"s\" access=\"read\"/>\n" \
" <property name=\"InactiveExitTimestamp\" type=\"t\" access=\"read\"/>\n" \
+ " <property name=\"InactiveExitTimestampMonotonic\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"ActiveEnterTimestamp\" type=\"t\" access=\"read\"/>\n" \
+ " <property name=\"ActiveEnterTimestampMonotonic\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"ActiveExitTimestamp\" type=\"t\" access=\"read\"/>\n" \
+ " <property name=\"ActiveExitTimestampMonotonic\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"InactiveEnterTimestamp\" type=\"t\" access=\"read\"/>\n" \
+ " <property name=\"InactiveEnterTimestampMonotonic\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"CanReload\" type=\"b\" access=\"read\"/>\n" \
" <property name=\"CanStart\" type=\"b\" access=\"read\"/>\n" \
" <property name=\"CanStop\" type=\"b\" access=\"read\"/>\n" \
@@ -103,6 +107,7 @@
" <property name=\"NeedDaemonReload\" type=\"b\" access=\"read\"/>\n" \
" <property name=\"JobTimeoutUSec\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"ConditionTimestamp\" type=\"t\" access=\"read\"/>\n" \
+ " <property name=\"ConditionTimestampMonotonic\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"ConditionResult\" type=\"b\" access=\"read\"/>\n" \
" </interface>\n"
@@ -134,10 +139,14 @@
{ "org.freedesktop.systemd1.Unit", "ActiveState", bus_unit_append_active_state, "s", u }, \
{ "org.freedesktop.systemd1.Unit", "SubState", bus_unit_append_sub_state, "s", u }, \
{ "org.freedesktop.systemd1.Unit", "FragmentPath", bus_property_append_string, "s", u->meta.fragment_path }, \
- { "org.freedesktop.systemd1.Unit", "InactiveExitTimestamp",bus_property_append_usec, "t", &u->meta.inactive_exit_timestamp.realtime }, \
- { "org.freedesktop.systemd1.Unit", "ActiveEnterTimestamp", bus_property_append_usec, "t", &u->meta.active_enter_timestamp.realtime }, \
- { "org.freedesktop.systemd1.Unit", "ActiveExitTimestamp", bus_property_append_usec, "t", &u->meta.active_exit_timestamp.realtime }, \
+ { "org.freedesktop.systemd1.Unit", "InactiveExitTimestamp",bus_property_append_usec, "t", &u->meta.inactive_exit_timestamp.realtime }, \
+ { "org.freedesktop.systemd1.Unit", "InactiveExitTimestampMonotonic",bus_property_append_usec, "t", &u->meta.inactive_exit_timestamp.monotonic }, \
+ { "org.freedesktop.systemd1.Unit", "ActiveEnterTimestamp", bus_property_append_usec, "t", &u->meta.active_enter_timestamp.realtime }, \
+ { "org.freedesktop.systemd1.Unit", "ActiveEnterTimestampMonotonic", bus_property_append_usec, "t", &u->meta.active_enter_timestamp.monotonic }, \
+ { "org.freedesktop.systemd1.Unit", "ActiveExitTimestamp", bus_property_append_usec, "t", &u->meta.active_exit_timestamp.realtime }, \
+ { "org.freedesktop.systemd1.Unit", "ActiveExitTimestampMonotonic", bus_property_append_usec, "t", &u->meta.active_exit_timestamp.monotonic }, \
{ "org.freedesktop.systemd1.Unit", "InactiveEnterTimestamp",bus_property_append_usec, "t", &u->meta.inactive_enter_timestamp.realtime }, \
+ { "org.freedesktop.systemd1.Unit", "InactiveEnterTimestampMonotonic",bus_property_append_usec,"t", &u->meta.inactive_enter_timestamp.monotonic }, \
{ "org.freedesktop.systemd1.Unit", "CanStart", bus_unit_append_can_start, "b", u }, \
{ "org.freedesktop.systemd1.Unit", "CanStop", bus_unit_append_can_stop, "b", u }, \
{ "org.freedesktop.systemd1.Unit", "CanReload", bus_unit_append_can_reload, "b", u }, \
@@ -154,6 +163,7 @@
{ "org.freedesktop.systemd1.Unit", "NeedDaemonReload", bus_unit_append_need_daemon_reload, "b", u }, \
{ "org.freedesktop.systemd1.Unit", "JobTimeoutUSec", bus_property_append_usec, "t", &u->meta.job_timeout }, \
{ "org.freedesktop.systemd1.Unit", "ConditionTimestamp", bus_property_append_usec, "t", &u->meta.condition_timestamp.realtime }, \
+ { "org.freedesktop.systemd1.Unit", "ConditionTimestampMonotonic", bus_property_append_usec,"t", &u->meta.condition_timestamp.monotonic }, \
{ "org.freedesktop.systemd1.Unit", "ConditionResult", bus_property_append_bool, "b", &u->meta.condition_result }
int bus_unit_append_names(Manager *m, DBusMessageIter *i, const char *property, void *data);
diff --git a/src/systemctl.c b/src/systemctl.c
index 00db47f125..0a72874145 100644
--- a/src/systemctl.c
+++ b/src/systemctl.c
@@ -1735,7 +1735,7 @@ static void exec_status_info_free(ExecStatusInfo *i) {
}
static int exec_status_info_deserialize(DBusMessageIter *sub, ExecStatusInfo *i) {
- uint64_t start_timestamp, exit_timestamp;
+ uint64_t start_timestamp, exit_timestamp, start_timestamp_monotonic, exit_timestamp_monotonic;
DBusMessageIter sub2, sub3;
const char*path;
unsigned n;
@@ -1789,7 +1789,9 @@ static int exec_status_info_deserialize(DBusMessageIter *sub, ExecStatusInfo *i)
if (!dbus_message_iter_next(&sub2) ||
bus_iter_get_basic_and_next(&sub2, DBUS_TYPE_BOOLEAN, &ignore, true) < 0 ||
bus_iter_get_basic_and_next(&sub2, DBUS_TYPE_UINT64, &start_timestamp, true) < 0 ||
+ bus_iter_get_basic_and_next(&sub2, DBUS_TYPE_UINT64, &start_timestamp_monotonic, true) < 0 ||
bus_iter_get_basic_and_next(&sub2, DBUS_TYPE_UINT64, &exit_timestamp, true) < 0 ||
+ bus_iter_get_basic_and_next(&sub2, DBUS_TYPE_UINT64, &exit_timestamp_monotonic, true) < 0 ||
bus_iter_get_basic_and_next(&sub2, DBUS_TYPE_UINT32, &pid, true) < 0 ||
bus_iter_get_basic_and_next(&sub2, DBUS_TYPE_INT32, &code, true) < 0 ||
bus_iter_get_basic_and_next(&sub2, DBUS_TYPE_INT32, &status, false) < 0)
@@ -2278,7 +2280,7 @@ static int print_property(const char *name, DBusMessageIter *iter) {
/* Yes, heuristics! But we can change this check
* should it turn out to not be sufficient */
- if (strstr(name, "Timestamp")) {
+ if (endswith(name, "Timestamp")) {
char timestamp[FORMAT_TIMESTAMP_MAX], *t;
if ((t = format_timestamp(timestamp, sizeof(timestamp), u)) || arg_all)
diff --git a/src/systemd-analyze b/src/systemd-analyze
index 5e3a087e9d..6f03d13bd0 100755
--- a/src/systemd-analyze
+++ b/src/systemd-analyze
@@ -15,10 +15,10 @@ def acquire_time_data():
properties = dbus.Interface(bus.get_object('org.freedesktop.systemd1', i[6]), 'org.freedesktop.DBus.Properties')
- ixt = int(properties.Get('org.freedesktop.systemd1.Unit', 'InactiveExitTimestamp'))
- aet = int(properties.Get('org.freedesktop.systemd1.Unit', 'ActiveEnterTimestamp'))
- axt = int(properties.Get('org.freedesktop.systemd1.Unit', 'ActiveExitTimestamp'))
- iet = int(properties.Get('org.freedesktop.systemd1.Unit', 'InactiveEnterTimestamp'))
+ 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))
@@ -27,12 +27,14 @@ def acquire_time_data():
def acquire_start_time():
properties = dbus.Interface(bus.get_object('org.freedesktop.systemd1', '/org/freedesktop/systemd1'), 'org.freedesktop.DBus.Properties')
- startup_time = int(properties.Get('org.freedesktop.systemd1.Manager', 'StartupTimestamp'))
- finish_time = int(properties.Get('org.freedesktop.systemd1.Manager', 'FinishTimestamp'))
+ 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'))
+ assert initrd_time <= startup_time
assert startup_time <= finish_time
- return 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()
@@ -63,7 +65,8 @@ 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 blame
+ sys.stdout.write("""systemd-analyze time
+systemd-analyze blame
systemd-analyze plot
Process systemd profiling information
@@ -74,7 +77,24 @@ Process systemd profiling information
bus = dbus.SystemBus()
-if len(sys.argv) <= 1 or sys.argv[1] == 'blame':
+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 (initrd) + %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" % ( \
+ startup_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)
@@ -92,7 +112,7 @@ if len(sys.argv) <= 1 or sys.argv[1] == 'blame':
elif sys.argv[1] == 'plot':
import cairo
- start_time, finish_time = acquire_start_time()
+ initrd_time, start_time, finish_time = acquire_start_time()
data = acquire_time_data()
s = sorted(data, key = lambda i: i[1])