run-tests: capture execution times in TestResult
authorGregory Szorc <gregory.szorc@gmail.com>
Sun, 20 Apr 2014 17:39:26 -0700
changeset 21495 b162bdc78bef
parent 21494 dcefc4091c86
child 21496 f145914e698d
run-tests: capture execution times in TestResult TestResult has facilities for recording when tests start and stop. It makes sense to move execution time recording into TestResult. In addition, output generation is being moved into TestResult, a class that has a concept of an output buffer (and a lock).
tests/run-tests.py
--- a/tests/run-tests.py	Sun Apr 20 17:28:24 2014 -0700
+++ b/tests/run-tests.py	Sun Apr 20 17:39:26 2014 -0700
@@ -404,11 +404,12 @@
 
     def run(self, result):
         result.startTest(self)
-        starttime = time.time()
+        interrupted = False
         try:
             try:
                 self.setUp()
             except (KeyboardInterrupt, SystemExit):
+                interrupted = True
                 raise
             except Exception:
                 result.addError(self, sys.exc_info())
@@ -418,10 +419,7 @@
             try:
                 self.runTest()
             except KeyboardInterrupt:
-                duration = time.time() - starttime
-                log('INTERRUPTED: %s (after %d seconds)' % (self.name,
-                                                            duration))
-                self._runner.times.append((self.name, duration))
+                interrupted = True
                 raise
             except SkipTest, e:
                 result.addSkip(self, str(e))
@@ -440,11 +438,10 @@
             else:
                 success = True
 
-            self._runner.times.append((self.name, time.time() - starttime))
-
             try:
                 self.tearDown()
             except (KeyboardInterrupt, SystemExit):
+                interrupted = True
                 raise
             except Exception:
                 result.addError(self, sys.exc_info())
@@ -453,7 +450,7 @@
             if success:
                 result.addSuccess(self)
         finally:
-            result.stopTest(self)
+            result.stopTest(self, interrupted=interrupted)
 
     def runTest(self):
         """Run this test instance.
@@ -1071,6 +1068,9 @@
         # sense to map it into fail some day.
         self.warned = []
 
+        self.times = []
+        self._started = {}
+
     def addFailure(self, test, reason):
         self.failures.append((test, reason))
 
@@ -1114,6 +1114,21 @@
             self.stream.write('~')
             self.stream.flush()
 
+    def startTest(self, test):
+        super(TestResult, self).startTest(test)
+
+        self._started[test.name] = time.time()
+
+    def stopTest(self, test, interrupted=False):
+        super(TestResult, self).stopTest(test)
+
+        self.times.append((test.name, time.time() - self._started[test.name]))
+        del self._started[test.name]
+
+        if interrupted:
+            self.stream.writeln('INTERRUPTED: %s (after %d seconds)' % (
+                test.name, self.times[-1][1]))
+
 class TestSuite(unittest.TestSuite):
     """Custom unitest TestSuite that knows how to execute concurrently."""
 
@@ -1169,14 +1184,14 @@
             self.stream.writeln('python hash seed: %s' %
                 os.environ['PYTHONHASHSEED'])
         if self._runner.options.time:
-            self.printtimes()
+            self.printtimes(result.times)
 
-    def printtimes(self):
+    def printtimes(self, times):
         self.stream.writeln('# Producing time report')
-        self._runner.times.sort(key=lambda t: (t[1], t[0]), reverse=True)
+        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 self._runner.times:
+        for test, timetaken in times:
             self.stream.writeln(cols % (timetaken, test))
 
 class TestRunner(object):
@@ -1209,7 +1224,6 @@
         self.tmpbinddir = None
         self.pythondir = None
         self.coveragefile = None
-        self.times = [] # Holds execution times of tests.
         self.abort = [False]
         self._createdfiles = []
         self._hgpath = None