From 6fe7cfa50f5f8edb03a87b79d641fc4be8b8df1a Mon Sep 17 00:00:00 2001 From: Rick Harris Date: Tue, 14 Jun 2011 01:21:08 +0000 Subject: [PATCH 1/5] Adds --show-elapsed option for run_tests --- run_tests.py | 82 ++++++++++++++++++++++++++++++++++++++++------------ 1 file changed, 63 insertions(+), 19 deletions(-) diff --git a/run_tests.py b/run_tests.py index d5d8acd1..ace91653 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) + 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(long_result, color) + if self.show_elapsed: + self._writeElapsedTime(test) + self.stream.writeln() + elif self.dots: + 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) - if self.showAll: - self.colorizer.write("OK", 'green') - self.stream.writeln() - elif self.dots: - self.stream.write('.') - self.stream.flush() + 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)) From 969db3d6440e7ecffa55137d765deb6249708df5 Mon Sep 17 00:00:00 2001 From: Rick Harris Date: Tue, 14 Jun 2011 16:39:37 +0000 Subject: [PATCH 2/5] 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 ace91653..3ecc146f 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_ From 483d9bdaaadf2724368e2703e6b462ac189a1102 Mon Sep 17 00:00:00 2001 From: Rick Harris Date: Wed, 15 Jun 2011 00:08:19 +0000 Subject: [PATCH 3/5] Removing seconds unit --- run_tests.py | 24 ++++++++---------------- 1 file changed, 8 insertions(+), 16 deletions(-) diff --git a/run_tests.py b/run_tests.py index 3ecc146f..c29a3da4 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): - 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 + if elapsed_time > 1.0: + return 'red' + elif elapsed_time > 0.25: + return 'yellow' + else: + 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): From f931a0e31d26b13ca9e9f7c1f218f4b0ba34ce92 Mon Sep 17 00:00:00 2001 From: Rick Harris Date: Wed, 15 Jun 2011 01:21:11 +0000 Subject: [PATCH 4/5] Showing elapsed time is now default --- run_tests.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/run_tests.py b/run_tests.py index c29a3da4..601c41e4 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) From 1054258981da6982811b1b848c2fa16495e5a62c Mon Sep 17 00:00:00 2001 From: Rick Harris Date: Wed, 15 Jun 2011 04:05:37 +0000 Subject: [PATCH 5/5] 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 601c41e4..0944bb58 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)