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

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.
This commit is contained in:
Lennart Poettering 2012-09-13 18:54:32 +02:00
parent e50d504865
commit 915b375388
7 changed files with 65 additions and 27 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

8
src/analyze/systemd-analyze
View File

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

22
src/core/dbus-manager.c
View File

@ -214,6 +214,8 @@
" <arg name=\"result\" type=\"s\"/>\n" \
" </signal>" \
" <signal name=\"StartupFinished\">\n" \
" <arg name=\"firmware\" type=\"t\"/>\n" \
" <arg name=\"loader\" type=\"t\"/>\n" \
" <arg name=\"kernel\" type=\"t\"/>\n" \
" <arg name=\"initrd\" type=\"t\"/>\n" \
" <arg name=\"userspace\" type=\"t\"/>\n" \
@ -226,10 +228,16 @@
" <property name=\"Distribution\" type=\"s\" access=\"read\"/>\n" \
" <property name=\"Features\" type=\"s\" access=\"read\"/>\n" \
" <property name=\"Tainted\" type=\"s\" access=\"read\"/>\n" \
" <property name=\"FirmwareTimestamp\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"FirmwareTimestampMonotonic\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"LoaderTimestamp\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"LoaderTimestampMonotonic\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"KernelTimestamp\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"KernelTimestampMonotonic\" type=\"t\" 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=\"UserspaceTimestamp\" type=\"t\" access=\"read\"/>\n" \
" <property name=\"UserspaceTimestampMonotonic\" 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" \
@ -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 },

4
src/core/dbus.c
View File

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

2
src/core/dbus.h
View File

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

49
src/core/manager.c
View File

@ -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.",

5
src/core/manager.h
View File

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

2
src/core/timer.c
View File

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