[PATCH V2] run-tests: '--time' option provide more details to linux users

[Anurag Goel]

# HG changeset patch
# User anuraggoel <anurag.dsps at gmail.com>
# Date 1401362915 -19800
#      Thu May 29 16:58:35 2014 +0530
# Node ID f1b7b84a4f310afc9fcf132bf73c671e53b14384
# Parent  bde505f47141257e5aa0c71f8a3834047d5251e2
run-tests: '--time' option provide more details to linux users

As our tests exceute in child process, this patch includes os.times()
module in replace of time.time() module to provide addition info like
children's user time and children's system time along with real time
taken by a process.

There is one limitation of this patch.It can only work for linux users and not
for windows users because in windows, os.times() module work only for parent
process.

I have also added a test case which check the behaviour of --time option.

diff -r bde505f47141 -r f1b7b84a4f31 tests/run-tests.py
--- a/tests/run-tests.py	Fri May 02 01:09:14 2014 +0200
+++ b/tests/run-tests.py	Thu May 29 16:58:35 2014 +0530
@@ -1069,6 +1069,7 @@
 
         self.times = []
         self._started = {}
+        self._stopped = {}
 
     def addFailure(self, test, reason):
         self.failures.append((test, reason))
@@ -1149,17 +1150,22 @@
     def startTest(self, test):
         super(TestResult, self).startTest(test)
 
-        self._started[test.name] = time.time()
+        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()
+        self.times.append((test.name, self._stopped[test.name][2] -
+                    self._started[test.name][2], self._stopped[test.name][3] -
+                    self._started[test.name][3], self._stopped[test.name][4] -
+                    self._started[test.name][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."""
@@ -1320,11 +1326,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 bde505f47141 -r f1b7b84a4f31 tests/test-run-tests.t
--- a/tests/test-run-tests.t	Fri May 02 01:09:14 2014 +0200
+++ b/tests/test-run-tests.t	Thu May 29 16:58:35 2014 +0530
@@ -74,6 +74,16 @@
   foo.bar\r \(no-eol\) (re) (esc)
   foo.bar\r \(no-eol\) (re)
 
+testing --time option
+
+  $ touch "$TESTDIR/temp.t"
+  $ python "$TESTDIR/run-tests.py" --time "$TESTDIR/temp.t"
+  
+  # Ran 0 tests, 0 skipped, 0 warned, 0 failed.
+  # Producing time report
+  cuser   csys    real      Test
+  $ rm "$TESTDIR/temp.t"
+
 testing hghave
 
   $ "$TESTDIR/hghave" true