[Libvirt-cim] [PATCH] [TEST] #3 Add timestamps to main.py to calculate run time of tests

[Kaitlin Rupert]

# HG changeset patch
# User Kaitlin Rupert <karupert at us.ibm.com>
# Date 1254854080 25200
# Node ID 324d7caaa53c8a3287053155342fdbdea85b1209
# Parent  be6620706891d4ff7863ad7e9f7e14ae2c71b6d0
[TEST] #3 Add timestamps to main.py to calculate run time of tests

Updates from 2 to 3:
  -Only print execution time if --print-exec-time is specified
  -In the test run summary, only print the execution time in the report header

Updates from 1 to 2:
  -Add deliniation between mins, sec, etc.
  -Add total execution time to top of test report

These changes allow the user to specify the --print-exec-time flag, which will
print the execution time of each test.  If this flag isn't specified, the
total run time of the test is still printed.

Signed-off-by: Kaitlin Rupert <karupert at us.ibm.com>

diff -r be6620706891 -r 324d7caaa53c suites/libvirt-cim/lib/XenKvmLib/reporting.py
--- a/suites/libvirt-cim/lib/XenKvmLib/reporting.py	Tue Oct 06 10:46:31 2009 -0700
+++ b/suites/libvirt-cim/lib/XenKvmLib/reporting.py	Tue Oct 06 11:34:40 2009 -0700
@@ -125,7 +125,9 @@
 
     fd = open(log_file, "r")
 
+    exec_time = "Total test execution: Unknown\n"
     run_output = ""
+
     for line in fd.xreadlines():
         for type, val in rvals.iteritems():
             if type in line:
@@ -133,11 +135,15 @@
                     continue
                 rvals[type] += 1
                 tstr[type] += "%s" % line
-        run_output += line
+
+        if line.find("Total test execution") >= 0:
+            exec_time = line 
+        else:
+            run_output += line
 
     fd.close()
 
-    return rvals, tstr, run_output
+    return rvals, tstr, run_output, exec_time
 
 def build_report_body(rvals, tstr, div):
     results = ""
@@ -168,13 +174,13 @@
 
     divider = "=================================================\n"
 
-    rvals, tstr, run_output = parse_run_output(log_file)
+    rvals, tstr, run_output, exec_time = parse_run_output(log_file)
 
     res, res_total, test_block = build_report_body(rvals, tstr, divider)
 
-    report = divider + heading + "\n" + divider + sys_env + divider + res \
-             + res_total + divider + test_block + "Full report:\n" \
-             + run_output
+    report = divider + heading + "\n" + divider + sys_env + exec_time \
+             + divider + res + res_total + divider + test_block \
+             + "Full report:\n" + run_output
 
     fd = open(log_file, "w")
     rc = fd.write(report)
diff -r be6620706891 -r 324d7caaa53c suites/libvirt-cim/main.py
--- a/suites/libvirt-cim/main.py	Tue Oct 06 10:46:31 2009 -0700
+++ b/suites/libvirt-cim/main.py	Tue Oct 06 11:34:40 2009 -0700
@@ -22,6 +22,7 @@
 # Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307  USA
 #
 
+from time import time
 from optparse import OptionParser
 import os
 import sys
@@ -64,6 +65,9 @@
                   help="Duplicate the output to stderr")
 parser.add_option("--report", dest="report",
                   help="Send report using mail info: --report=<recipient addr>")
+parser.add_option("--print-exec-time", action="store_true", 
+                  dest="print_exec_time",
+                  help="Print execution time of each test")
 
 TEST_SUITE = 'cimtest'
 CIMTEST_RCFILE = '%s/.cimtestrc' % os.environ['HOME']
@@ -146,6 +150,30 @@
 
     return PASS
 
+def print_exec_time(testsuite, exec_time, prefix=None):
+
+    #Convert run time from seconds to hours
+    tmp = exec_time / (60 * 60)
+    h = int(tmp)
+
+    #Subtract out hours and convert remainder to minutes
+    tmp = (tmp - h) * 60 
+    m = int(tmp)
+
+    #Subtract out minutes and convert remainder to seconds
+    tmp = (tmp - m) * 60 
+    s = int(tmp)
+
+    #Subtract out seconds and convert remainder to milliseconds
+    tmp = (tmp - s) * 1000
+    msec = int(tmp)
+
+    if prefix is None:
+        prefix = " "
+
+    testsuite.debug("%s %sh | %smin | %ssec | %smsec" %
+                    (prefix, h, m, s, msec)) 
+
 def main():
     (options, args) = parser.parse_args()
     to_addr = None
@@ -213,6 +241,8 @@
 
     print "\nTesting " + options.virt + " hypervisor"
 
+    test_run_time_total = 0
+
     for test in test_list: 
         testsuite.debug(div) 
         t_path = os.path.join(TEST_SUITE, test['group'])
@@ -222,13 +252,26 @@
                                                   options.virt, dbg,
                                                   options.t_url)
         cmd = cdto + ' && ' + ' ' + run
+        start_time = time()
         status, output = commands.getstatusoutput(cmd)
+        end_time = time()
 
         os_status = os.WEXITSTATUS(status)
 
         testsuite.print_results(test['group'], test['test'], os_status, output)
 
+        exec_time = end_time - start_time
+        test_run_time_total = test_run_time_total + exec_time
+
+        if options.print_exec_time:
+            print_exec_time(testsuite, exec_time, "  Test execution time:")
+
     testsuite.debug("%s\n" % div) 
+
+    if options.print_exec_time:
+        print_exec_time(testsuite, test_run_time_total, "Total test execution:")
+        testsuite.debug("\n") 
+
     testsuite.finish()
 
     status = cleanup_env(options.ip, options.virt)