add util.log_time helper

The reason for this is that more and more things I was wanting to be able to
see how long they took. This puts that time logic into a single place. It
also supports from /proc/uptime as the timing mechanism.

While reading /proc/uptime is almost certainly slower than time.time(), it does
give millisecond granularity and is not affected by 'ntpdate' having run in
between the two events.

1 files changed, 35 insertions, 0 deletions

diff --git a/cloudinit/util.py b/cloudinit/util.py
index 8542fe27..4a74ba57 100644
--- a/cloudinit/util.py
+++ b/cloudinit/util.py
@@ -1770,3 +1770,38 @@ def which(program):
                 return exe_file
 
     return None
+
+
+def log_time(logfunc, msg, func, args=None, kwargs=None, get_uptime=False):
+    if args is None:
+        args = []
+    if kwargs is None:
+        kwargs = {}
+
+    start = time.time()
+
+    ustart = None
+    if get_uptime:
+        try:
+            ustart = float(uptime())
+        except ValueError:
+            pass
+
+    try:
+        ret = func(*args, **kwargs)
+    finally:
+        delta = time.time() - start
+        if ustart is not None:
+            try:
+                udelta = float(uptime()) - ustart
+            except ValueError:
+                udelta = "N/A"
+
+        tmsg = " took %0.3f seconds" % delta
+        if get_uptime:
+            tmsg += "(%0.2f)" % udelta
+        try:
+            logfunc(msg + tmsg)
+        except:
+            pass
+    return ret