From 435eaf4422c50a37594d4c2d6ba46317c7e102fa Mon Sep 17 00:00:00 2001 From: Victor Stinner Date: Wed, 17 Aug 2016 12:22:52 +0200 Subject: [PATCH] regrtest: nicer output for durations Use milliseconds and minutes units, not only seconds. --- Lib/test/libregrtest/main.py | 31 +++++++++++++++++++------------ Lib/test/test_regrtest.py | 4 ++-- 2 files changed, 21 insertions(+), 14 deletions(-) diff --git a/Lib/test/libregrtest/main.py b/Lib/test/libregrtest/main.py index e503c131acc..edf38b4d175 100644 --- a/Lib/test/libregrtest/main.py +++ b/Lib/test/libregrtest/main.py @@ -34,6 +34,16 @@ else: TEMPDIR = os.path.abspath(TEMPDIR) +def format_duration(seconds): + if seconds < 1.0: + return '%.0f ms' % (seconds * 1e3) + if seconds < 60.0: + return '%.0f sec' % seconds + + minutes, seconds = divmod(seconds, 60.0) + return '%.0f min %.0f sec' % (minutes, seconds) + + class Regrtest: """Execute a test suite. @@ -107,14 +117,6 @@ class Regrtest: self.skipped.append(test) self.resource_denieds.append(test) - def time_delta(self, ceil=False): - seconds = time.monotonic() - self.start_time - if ceil: - seconds = math.ceil(seconds) - else: - seconds = int(seconds) - return datetime.timedelta(seconds=seconds) - def display_progress(self, test_index, test): if self.ns.quiet: return @@ -122,12 +124,14 @@ class Regrtest: fmt = "{time} [{test_index:{count_width}}{test_count}/{nbad}] {test_name}" else: fmt = "{time} [{test_index:{count_width}}{test_count}] {test_name}" + test_time = time.monotonic() - self.start_time + test_time = datetime.timedelta(seconds=int(test_time)) line = fmt.format(count_width=self.test_count_width, test_index=test_index, test_count=self.test_count, nbad=len(self.bad), test_name=test, - time=self.time_delta()) + time=test_time) print(line, flush=True) def parse_args(self, kwargs): @@ -286,9 +290,10 @@ class Regrtest: if self.ns.print_slow: self.test_times.sort(reverse=True) + print() print("10 slowest tests:") for time, test in self.test_times[:10]: - print("%s: %.1fs" % (test, time)) + print("- %s: %s" % (test, format_duration(time))) if self.bad: print(count(len(self.bad), "test"), "failed:") @@ -342,7 +347,7 @@ class Regrtest: previous_test = format_test_result(test, result[0]) test_time = time.monotonic() - start_time if test_time >= PROGRESS_MIN_TIME: - previous_test = "%s in %.0f sec" % (previous_test, test_time) + previous_test = "%s in %s" % (previous_test, format_duration(test_time)) elif result[0] == PASSED: # be quiet: say nothing if the test passed shortly previous_test = None @@ -418,7 +423,9 @@ class Regrtest: r.write_results(show_missing=True, summary=True, coverdir=self.ns.coverdir) - print("Total duration: %s" % self.time_delta(ceil=True)) + print() + duration = time.monotonic() - self.start_time + print("Total duration: %s" % format_duration(duration)) if self.ns.runleaks: os.system("leaks %d" % os.getpid()) diff --git a/Lib/test/test_regrtest.py b/Lib/test/test_regrtest.py index 4a96c6f0697..0b6f2ea5376 100644 --- a/Lib/test/test_regrtest.py +++ b/Lib/test/test_regrtest.py @@ -660,13 +660,13 @@ class ArgsTestCase(BaseTestCase): output = self.run_tests(test, exitcode=1) self.check_executed_tests(output, test, omitted=test) - def test_slow(self): + def test_slowest(self): # test --slowest tests = [self.create_test() for index in range(3)] output = self.run_tests("--slowest", *tests) self.check_executed_tests(output, tests) regex = ('10 slowest tests:\n' - '(?:%s: [0-9]+\.[0-9]+s\n){%s}' + '(?:- %s: .*\n){%s}' % (self.TESTNAME_REGEX, len(tests))) self.check_line(output, regex)