fedabipkgdiff: Add timing data in debug logs

This patch adds elapsed timing data to the debug logs emitted by the
"log_call" decorator.

	* tools/fedabipkgdiff (log_call): Log the time taken by the
	decorated function.

Signed-off-by: Dodji Seketeli <dodji@redhat.com>

diff --git a/tools/fedabipkgdiff b/tools/fedabipkgdiff
index 86bf0048beb4d75b0679bca23aa17e797d7993cc..960b15a619fac846cdf6c0eb8c9508562bde4571 100755 (executable)
--- a/tools/fedabipkgdiff
+++ b/tools/fedabipkgdiff
@@ -30,6 +30,9 @@ import xdg.BaseDirectory
 import rpm
 import koji
 
+from timeit import default_timer as timer
+from datetime import timedelta
+
 # @file
 #
 # You might have known that abipkgdiff is a command line tool to compare two
@@ -261,8 +264,12 @@ def log_call(func):
                      func.__name__,
                      args if args else '',
                      kwargs if kwargs else '')
+        start = timer()
         result = func(*args, **kwargs)
-        logger.debug('Result from %s: %s', func.__name__, result)
+        end = timer();
+        elapsed_type = timedelta(seconds=end-start)
+        logger.debug('Result from %s: %s, in: %s',
+                     func.__name__, result, elapsed_type)
         return result
     return proxy