[tor-commits] [stem/master] Track individual test runtimes

[atagar at torproject.org]

commit a53a1d97d183b2681bfcd721fc8136a4386e7be0
Author: Damian Johnson <atagar at torproject.org>
Date:   Thu Dec 29 10:39:08 2016 -0800

    Track individual test runtimes
    
    I'd like to further speed up our tests and the first step for doing so is
    getting more information about where we're spending our time.
    
    Python's built-in unittest module provides the runtime for full modules but
    makes it a surprising pita to get all individual runtimes. Expanding their
    runner to make this possible.
    
    Runtimes aren't weaved into our test output yet and I might fiddle with this
    some more (don't like the need for a global). Good starting place though.
---
 docs/change_log.rst     |  4 ++++
 run_tests.py            |  7 +++++--
 stem/util/test_tools.py | 51 +++++++++++++++++++++++++++++++++++++++++++++++++
 3 files changed, 60 insertions(+), 2 deletions(-)

diff --git a/docs/change_log.rst b/docs/change_log.rst
index 5870beb..e16a948 100644
--- a/docs/change_log.rst
+++ b/docs/change_log.rst
@@ -48,6 +48,10 @@ The following are only available within Stem's `git repository
   * Support for protocol descriptor fields (:spec:`eb4fb3c`)
   * Shared randomness properties weren't being read in votes (:trac:`21102`)
 
+ * **Utilities**
+
+  * Added :class:`~stem.util.test_tools.TimedTestRunner` and :func:`~stem.util.test_tools.test_runtimes`
+
 .. _version_1.5:
 
 Version 1.5 (November 20th, 2016)
diff --git a/run_tests.py b/run_tests.py
index db34e5b..df4da12 100755
--- a/run_tests.py
+++ b/run_tests.py
@@ -158,7 +158,10 @@ def main():
     Task('checking pyflakes version', test.util.check_pyflakes_version),
     Task('checking pycodestyle version', test.util.check_pycodestyle_version),
     Task('checking for orphaned .pyc files', test.util.clean_orphaned_pyc, (SRC_PATHS,)),
-    Task('checking for unused tests', test.util.check_for_unused_tests, ((os.path.join(STEM_BASE, 'test'),),)),
+    Task('checking for unused tests', test.util.check_for_unused_tests, [(
+      os.path.join(STEM_BASE, 'test', 'unit'),
+      os.path.join(STEM_BASE, 'test', 'integ'),
+    )]),
     pyflakes_task,
     pycodestyle_task,
   )
@@ -381,7 +384,7 @@ def _run_test(args, test_class, output_filters, logging_buffer):
     return None
 
   test_results = StringIO()
-  run_result = unittest.TextTestRunner(test_results, verbosity=2).run(suite)
+  run_result = stem.util.test_tools.TimedTestRunner(test_results, verbosity=2).run(suite)
 
   if args.verbose:
     println(test.output.apply_filters(test_results.getvalue(), *output_filters))
diff --git a/stem/util/test_tools.py b/stem/util/test_tools.py
index 406ebd7..21adc9a 100644
--- a/stem/util/test_tools.py
+++ b/stem/util/test_tools.py
@@ -8,6 +8,9 @@ Helper functions for testing.
 
 ::
 
+  TimedTestRunner - test runner that tracks test runtimes
+  test_runtimes - provides runtime of tests excuted through TimedTestRunners
+
   clean_orphaned_pyc - delete *.pyc files without corresponding *.py
 
   is_pyflakes_available - checks if pyflakes is available
@@ -21,6 +24,8 @@ import collections
 import linecache
 import os
 import re
+import time
+import unittest
 
 import stem.util.conf
 import stem.util.system
@@ -32,6 +37,8 @@ CONFIG = stem.util.conf.config_dict('test', {
   'exclude_paths': [],
 })
 
+TEST_RUNTIMES = {}
+
 
 class Issue(collections.namedtuple('Issue', ['line_number', 'message', 'line'])):
   """
@@ -43,6 +50,50 @@ class Issue(collections.namedtuple('Issue', ['line_number', 'message', 'line']))
   """
 
 
+class TimedTestRunner(unittest.TextTestRunner):
+  """
+  Test runner that tracks the runtime of individual tests. When tests are run
+  with this their runtimes are made available through
+  :func:`stem.util.test_tools.test_runtimes`.
+
+  .. versionadded:: 1.6.0
+  """
+
+  def run(self, test):
+    for t in test._tests:
+      original_type = type(t)
+
+      class _TestWrapper(original_type):
+        def run(self, result = None):
+          start_time = time.time()
+          result = super(type(self), self).run(result)
+          TEST_RUNTIMES[self.id()] = time.time() - start_time
+          return result
+
+        def id(self):
+          return '%s.%s.%s' % (original_type.__module__, original_type.__name__, self._testMethodName)
+
+        def __str__(self):
+          return '%s (%s.%s)' % (self._testMethodName, original_type.__module__, original_type.__name__)
+
+      t.__class__ = _TestWrapper
+
+    return super(TimedTestRunner, self).run(test)
+
+
+def test_runtimes():
+  """
+  Provides the runtimes of tests executed through TimedTestRunners.
+
+  :returns: **dict** of fully qualified test names to floats for the runtime in
+    seconds
+
+  .. versionadded:: 1.6.0
+  """
+
+  return dict(TEST_RUNTIMES)
+
+
 def clean_orphaned_pyc(paths):
   """
   Deletes any file with a \*.pyc extention without a corresponding \*.py. This