From b0c918b97f1abb160d8df2b94deb03efcb4fcf8f Mon Sep 17 00:00:00 2001
From: Lennart Poettering <lennart@poettering.net>
Date: Tue, 21 Sep 2010 04:14:38 +0200
Subject: [PATCH] manager: measure startup times

---
 src/dbus-manager.c |  1 +
 src/job.c          |  2 ++
 src/manager.c      | 30 ++++++++++++++++++++++++++++++
 src/manager.h      |  3 +++
 src/util.h         |  2 ++
 5 files changed, 38 insertions(+)

diff --git a/src/dbus-manager.c b/src/dbus-manager.c
index fb10bd4fb..c08781d57 100644
--- a/src/dbus-manager.c
+++ b/src/dbus-manager.c
@@ -242,6 +242,7 @@ static DBusHandlerResult bus_manager_message_handler(DBusConnection *connection,
                 { "org.freedesktop.systemd1.Manager", "Version",       bus_property_append_string,    "s",  PACKAGE_STRING     },
                 { "org.freedesktop.systemd1.Manager", "RunningAs",     bus_manager_append_running_as, "s",  &m->running_as     },
                 { "org.freedesktop.systemd1.Manager", "StartupTimestamp", bus_property_append_uint64, "t",  &m->startup_timestamp.realtime },
+                { "org.freedesktop.systemd1.Manager", "FinishTimestamp", bus_property_append_uint64,  "t",  &m->finish_timestamp.realtime },
                 { "org.freedesktop.systemd1.Manager", "LogLevel",      bus_manager_append_log_level,  "s",  NULL               },
                 { "org.freedesktop.systemd1.Manager", "LogTarget",     bus_manager_append_log_target, "s",  NULL               },
                 { "org.freedesktop.systemd1.Manager", "NNames",        bus_manager_append_n_names,    "u",  NULL               },
diff --git a/src/job.c b/src/job.c
index 7b20987c4..ac3bb9d72 100644
--- a/src/job.c
+++ b/src/job.c
@@ -540,6 +540,8 @@ int job_finish_and_invalidate(Job *j, bool success) {
                 if (other->meta.job)
                         job_add_to_run_queue(other->meta.job);
 
+        manager_check_finished(u->meta.manager);
+
         return 0;
 }
 
diff --git a/src/manager.c b/src/manager.c
index 31dd44caa..1be2bfdfc 100644
--- a/src/manager.c
+++ b/src/manager.c
@@ -2173,6 +2173,8 @@ int manager_loop(Manager *m) {
         set_free_free(m->unit_path_cache);
         m->unit_path_cache = NULL;
 
+        manager_check_finished(m);
+
         /* There might still be some zombies hanging around from
          * before we were exec()'ed. Leat's reap them */
         if ((r = manager_dispatch_sigchld(m)) < 0)
@@ -2598,6 +2600,34 @@ bool manager_unit_pending_inactive(Manager *m, const char *name) {
         return unit_pending_inactive(u);
 }
 
+void manager_check_finished(Manager *m) {
+        char userspace[FORMAT_TIMESPAN_MAX], kernel[FORMAT_TIMESPAN_MAX], sum[FORMAT_TIMESPAN_MAX];
+
+        assert(m);
+
+        if (dual_timestamp_is_set(&m->finish_timestamp))
+                return;
+
+        if (hashmap_size(m->jobs) > 0)
+                return;
+
+        dual_timestamp_get(&m->finish_timestamp);
+
+        if (m->running_as == MANAGER_SYSTEM)
+                log_info("Startup finished in %s (kernel) + %s (userspace) = %s.",
+                         format_timespan(kernel, sizeof(kernel),
+                                         m->startup_timestamp.monotonic),
+                         format_timespan(userspace, sizeof(userspace),
+                                         m->finish_timestamp.monotonic - m->startup_timestamp.monotonic),
+                         format_timespan(sum, sizeof(sum),
+                                         m->finish_timestamp.monotonic));
+        else
+                log_debug("Startup finished in %s.",
+                          format_timespan(userspace, sizeof(userspace),
+                                          m->finish_timestamp.monotonic - m->startup_timestamp.monotonic));
+
+}
+
 static const char* const manager_running_as_table[_MANAGER_RUNNING_AS_MAX] = {
         [MANAGER_SYSTEM] = "system",
         [MANAGER_SESSION] = "session"
diff --git a/src/manager.h b/src/manager.h
index a137eb7c6..c404443f5 100644
--- a/src/manager.h
+++ b/src/manager.h
@@ -139,6 +139,7 @@ struct Manager {
         char **environment;
 
         dual_timestamp startup_timestamp;
+        dual_timestamp finish_timestamp;
 
         char *console;
 
@@ -263,6 +264,8 @@ void manager_send_unit_audit(Manager *m, Unit *u, int type, bool success);
 
 bool manager_unit_pending_inactive(Manager *m, const char *name);
 
+void manager_check_finished(Manager *m);
+
 const char *manager_running_as_to_string(ManagerRunningAs i);
 ManagerRunningAs manager_running_as_from_string(const char *s);
 
diff --git a/src/util.h b/src/util.h
index 7ea163f21..ae00ff50c 100644
--- a/src/util.h
+++ b/src/util.h
@@ -73,6 +73,8 @@ usec_t now(clockid_t clock);
 
 dual_timestamp* dual_timestamp_get(dual_timestamp *ts);
 
+#define dual_timestamp_is_set(ts) ((ts)->realtime > 0)
+
 usec_t timespec_load(const struct timespec *ts);
 struct timespec *timespec_store(struct timespec *ts, usec_t u);
 
-- 
2.30.2