framework: use TimeAttribute for TestResult and TestrunResult

This makes use of the time TimeAttribute for handling times in results,
both for tests and for runs.

This change requires bumping the json version, and a large chunk of the
changes in this patch are for that change.

This could be split into two patches, but that would require making two
sequential bumps to the json results version, and I felt that the larger
patch was better than making two version bumps.

Reviewed-by: Mark Janes <mark.a.janes@intel.com>
Signed-off-by: Dylan Baker <dylanx.c.baker@intel.com>

13 files changed, 125 insertions, 57 deletions

diff --git a/framework/backends/json.py b/framework/backends/json.py
index 4cc7957b0..99f7e87a4 100644
--- a/framework/backends/json.py
+++ b/framework/backends/json.py
@@ -42,7 +42,7 @@ __all__ = [
 ]
 
 # The current version of the JSON results
-CURRENT_JSON_VERSION = 7
+CURRENT_JSON_VERSION = 8
 
 # The level to indent a final file
 INDENT = 4
@@ -290,6 +290,7 @@ def _update_results(results, filepath):
             4: _update_four_to_five,
             5: _update_five_to_six,
             6: _update_six_to_seven,
+            7: _update_seven_to_eight,
         }
 
         while results.results_version < CURRENT_JSON_VERSION:
@@ -567,6 +568,26 @@ def _update_six_to_seven(result):
     return result
 
 
