# HG changeset patch
# User Gregory Szorc <gregory.szorc@gmail.com>
# Date 1398040766 25200
# Node ID b162bdc78befeaae8dfe3b23c4eeedaacd3c93a1
# Parent  dcefc4091c862e9c53d4f3a32c4014c0f4c3ac98
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).

diff -r dcefc4091c86 -r b162bdc78bef 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