[systemd-commits] src/analyze src/core
Lennart Poettering
lennart at kemper.freedesktop.org
Thu Sep 13 09:56:28 PDT 2012
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(-)
New commits:
commit 915b375388231ed97cad2929ab948756bfc77c42
Author: Lennart Poettering <lennart at poettering.net>
Date: Thu Sep 13 18:54:32 2012 +0200
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.
diff --git a/src/analyze/systemd-analyze b/src/analyze/systemd-analyze
index 76eceee..636fd74 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 c341d36..557b3e4 100644
--- a/src/core/dbus-manager.c
+++ b/src/core/dbus-manager.c
@@ -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 },
diff --git a/src/core/dbus.c b/src/core/dbus.c
index 1fc7148..75773aa 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 0502d7c..c7a058e 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 40b0c50..23d8ca3 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 603c2dc..653496d 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 0b3c5ce..03c9610 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:
More information about the systemd-commits
mailing list