+def _update_seven_to_eight(result):
+    """Update json results from version 7 to 8.
+
+    This update replaces the time attribute float with a TimeAttribute object,
+    which stores a start time and an end time, and provides methods for getting
+    total and delta.
+
+    This value is used for both TestResult.time and TestrunResult.time_elapsed.
+
+    """
+    for test in result.tests.viewvalues():
+        test.time = results.TimeAttribute(end=test.time)
+
+    result.time_elapsed = results.TimeAttribute(end=result.time_elapsed)
+
+    result.results_version = 8
+
+    return result
+
+
 REGISTRY = Registry(
     extensions=['', '.json'],
     backend=JSONBackend,
diff --git a/framework/backends/junit.py b/framework/backends/junit.py
index a2cdd49a5..ee1cf288a 100644
--- a/framework/backends/junit.py
+++ b/framework/backends/junit.py
@@ -196,7 +196,7 @@ class JUnitBackend(FileBackend):
         element = etree.Element('testcase', name=full_test_name,
                                 classname=classname,
                                 # Incomplete will not have a time.
-                                time=str(data.time),
+                                time=str(data.time.total),
                                 status=str(data.result))
 
         # If this is an incomplete status then none of these values will be
@@ -253,7 +253,7 @@ def _load(results_file):
             name = name[:-1]
 
         result.result = test.attrib['status']
-        result.time = float(test.attrib['time'])
+        result.time = results.TimeAttribute(end=float(test.attrib['time']))
         result.err = test.find('system-err').text
 
         # The command is prepended to system-out, so we need to separate those
@@ -263,7 +263,7 @@ def _load(results_file):
         result.out = '\n'.join(out[1:])
 
         run_result.tests[name] = result
-    
+
     return run_result
 
 
diff --git a/framework/programs/run.py b/framework/programs/run.py
index 16c3d3744..6626a6b6f 100644
--- a/framework/programs/run.py
+++ b/framework/programs/run.py
@@ -269,14 +269,13 @@ def run(input_):
     profile = framework.profile.merge_test_profiles(args.test_profile)
     profile.results_dir = args.results_path
 
-    time_start = time.time()
+    results.time_elapsed.start = time.time()
     # Set the dmesg type
     if args.dmesg:
         profile.dmesg = args.dmesg
     profile.run(opts, args.log_level, backend)
-    time_end = time.time()
 
-    results.time_elapsed = time_end - time_start
+    results.time_elapsed.end = time.time()
     backend.finalize({'time_elapsed': results.time_elapsed})
 
     print('Thank you for running Piglit!\n'
diff --git a/framework/results.py b/framework/results.py
index 7eca5bdec..5354a32af 100644
--- a/framework/results.py
+++ b/framework/results.py
@@ -151,7 +151,7 @@ class TestResult(object):
 
     def __init__(self, result=None):
         self.returncode = None
-        self.time = float()
+        self.time = TimeAttribute()
         self.command = str()
         self.environment = str()
         self.subtests = Subtests()
@@ -214,9 +214,8 @@ class TestResult(object):
         # pylint: disable=assigning-non-slot
         inst = cls()
 
-        # TODO: There's probably a more clever way to do this
-        for each in ['returncode', 'time', 'command', 'exception',
-                     'environment', 'result', 'dmesg']:
+        for each in ['returncode', 'command', 'exception', 'environment',
+                     'time', 'result', 'dmesg']:
             if each in dict_:
                 setattr(inst, each, dict_[each])
 
@@ -284,7 +283,7 @@ class TestrunResult(object):
         self.wglinfo = None
         self.clinfo = None
         self.lspci = None
-        self.time_elapsed = None
+        self.time_elapsed = TimeAttribute()
         self.tests = {}
         self.totals = collections.defaultdict(Totals)
 
@@ -330,15 +329,12 @@ class TestrunResult(object):
         """
         res = cls()
         for name in ['name', 'uname', 'options', 'glxinfo', 'wglinfo', 'lspci',
-                     'tests', 'totals', 'results_version', 'clinfo']:
+                     'time_elapsed', 'tests', 'totals', 'results_version',
+                     'clinfo']:
             value = dict_.get(name)
             if value:
                 setattr(res, name, value)
 
-        # This could be replaced with a getter/setter property
-        time = dict_.get('time_elapsed')
-        res.time_elapsed = None if time is None else float(time)
-
         if not res.totals and not _no_totals:
             res.calculate_group_totals()
 
diff --git a/framework/summary/common.py b/framework/summary/common.py
index 96562e552..b67a98352 100644
--- a/framework/summary/common.py
+++ b/framework/summary/common.py
@@ -24,7 +24,6 @@
 
 from __future__ import absolute_import, division, print_function
 import itertools
-import datetime
 import re
 import operator
 
@@ -267,13 +266,6 @@ def escape_pathname(key):
     return re.sub(r'[/\\]', '_', key)
 
 
-def time_as_delta(time):
-    """Convert time to a time delta, or return None."""
-    if time is not None:
-        return datetime.timedelta(0, time)
-    return None
-
-
 def find_diffs(results, tests, comparator, handler=lambda *a: None):
     """Generate diffs between two or more sets of results.
 
diff --git a/framework/summary/html_.py b/framework/summary/html_.py
index 689bcf1a1..12172b75c 100644
--- a/framework/summary/html_.py
+++ b/framework/summary/html_.py
@@ -36,7 +36,7 @@ from mako.lookup import TemplateLookup
 # the module
 from framework import backends, exceptions
 
-from .common import Results, escape_filename, escape_pathname, time_as_delta
+from .common import Results, escape_filename, escape_pathname
 
 __all__ = [
     'html',
@@ -85,7 +85,7 @@ def _make_testrun_info(results, destination, exclude):
             out.write(_TEMPLATES.get_template('testrun_info.mako').render(
                 name=each.name,
                 totals=each.totals['root'],
-                time=time_as_delta(each.time_elapsed),
+                time=each.time_elapsed.delta,
                 options=each.options,
                 uname=each.uname,
                 glxinfo=each.glxinfo,
@@ -105,9 +105,6 @@ def _make_testrun_info(results, destination, exclude):
                 if not os.path.exists(temp_path):
                     os.makedirs(temp_path)
 
-                if value.time:
-                    value.time = time_as_delta(value.time)
-
                 with open(html_path, 'w') as out:
                     out.write(_TEMPLATES.get_template(
                         'test_result.mako').render(
diff --git a/framework/test/base.py b/framework/test/base.py
index 16615a170..bf0039667 100644
--- a/framework/test/base.py
+++ b/framework/test/base.py
@@ -177,10 +177,10 @@ class Test(object):
         # Run the test
         if self.OPTS.execute:
             try:
-                time_start = time.time()
+                self.result.time.start = time.time()
                 dmesg.update_dmesg()
                 self.run()
-                self.result.time = time.time() - time_start
+                self.result.time.end = time.time()
                 self.result = dmesg.update_result(self.result)
             # This is a rare case where a bare exception is okay, since we're
             # using it to log exceptions
diff --git a/framework/tests/json_results_update_tests.py b/framework/tests/json_results_update_tests.py
index f89d65f42..4f7a59c39 100644
--- a/framework/tests/json_results_update_tests.py
+++ b/framework/tests/json_results_update_tests.py
@@ -752,3 +752,68 @@ class TestV6toV7(object):
         """backends.json.update_results (6 -> 7): Totals are populated"""
         nt.ok_(self.result.totals != {})
 
+
+class TestV7toV8(object):
+    DATA = {
+        "results_version": 7,
+        "name": "test",
+        "options": {
+            "profile": ['quick'],
+            "dmesg": False,
+            "verbose": False,
+            "platform": "gbm",
+            "sync": False,
+            "valgrind": False,
+            "filter": [],
+            "concurrent": "all",
+            "test_count": 0,
+            "exclude_tests": [],
+            "exclude_filter": [],
+            "env": {
+                "lspci": "stuff",
+                "uname": "more stuff",
+                "glxinfo": "and stuff",
+                "wglinfo": "stuff"
+            }
+        },
+        "tests": {
+            'a@test': results.TestResult('pass'),
+        },
+        "time_elapsed": 1.2,
+    }
+
+    @classmethod
+    def setup_class(cls):
+        """Class setup. Create a TestrunResult with v4 data."""
+        cls.DATA['tests']['a@test'] = cls.DATA['tests']['a@test'].to_json()
+        cls.DATA['tests']['a@test']['time'] = 1.2
+
+        with utils.tempfile(
+                json.dumps(cls.DATA, default=backends.json.piglit_encoder)) as t:
+            with open(t, 'r') as f:
+                cls.result = backends.json._update_seven_to_eight(
+                    backends.json._load(f))
+
+    def test_time(self):
+        """backends.json.update_results (7 -> 8): test time is stored as start and end"""
+        nt.eq_(self.result.tests['a@test'].time.start, 0.0)
+        nt.eq_(self.result.tests['a@test'].time.end, 1.2)
+
+    def test_time_inst(self):
+        """backends.json.update_results (7 -> 8): test time is a TimeAttribute instance"""
+        nt.ok_(
+            isinstance(self.result.tests['a@test'].time, results.TimeAttribute),
+            msg='Testresult.time should have been TimeAttribute, '
+                'but was "{}"'.format(type(self.result.tests['a@test'].time)))
+
+    def test_time_elapsed_inst(self):
+        """backends.json.update_results (7 -> 8): total time is stored as TimeAttribute"""
+        nt.ok_(
+            isinstance(self.result.time_elapsed, results.TimeAttribute),
+            msg='TestrunResult.time_elapsed should have been TimeAttribute, '
+                'but was "{}"'.format(type(self.result.time_elapsed)))
+
+    def test_time_elapsed(self):
+        """backends.json.update_results (7 -> 8): total time is stored as start and end"""
+        nt.eq_(self.result.time_elapsed.start, 0.0)
+        nt.eq_(self.result.time_elapsed.end, 1.2)
diff --git a/framework/tests/json_tests.py b/framework/tests/json_tests.py
index be76f3bc2..36409ebca 100644
--- a/framework/tests/json_tests.py
+++ b/framework/tests/json_tests.py
@@ -75,7 +75,7 @@ class TestJsonOutput(utils.StaticDirectory):
         backend.initialize(_create_metadata(args, 'test', core.Options()))
         with backend.write_test('result') as t:
             t(results.TestResult('pass'))
-        backend.finalize({'time_elapsed': 1.22})
+        backend.finalize({'time_elapsed': results.TimeAttribute(end=1.2)})
         with open(os.path.join(cls.tdir, 'results.json'), 'r') as f:
             cls.json = json.load(f)
 
diff --git a/framework/tests/junit_backends_tests.py b/framework/tests/junit_backends_tests.py
index 764f4c35d..96335f330 100644
--- a/framework/tests/junit_backends_tests.py
+++ b/framework/tests/junit_backends_tests.py
@@ -89,7 +89,7 @@ class TestJUnitSingleTest(TestJunitNoTests):
         cls.test_file = os.path.join(cls.tdir, 'results.xml')
 
         result = results.TestResult()
-        result.time = 1.2345
+        result.time.end = 1.2345
         result.result = 'pass'
         result.out = 'this is stdout'
         result.err = 'this is stderr'
@@ -120,7 +120,7 @@ class TestJUnitMultiTest(TestJUnitSingleTest):
         super(TestJUnitMultiTest, cls).setup_class()
 
         result = results.TestResult()
-        result.time = 1.2345
+        result.time.end = 1.2345
         result.result = 'pass'
         result.out = 'this is stdout'
         result.err = 'this is stderr'
@@ -152,7 +152,7 @@ def test_junit_replace():
     """backends.junit.JUnitBackend.write_test(): '{separator}' is replaced with '.'"""
     with utils.tempdir() as tdir:
         result = results.TestResult()
-        result.time = 1.2345
+        result.time.end = 1.2345
         result.result = 'pass'
         result.out = 'this is stdout'
         result.err = 'this is stderr'
@@ -175,7 +175,7 @@ def test_junit_skips_bad_tests():
     """backends.junit.JUnitBackend: skips illformed tests"""
     with utils.tempdir() as tdir:
         result = results.TestResult()
-        result.time = 1.2345
+        result.time.end = 1.2345
         result.result = 'pass'
         result.out = 'this is stdout'
         result.err = 'this is stderr'
@@ -237,8 +237,8 @@ class TestJUnitLoad(utils.StaticDirectory):
     def test_time(self):
         """backends.junit._load: Time is loaded correctly."""
         time = self.xml().tests[self.testname].time
-        nt.assert_is_instance(time, float)
-        nt.assert_equal(time, 1.12345)
+        nt.assert_is_instance(time, results.TimeAttribute)
+        nt.assert_equal(time.total, 1.12345)
 
     def test_command(self):
         """backends.junit._load: command is loaded correctly."""
diff --git a/framework/tests/results_tests.py b/framework/tests/results_tests.py
index 57ca6466e..d35cfa387 100644
--- a/framework/tests/results_tests.py
+++ b/framework/tests/results_tests.py
@@ -469,7 +469,7 @@ class TestTestrunResultToJson(object):
         test.clinfo = 'clinfo'
         test.wglinfo = 'wglinfo'
         test.lspci = 'this is lspci'
-        test.time_elapsed = 1.23
+        test.time_elapsed.end = 1.23
         test.tests = {'a test': results.TestResult('pass')}
 
         cls.test = test.to_json()
@@ -504,7 +504,7 @@ class TestTestrunResultToJson(object):
 
     def test_time(self):
         """results.TestrunResult.to_json: time_elapsed is properly encoded"""
-        nt.eq_(self.test['time_elapsed'], 1.23)
+        nt.eq_(self.test['time_elapsed'].end, 1.23)
 
     def test_tests(self):
         """results.TestrunResult.to_json: tests is properly encoded"""
@@ -530,7 +530,7 @@ class TestTestrunResultFromDict(object):
         test.wglinfo = 'wglinfo'
         test.clinfo = 'clinfo'
         test.lspci = 'this is lspci'
-        test.time_elapsed = 1.23
+        test.time_elapsed.end = 1.23
         test.tests = {
             'a test': results.TestResult('pass'),
             'subtest': subtest,
@@ -548,7 +548,7 @@ class TestTestrunResultFromDict(object):
             nt.eq_(baseline, test)
 
         for attrib in ['name', 'uname', 'glxinfo', 'wglinfo', 'lspci',
-                       'time_elapsed', 'results_version', 'clinfo']:
+                       'results_version', 'clinfo']:
             test.description = ('results.TestrunResult.from_dict: '
                                 '{} is restored correctly'.format(attrib))
             yield (test,
@@ -582,6 +582,17 @@ class TestTestrunResultFromDict(object):
                msg='Subtests should be type Status, but was "{}"'.format(
                    type(self.test.tests['subtest'].subtests['foo'])))
 
+    def test_time_elapsed(self):
+        """results.TestrunRresult.from_dict: time_elapsed is restored correctly
+        """
+        nt.eq_(self.baseline.time_elapsed.end, self.test.time_elapsed.end)
+
+    def test_time(self):
+        """results.TestrunResult.from_dict: time_elapsed is TimeAttribute instance"""
+        nt.ok_(isinstance(self.test.time_elapsed, results.TimeAttribute),
+               msg='time_elapsed should be tpe TimeAttribute, '
+                   'but was "{}"'.format(type(self.test.time_elapsed)))
+
 
 def test_TimeAttribute_to_json():
     """results.TimeAttribute.to_json(): returns expected dictionary"""
diff --git a/framework/tests/summary_common_tests.py b/framework/tests/summary_common_tests.py
index 202049589..1edaf5c02 100644
--- a/framework/tests/summary_common_tests.py
+++ b/framework/tests/summary_common_tests.py
@@ -344,19 +344,6 @@ def test_Results_get_results_missing_subtest():
            [status.PASS, status.NOTRUN])
 
 
-def test_time_as_delta():
-    """summary.time_as_delta: converts a time into a delta"""
-    input_ = 1.2
-    expected = datetime.timedelta(0, input_)
-
-    nt.eq_(expected, summary.time_as_delta(input_))
-
-
-def test_time_as_delta_none():
-    """summary.time_as_delta: returns None when input is None"""
-    nt.eq_(None, summary.time_as_delta(None))
-
-
 def test_escape_filename():
     """summary.escape_filename: replaces invalid characters with '_'"""
     invalid = r'<>:"|?*#'
diff --git a/templates/test_result.mako b/templates/test_result.mako
index f08810a1d..229a5a7c1 100644
--- a/templates/test_result.mako
+++ b/templates/test_result.mako
@@ -26,7 +26,7 @@
       </tr>
       <tr>
         <td>Time</td>
-        <td>${value.time}</b>
+        <td>${value.time.delta}</b>
       </tr>
     % if value.images:
       <tr>