picnoir/Systemd
1
0
Fork 0
Code Issues Pull requests Projects Releases Wiki Activity

dbus: expose monotonic timestamps on the bus

Browse source
This commit is contained in:
Lennart Poettering 2011-04-07 21:35:37 +02:00
parent f1d19aa412
commit b21a0ef8fc
7 changed files with 60 additions and 18 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

2
TODO
View file

@ -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

2
src/dbus-execute.c
View file

@ -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))

6
src/dbus-execute.h
View file

@ -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);

6
src/dbus-manager.c
View file

@ -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 },

16
src/dbus-unit.h
View file

@ -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);

6
src/systemctl.c
View file

@ -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)

40
src/systemd-analyze
View file

@ -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])