Patchwork [V5] run-tests: '--time' option provide more details to Linux users

login
register
mail settings
Submitter Anurag Goel
Date Aug. 1, 2014, 5:52 p.m.
Message ID <f923d7ab5a447b32d3db.1406915566@ubuntu.ubuntu-domain>
Download mbox | patch
Permalink /patch/5218/
State Accepted
Headers show

Comments

Anurag Goel - Aug. 1, 2014, 5:52 p.m.
# HG changeset patch
# User anuraggoel <anurag.dsps@gmail.com>
# Date 1403725970 -19800
#      Thu Jun 26 01:22:50 2014 +0530
# Node ID f923d7ab5a447b32d3db164153fa1e32d0145f31
# Parent  16132125b0be467a97fc49ab124f3c03022d02bc
run-tests: '--time' option provide more details to Linux users

As our tests execute in child processes, this patch uses os.times()
module in replace of time.time() module to provide additional info like
user time and system time spent by child's processes along with real elapsed
time taken by a process.

There is one limitation of this patch. It can work only for Linux users and
not for Windows.

"os.times" module returns a 5-tuple of a floaing point numbers.
1) User time
2) System time
3) Child's user time
4) Child's system time
5) Ellapsed real time

On Windows, only the first two items are filled, the others are zero.
Therefore, below test cases does not break on Windows but instead gives the
zero value.
Pierre-Yves David - Aug. 4, 2014, 5:28 p.m.
On 08/01/2014 10:52 AM, Anurag Goel wrote:
> # HG changeset patch
> # User anuraggoel <anurag.dsps@gmail.com>
> # Date 1403725970 -19800
> #      Thu Jun 26 01:22:50 2014 +0530
> # Node ID f923d7ab5a447b32d3db164153fa1e32d0145f31
> # Parent  16132125b0be467a97fc49ab124f3c03022d02bc
> run-tests: '--time' option provide more details to Linux users

I pushed this patches after small fixes to the formatting and the test 
regexp (did you ran the tests?).

Thanks.

(queued)

Patch

diff -r 16132125b0be -r f923d7ab5a44 tests/run-tests.py
--- a/tests/run-tests.py	Wed Jun 25 21:00:24 2014 +0530
+++ b/tests/run-tests.py	Thu Jun 26 01:22:50 2014 +0530
@@ -1076,6 +1076,7 @@ 
 
         self.times = []
         self._started = {}
+        self._stopped = {}
 
     def addFailure(self, test, reason):
         self.failures.append((test, reason))
@@ -1165,17 +1166,28 @@ 
     def startTest(self, test):
         super(TestResult, self).startTest(test)
 
-        self._started[test.name] = time.time()
+        # os.times module computes the user time and system time spent by
+        # child's processes along with real elapsed time taken by a process.
+        # This module has one limitation. It can only work for Linux user
+        # and not for Windows.
+        self._started[test.name] = os.times()
 
     def stopTest(self, test, interrupted=False):
         super(TestResult, self).stopTest(test)
 
-        self.times.append((test.name, time.time() - self._started[test.name]))
+        self._stopped[test.name] = os.times()
+
+        starttime = self._started[test.name]
+        endtime = self._stopped[test.name]
+        self.times.append((test.name, endtime[2] - starttime[2],
+                    endtime[3] - starttime[3], endtime[4] - starttime[4]))
+
         del self._started[test.name]
+        del self._stopped[test.name]
 
         if interrupted:
             self.stream.writeln('INTERRUPTED: %s (after %d seconds)' % (
-                test.name, self.times[-1][1]))
+                test.name, self.times[-1][3]))
 
 class TestSuite(unittest.TestSuite):
     """Custom unitest TestSuite that knows how to execute Mercurial tests."""
@@ -1346,11 +1358,12 @@ 
 
     def printtimes(self, times):
         self.stream.writeln('# Producing time report')
-        times.sort(key=lambda t: (t[1], t[0]), reverse=True)
-        cols = '%7.3f   %s'
-        self.stream.writeln('%-7s   %s' % ('Time', 'Test'))
-        for test, timetaken in times:
-            self.stream.writeln(cols % (timetaken, test))
+        times.sort(key=lambda t: (t[3]))
+        cols = '%0.3f %7.3f %7.3f   %s'
+        self.stream.writeln('%-7s %-7s %-7s   %s' % ('cuser', 'csys', 'real',
+                    'Test'))
+        for test, cuser, csys, real in times:
+            self.stream.writeln(cols % (cuser, csys, real, test))
 
 class TestRunner(object):
     """Holds context for executing tests.
diff -r 16132125b0be -r f923d7ab5a44 tests/test-run-tests.t
--- a/tests/test-run-tests.t	Wed Jun 25 21:00:24 2014 +0530
+++ b/tests/test-run-tests.t	Thu Jun 26 01:22:50 2014 +0530
@@ -201,3 +201,23 @@ 
   # Ran 2 tests, 0 skipped, 0 warned, 1 failed.
   python hash seed: * (glob)
   [1]
+
+test for --time
+==================
+
+  $ $TESTDIR/run-tests.py --with-hg=`which hg` test-success.t --time
+  .
+  # Ran 1 tests, 0 skipped, 0 warned, 0 failed.
+  # Producing time report
+  cuser   csys    real      Test
+  [\d\.]{5}   [\d\.]{5}   [\d\.]{5}   test-success.t (re)
+
+test for --time with --job enabled
+====================================
+
+  $ $TESTDIR/run-tests.py --with-hg=`which hg` test-success.t --time --jobs 2
+  .
+  # Ran 1 tests, 0 skipped, 0 warned, 0 failed.
+  # Producing time report
+  cuser   csys    real      Test
+  [\d\.]{5}   [\d\.]{5}   [\d\.]{5}   test-success.t (re)