From 00071a6e0bd9bf70d7e7afd1656fea39d5149e68 Mon Sep 17 00:00:00 2001 From: Rick Harris Date: Tue, 14 Jun 2011 01:21:08 +0000 Subject: Adds --show-elapsed option for run_tests --- run_tests.py | 80 ++++++++++++++++++++++++++++++++++++++++++++++-------------- run_tests.sh | 1 + 2 files changed, 63 insertions(+), 18 deletions(-) diff --git a/run_tests.py b/run_tests.py index d5d8acd16..ace916535 100644 --- a/run_tests.py +++ b/run_tests.py @@ -56,9 +56,11 @@ To run a single test module: """ import gettext +import heapq import os import unittest import sys +import time gettext.install('nova', unicode=1) @@ -185,7 +187,10 @@ class _NullColorizer(object): class NovaTestResult(result.TextTestResult): def __init__(self, *args, **kw): + self.show_elapsed = kw.pop('show_elapsed') result.TextTestResult.__init__(self, *args, **kw) + self.num_slow_tests = 5 + self.slow_tests = [] # this is a fixed-sized heap self._last_case = None self.colorizer = None # NOTE(vish): reset stdout for the terminal check @@ -200,25 +205,48 @@ class NovaTestResult(result.TextTestResult): def getDescription(self, test): return str(test) - # NOTE(vish): copied from unittest with edit to add color - def addSuccess(self, test): - unittest.TestResult.addSuccess(self, test) + def _handleElapsedTime(self, test): + self.elapsed_time = time.time() - self.start_time + item = (self.elapsed_time, test) + # Record only the n-slowest tests using heap + if len(self.slow_tests) >= self.num_slow_tests: + heapq.heappushpop(self.slow_tests, item) + else: + heapq.heappush(self.slow_tests, item) + + def _writeElapsedTime(self, test): + if self.elapsed_time >= 3.0: + color = 'red' + elif self.elapsed_time >= 1.0: + color = 'yellow' + else: + color = 'green' + + self.stream.write(' ' * 10) + self.colorizer.write("%.2f" % self.elapsed_time, color) + self.stream.write(' secs') + + def _writeResult(self, test, long_result, color, short_result): if self.showAll: - self.colorizer.write("OK", 'green') + self.colorizer.write(long_result, color) + if self.show_elapsed: + self._writeElapsedTime(test) self.stream.writeln() elif self.dots: - self.stream.write('.') + self.stream.write(short_result) self.stream.flush() + # NOTE(vish): copied from unittest with edit to add color + def addSuccess(self, test): + unittest.TestResult.addSuccess(self, test) + self._handleElapsedTime(test) + self._writeResult(test, 'OK', 'green', '.') + # NOTE(vish): copied from unittest with edit to add color def addFailure(self, test, err): unittest.TestResult.addFailure(self, test, err) - if self.showAll: - self.colorizer.write("FAIL", 'red') - self.stream.writeln() - elif self.dots: - self.stream.write('F') - self.stream.flush() + self._handleElapsedTime(test) + self._writeResult(test, 'FAIL', 'red', 'F') # NOTE(vish): copied from nose with edit to add color def addError(self, test, err): @@ -226,6 +254,7 @@ class NovaTestResult(result.TextTestResult): errorClasses. If the exception is a registered class, the error will be added to the list for that class, not errors. """ + self._handleElapsedTime(test) stream = getattr(self, 'stream', None) ec, ev, tb = err try: @@ -252,14 +281,11 @@ class NovaTestResult(result.TextTestResult): self.errors.append((test, exc_info)) test.passed = False if stream is not None: - if self.showAll: - self.colorizer.write("ERROR", 'red') - self.stream.writeln() - elif self.dots: - stream.write('E') + self._writeResult(test, 'ERROR', 'red', 'E') def startTest(self, test): unittest.TestResult.startTest(self, test) + self.start_time = time.time() current_case = test.test.__class__.__name__ if self.showAll: @@ -273,21 +299,38 @@ class NovaTestResult(result.TextTestResult): class NovaTestRunner(core.TextTestRunner): + def __init__(self, *args, **kwargs): + self.show_elapsed = kwargs.pop('show_elapsed') + core.TextTestRunner.__init__(self, *args, **kwargs) + def _makeResult(self): return NovaTestResult(self.stream, self.descriptions, self.verbosity, - self.config) + self.config, + show_elapsed=self.show_elapsed) + + def run(self, test): + result_ = core.TextTestRunner.run(self, test) + if self.show_elapsed: + self.stream.writeln("Slowest %i tests:" % result_.num_slow_tests) + for elapsed_time, test in reversed(sorted(result_.slow_tests)): + time_str = "%.2f secs" % elapsed_time + self.stream.writeln(" %s %s" % (time_str.ljust(10), test)) + return result_ if __name__ == '__main__': logging.setup() # If any argument looks like a test name but doesn't have "nova.tests" in # front of it, automatically add that so we don't have to type as much + show_elapsed = False argv = [] for x in sys.argv: if x.startswith('test_'): argv.append('nova.tests.%s' % x) + elif x.startswith('--show-elapsed'): + show_elapsed = True else: argv.append(x) @@ -300,5 +343,6 @@ if __name__ == '__main__': runner = NovaTestRunner(stream=c.stream, verbosity=c.verbosity, - config=c) + config=c, + show_elapsed=show_elapsed) sys.exit(not core.run(config=c, testRunner=runner, argv=argv)) diff --git a/run_tests.sh b/run_tests.sh index c7bcd5d67..5fc406035 100755 --- a/run_tests.sh +++ b/run_tests.sh @@ -10,6 +10,7 @@ function usage { echo " -f, --force Force a clean re-build of the virtual environment. Useful when dependencies have been added." echo " -p, --pep8 Just run pep8" echo " -h, --help Print this usage message" + echo " --show-elapsed Print elapsed time for tests along with slowest tests" echo "" echo "Note: with no options specified, the script will try to run the tests in a virtual environment," echo " If no virtualenv is found, the script will ask if you would like to create one. If you " -- cgit From f46c9d7c96d591d1fffe2f45aee3e8d437e016bf Mon Sep 17 00:00:00 2001 From: Rick Harris Date: Tue, 14 Jun 2011 16:39:37 +0000 Subject: Making timing points stricter, only show slow/sluggish tests in summary --- run_tests.py | 44 +++++++++++++++++++++++++++++++------------- 1 file changed, 31 insertions(+), 13 deletions(-) diff --git a/run_tests.py b/run_tests.py index ace916535..3ecc146fd 100644 --- a/run_tests.py +++ b/run_tests.py @@ -185,6 +185,22 @@ class _NullColorizer(object): self.stream.write(text) +def classify_test_speed(elapsed_time): + if elapsed_time > 1.0: + return 'slow' + elif elapsed_time > 0.25: + return 'sluggish' + else: + return 'fast' + + +def get_elapsed_time_color(elapsed_time): + color_map = {'slow': 'red', 'sluggish': 'yellow', 'fast': 'green'} + slowness = classify_test_speed(elapsed_time) + color = color_map[slowness] + return color + + class NovaTestResult(result.TextTestResult): def __init__(self, *args, **kw): self.show_elapsed = kw.pop('show_elapsed') @@ -215,15 +231,8 @@ class NovaTestResult(result.TextTestResult): heapq.heappush(self.slow_tests, item) def _writeElapsedTime(self, test): - if self.elapsed_time >= 3.0: - color = 'red' - elif self.elapsed_time >= 1.0: - color = 'yellow' - else: - color = 'green' - - self.stream.write(' ' * 10) - self.colorizer.write("%.2f" % self.elapsed_time, color) + color = get_elapsed_time_color(self.elapsed_time) + self.colorizer.write(" %.2f" % self.elapsed_time, color) self.stream.write(' secs') def _writeResult(self, test, long_result, color, short_result): @@ -310,13 +319,22 @@ class NovaTestRunner(core.TextTestRunner): self.config, show_elapsed=self.show_elapsed) + def _writeSlowTests(self, result_): + # Pare out 'fast' tests + slow_tests = [item for item in result_.slow_tests + if classify_test_speed(item[0]) != 'fast'] + + slow_total_time = sum(item[0] for item in slow_tests) + self.stream.writeln("Slowest %i tests took %.2f secs:" + % (len(slow_tests), slow_total_time)) + for elapsed_time, test in sorted(slow_tests, reverse=True): + time_str = "%.2f secs" % elapsed_time + self.stream.writeln(" %s %s" % (time_str.ljust(10), test)) + def run(self, test): result_ = core.TextTestRunner.run(self, test) if self.show_elapsed: - self.stream.writeln("Slowest %i tests:" % result_.num_slow_tests) - for elapsed_time, test in reversed(sorted(result_.slow_tests)): - time_str = "%.2f secs" % elapsed_time - self.stream.writeln(" %s %s" % (time_str.ljust(10), test)) + self._writeSlowTests(result_) return result_ -- cgit From 3368a35ff9c06d74ec4b8fdb58d37771fc1a4f0d Mon Sep 17 00:00:00 2001 From: Rick Harris Date: Wed, 15 Jun 2011 00:08:19 +0000 Subject: Removing seconds unit --- run_tests.py | 20 ++++++-------------- run_tests.sh | 2 +- 2 files changed, 7 insertions(+), 15 deletions(-) diff --git a/run_tests.py b/run_tests.py index 3ecc146fd..c29a3da43 100644 --- a/run_tests.py +++ b/run_tests.py @@ -185,20 +185,13 @@ class _NullColorizer(object): self.stream.write(text) -def classify_test_speed(elapsed_time): +def get_elapsed_time_color(elapsed_time): if elapsed_time > 1.0: - return 'slow' + return 'red' elif elapsed_time > 0.25: - return 'sluggish' + return 'yellow' else: - return 'fast' - - -def get_elapsed_time_color(elapsed_time): - color_map = {'slow': 'red', 'sluggish': 'yellow', 'fast': 'green'} - slowness = classify_test_speed(elapsed_time) - color = color_map[slowness] - return color + return 'green' class NovaTestResult(result.TextTestResult): @@ -233,7 +226,6 @@ class NovaTestResult(result.TextTestResult): def _writeElapsedTime(self, test): color = get_elapsed_time_color(self.elapsed_time) self.colorizer.write(" %.2f" % self.elapsed_time, color) - self.stream.write(' secs') def _writeResult(self, test, long_result, color, short_result): if self.showAll: @@ -322,13 +314,13 @@ class NovaTestRunner(core.TextTestRunner): def _writeSlowTests(self, result_): # Pare out 'fast' tests slow_tests = [item for item in result_.slow_tests - if classify_test_speed(item[0]) != 'fast'] + if get_elapsed_time_color(item[0]) != 'green'] slow_total_time = sum(item[0] for item in slow_tests) self.stream.writeln("Slowest %i tests took %.2f secs:" % (len(slow_tests), slow_total_time)) for elapsed_time, test in sorted(slow_tests, reverse=True): - time_str = "%.2f secs" % elapsed_time + time_str = "%.2f" % elapsed_time self.stream.writeln(" %s %s" % (time_str.ljust(10), test)) def run(self, test): diff --git a/run_tests.sh b/run_tests.sh index 5fc406035..90af35579 100755 --- a/run_tests.sh +++ b/run_tests.sh @@ -10,7 +10,7 @@ function usage { echo " -f, --force Force a clean re-build of the virtual environment. Useful when dependencies have been added." echo " -p, --pep8 Just run pep8" echo " -h, --help Print this usage message" - echo " --show-elapsed Print elapsed time for tests along with slowest tests" + echo " --show-elapsed Print elapsed time in seconds for tests along with slowest tests" echo "" echo "Note: with no options specified, the script will try to run the tests in a virtual environment," echo " If no virtualenv is found, the script will ask if you would like to create one. If you " -- cgit From e20444542af9136c330d1cf469eb0e065860ded1 Mon Sep 17 00:00:00 2001 From: Rick Harris Date: Wed, 15 Jun 2011 01:16:53 +0000 Subject: Ensuring pep8 runs even when nose optons are passed --- run_tests.sh | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/run_tests.sh b/run_tests.sh index 90af35579..b90e1e837 100755 --- a/run_tests.sh +++ b/run_tests.sh @@ -25,6 +25,7 @@ function process_option { -N|--no-virtual-env) let always_venv=0; let never_venv=1;; -f|--force) let force=1;; -p|--pep8) let just_pep8=1;; + -*) noseopts="$noseopts $1";; *) noseargs="$noseargs $1" esac } @@ -35,6 +36,7 @@ always_venv=0 never_venv=0 force=0 noseargs= +noseopts= wrapper="" just_pep8=0 @@ -73,7 +75,7 @@ function run_pep8 { --exclude=vcsversion.py ${srcfiles} } -NOSETESTS="python run_tests.py $noseargs" +NOSETESTS="python run_tests.py $noseopts $noseargs" if [ $never_venv -eq 0 ] then @@ -108,7 +110,10 @@ fi run_tests || exit -# Also run pep8 if no options were provided. +# NOTE(sirp): we only want to run pep8 when we're running the full-test suite, +# not when we're running tests individually. To handle this, we need to +# distinguish between options (noseopts), which begin with a '-', and +# arguments (noseargs). if [ -z "$noseargs" ]; then run_pep8 fi -- cgit From 43dd1ec6089497b6e977c49f9006d03c3e7a4117 Mon Sep 17 00:00:00 2001 From: Rick Harris Date: Wed, 15 Jun 2011 01:21:11 +0000 Subject: Showing elapsed time is now default --- run_tests.py | 6 +++--- run_tests.sh | 2 +- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/run_tests.py b/run_tests.py index c29a3da43..601c41e40 100644 --- a/run_tests.py +++ b/run_tests.py @@ -334,13 +334,13 @@ if __name__ == '__main__': logging.setup() # If any argument looks like a test name but doesn't have "nova.tests" in # front of it, automatically add that so we don't have to type as much - show_elapsed = False + show_elapsed = True argv = [] for x in sys.argv: if x.startswith('test_'): argv.append('nova.tests.%s' % x) - elif x.startswith('--show-elapsed'): - show_elapsed = True + elif x.startswith('--hide-elapsed'): + show_elapsed = False else: argv.append(x) diff --git a/run_tests.sh b/run_tests.sh index b90e1e837..c3f06f837 100755 --- a/run_tests.sh +++ b/run_tests.sh @@ -10,7 +10,7 @@ function usage { echo " -f, --force Force a clean re-build of the virtual environment. Useful when dependencies have been added." echo " -p, --pep8 Just run pep8" echo " -h, --help Print this usage message" - echo " --show-elapsed Print elapsed time in seconds for tests along with slowest tests" + echo " --hide-elapsed Don't print the elapsed time for each test along with slow test list" echo "" echo "Note: with no options specified, the script will try to run the tests in a virtual environment," echo " If no virtualenv is found, the script will ask if you would like to create one. If you " -- cgit From 4d5a73bf7cc61d94ac1f29a7566def853d0efb1b Mon Sep 17 00:00:00 2001 From: Rick Harris Date: Wed, 15 Jun 2011 04:05:37 +0000 Subject: Show only if we have slow tests, elapsed only if test success --- run_tests.py | 24 ++++++++++++------------ 1 file changed, 12 insertions(+), 12 deletions(-) diff --git a/run_tests.py b/run_tests.py index 601c41e40..0944bb585 100644 --- a/run_tests.py +++ b/run_tests.py @@ -227,10 +227,10 @@ class NovaTestResult(result.TextTestResult): color = get_elapsed_time_color(self.elapsed_time) self.colorizer.write(" %.2f" % self.elapsed_time, color) - def _writeResult(self, test, long_result, color, short_result): + def _writeResult(self, test, long_result, color, short_result, success): if self.showAll: self.colorizer.write(long_result, color) - if self.show_elapsed: + if self.show_elapsed and success: self._writeElapsedTime(test) self.stream.writeln() elif self.dots: @@ -241,13 +241,13 @@ class NovaTestResult(result.TextTestResult): def addSuccess(self, test): unittest.TestResult.addSuccess(self, test) self._handleElapsedTime(test) - self._writeResult(test, 'OK', 'green', '.') + self._writeResult(test, 'OK', 'green', '.', True) # NOTE(vish): copied from unittest with edit to add color def addFailure(self, test, err): unittest.TestResult.addFailure(self, test, err) self._handleElapsedTime(test) - self._writeResult(test, 'FAIL', 'red', 'F') + self._writeResult(test, 'FAIL', 'red', 'F', False) # NOTE(vish): copied from nose with edit to add color def addError(self, test, err): @@ -282,7 +282,7 @@ class NovaTestResult(result.TextTestResult): self.errors.append((test, exc_info)) test.passed = False if stream is not None: - self._writeResult(test, 'ERROR', 'red', 'E') + self._writeResult(test, 'ERROR', 'red', 'E', False) def startTest(self, test): unittest.TestResult.startTest(self, test) @@ -315,13 +315,13 @@ class NovaTestRunner(core.TextTestRunner): # Pare out 'fast' tests slow_tests = [item for item in result_.slow_tests if get_elapsed_time_color(item[0]) != 'green'] - - slow_total_time = sum(item[0] for item in slow_tests) - self.stream.writeln("Slowest %i tests took %.2f secs:" - % (len(slow_tests), slow_total_time)) - for elapsed_time, test in sorted(slow_tests, reverse=True): - time_str = "%.2f" % elapsed_time - self.stream.writeln(" %s %s" % (time_str.ljust(10), test)) + if slow_tests: + slow_total_time = sum(item[0] for item in slow_tests) + self.stream.writeln("Slowest %i tests took %.2f secs:" + % (len(slow_tests), slow_total_time)) + for elapsed_time, test in sorted(slow_tests, reverse=True): + time_str = "%.2f" % elapsed_time + self.stream.writeln(" %s %s" % (time_str.ljust(10), test)) def run(self, test): result_ = core.TextTestRunner.run(self, test) -- cgit