ext: Add timing indications to every TestCase

The log_call helper is now accepting a time parameter (dictionary). If
the param is not None, the function will fill the timing indications
(user and system time) for the TestCase.

There are some TestCases whose user time is not of our interest; for
example we don't really care about the cpu time of a stdout diff
(MatchStdout tests). In those cases the resulting cpu time in the
generated JUnit file (results.xml) will be 0.

JIRA: https://gem5.atlassian.net/browse/GEM5-548

Change-Id: I53c1b59f8ad93900aeac06197e39189c00a9053c
Signed-off-by: Giacomo Travaglini <giacomo.travaglini@arm.com>
Reviewed-on: https://gem5-review.googlesource.com/c/public/gem5/+/32653
Tested-by: kokoro <noreply+kokoro@google.com>

diff --git a/ext/testlib/helper.py b/ext/testlib/helper.py
index 01ca539dc3ff907703d29e00621e9a3eb21984de..1cb13f06ec3d22751124c7eb2d67d9443f50cb72 100644 (file)
--- a/ext/testlib/helper.py
+++ b/ext/testlib/helper.py
@@ -132,7 +132,7 @@ class TimedWaitPID(object):
 TimedWaitPID.install()
 
 #TODO Tear out duplicate logic from the sandbox IOManager
-def log_call(logger, command, *popenargs, **kwargs):
+def log_call(logger, command, time, *popenargs, **kwargs):
     '''
     Calls the given process and automatically logs the command and output.
 
@@ -186,6 +186,12 @@ def log_call(logger, command, *popenargs, **kwargs):
     retval = p.wait()
     stdout_thread.join()
     stderr_thread.join()
+
+    if time is not None and TimedWaitPID.has_time_for_pid(p.pid):
+        resource_usage = TimedWaitPID.get_time_for_pid(p.pid)
+        time['user_time'] = resource_usage.user_time
+        time['system_time'] = resource_usage.system_time
+
     # Return the return exit code of the process.
     if retval != 0:
         raise subprocess.CalledProcessError(retval, cmdstr)
@@ -482,7 +488,8 @@ def diff_out_file(ref_file, out_file, logger, ignore_regexes=tuple()):
     (_, tfname) = tempfile.mkstemp(dir=os.path.dirname(out_file), text=True)
     with open(tfname, 'r+') as tempfile_:
         try:
-            log_call(logger, ['diff', out_file, ref_file], stdout=tempfile_)
+            log_call(logger, ['diff', out_file, ref_file],
+                time=None, stdout=tempfile_)
         except OSError:
             # Likely signals that diff does not exist on this system. fallback
             # to difflib

diff --git a/ext/testlib/result.py b/ext/testlib/result.py
index 2d2c506a1384c76de21030e9608e7541635b276e..5c60342c111f14457efa4924ac253522f218eb66 100644 (file)
--- a/ext/testlib/result.py
+++ b/ext/testlib/result.py
@@ -1,3 +1,15 @@
+# Copyright (c) 2020 ARM Limited
+# All rights reserved
+#
+# The license below extends only to copyright in the software and shall
+# not be construed as granting a license to any other intellectual
+# property including but not limited to intellectual property relating
+# to a hardware implementation of the functionality of the software
+# licensed hereunder.  You may use the software subject to the license
+# terms below provided that you ensure that this notice is replicated
+# unmodified and in its entirety in all distributions of the software,
+# modified or unmodified, in source code or in binary form.
+#
 # Copyright (c) 2017 Mark D. Hill and David A. Wood
 # All rights reserved.
 #
@@ -60,6 +72,10 @@ class _CommonMetadataMixin:
     def unsuccessful(self):
         return self._metadata.result.value != state.Result.Passed
 
+    @property
+    def time(self):
+        return self._metadata.time
+
 
 class InternalTestResult(_CommonMetadataMixin):
     def __init__(self, obj, suite, directory):
@@ -258,6 +274,7 @@ class JUnitTestCase(XMLElement):
              # TODO JUnit expects class of test.. add as test metadata.
             XMLAttribute('classname', str(test_result.uid)),
             XMLAttribute('status', str(test_result.result)),
+            XMLAttribute('time', str(test_result.time["user_time"])),
         ]
 
         # TODO JUnit expects a message for the reason a test was

diff --git a/ext/testlib/runner.py b/ext/testlib/runner.py
index ee658c966515946db24bcfe61cba8f5e355eac99..16ff9529851ca50987cf91f3f762fa4171ddd76a 100644 (file)
--- a/ext/testlib/runner.py
+++ b/ext/testlib/runner.py
@@ -79,6 +79,8 @@ class TestParameters(object):
         self.suite = suite
         self.log = log.test_log
         self.log.test = test
+        self.time = {
+            "user_time" : 0, "system_time" : 0}
 
     @helper.cacheresult
     def _fixtures(self):
@@ -152,6 +154,8 @@ class TestRunner(RunnerPattern):
         else:
             self.testable.result = Result(Result.Passed)
 
+        self.testable.time = test_params.time
+
 
 class SuiteRunner(RunnerPattern):
     def test(self):

diff --git a/ext/testlib/wrappers.py b/ext/testlib/wrappers.py
index e91970262e31afc8a40a08aa3bc0b3c51a659714..b2b887b0f9b51b10aa9b8925f64fac5f23ccd446 100644 (file)
--- a/ext/testlib/wrappers.py
+++ b/ext/testlib/wrappers.py
@@ -1,4 +1,4 @@
-# Copyright (c) 2019 ARM Limited
+# Copyright (c) 2019-2020 ARM Limited
 # All rights reserved
 #
 # The license below extends only to copyright in the software and shall
@@ -124,6 +124,14 @@ class LoadedTestable(object):
     def runner(self):
         return self.obj.runner
 
+    @property
+    def time(self):
+        return self.metadata.time
+
+    @time.setter
+    def time(self, value):
+        self.metadata.time = value
+
     # TODO Change log to provide status_update, result_update for all types.
     def log_status(self, status):
         import testlib.log as log

diff --git a/tests/gem5/fixture.py b/tests/gem5/fixture.py
index bb911dde0ff28fe796ba3f1d30e8baa9dc4a9254..e141d022dbe896314f58529b65c93670ea7879df 100644 (file)
--- a/tests/gem5/fixture.py
+++ b/tests/gem5/fixture.py
@@ -170,7 +170,7 @@ class SConsFixture(UniqueFixture):
         command.extend(self.targets)
         if self.options:
             command.extend(self.options)
-        log_call(log.test_log, command, stderr=sys.stderr)
+        log_call(log.test_log, command, time=None, stderr=sys.stderr)
 
 class Gem5Fixture(SConsFixture):
     def __new__(cls, isa, variant, protocol=None):
@@ -208,7 +208,7 @@ class MakeFixture(Fixture):
         targets = set(self.required_by)
         command = ['make', '-C', self.directory]
         command.extend([target.target for target in targets])
-        log_call(log.test_log, command, stderr=sys.stderr)
+        log_call(log.test_log, command, time=None, stderr=sys.stderr)
 
 
 class MakeTarget(Fixture):

diff --git a/tests/gem5/suite.py b/tests/gem5/suite.py
index cba3d43227e594f1a9cfd11707fa6f0dfff07703..3b0f1f80dbb4eaeea0037a4866795ae8a88cde6e 100644 (file)
--- a/tests/gem5/suite.py
+++ b/tests/gem5/suite.py
@@ -176,6 +176,7 @@ def _create_test_run_gem5(config, config_args, gem5_args):
         command.append(config)
         # Config_args should set up the program args.
         command.extend(config_args)
-        log_call(params.log, command, stdout=sys.stdout, stderr=sys.stderr)
+        log_call(params.log, command, time=params.time,
+            stdout=sys.stdout, stderr=sys.stderr)
 
     return test_run_gem5