diff --git a/lib/test.py b/lib/test.py index 0f002802..a3370e50 100644 --- a/lib/test.py +++ b/lib/test.py @@ -5,11 +5,13 @@ import re import shutil import sys +import time import traceback from functools import partial from hashlib import md5 from lib import Options +from lib.colorer import color_log from lib.colorer import color_stdout from lib.utils import assert_bytes from lib.utils import non_empty_valgrind_logs @@ -130,6 +132,7 @@ def __init__(self, name, args, suite_ini, params={}, conf_name=None): self.is_terminated = False self.run_params = params self.conf_name = conf_name + self.started_time = 0.0 # filled in execute() when a greenlet runs self.current_test_greenlet = None @@ -185,6 +188,7 @@ def run(self, server): sys.stdout.close() sys.stdout = save_stdout if not self.skip: + self.started_time = time.time() sys.stdout = FilteredStream(self.tmp_result) stdout_fileno = sys.stdout.stream.fileno() self.execute(server) @@ -232,6 +236,7 @@ def run(self, server): short_status = None result_checksum = None + test_timing = round(time.time() - self.started_time, 2) if self.skip: short_status = 'skip' @@ -242,7 +247,7 @@ def run(self, server): self.is_equal_result and self.is_valgrind_clean): short_status = 'pass' - color_stdout("[ pass ]\n", schema='test_pass') + color_stdout("[ pass ] [ {} ]\n" . format(test_timing), schema='test_pass') if os.path.exists(self.tmp_result): os.remove(self.tmp_result) elif (self.is_executed_ok and @@ -269,7 +274,7 @@ def run(self, server): with open(self.tmp_result, mode='rb') as result_file: result_checksum = md5(result_file.read()).hexdigest() short_status = 'fail' - color_stdout("[ fail ]\n", schema='test_fail') + color_stdout("[ fail ] [ {} ]\n" . format(test_timing), schema='test_fail') where = "" if not self.is_crash_reported and not has_result: @@ -293,6 +298,8 @@ def run(self, server): "Test failed! Output from log file " "{0}:\n".format(log_file)) where = ": there were warnings in the valgrind log file(s)" + color_log("TEST:CONF TIMING: {}:{} {}\n" . format(self.name, self.conf_name, test_timing), + schema='log') return short_status, result_checksum def print_diagnostics(self, log_file, message): diff --git a/test-run.py b/test-run.py index 0b90494e..9b0a4cf1 100755 --- a/test-run.py +++ b/test-run.py @@ -107,18 +107,19 @@ def main_loop_parallel(): print_greetings() - color_stdout("\n", '=' * 86, "\n", schema='separator') + color_stdout("\n", '=' * 96, "\n", schema='separator') color_stdout("WORKR".ljust(6), schema='t_name') color_stdout("TEST".ljust(48), schema='t_name') color_stdout("PARAMS".ljust(16), schema='test_var') - color_stdout("RESULT\n", schema='test_pass') - color_stdout('-' * 81, "\n", schema='separator') + color_stdout("RESULT".ljust(9), schema='test_pass') + color_stdout("TIMING\n", schema='test_pass') + color_stdout('-' * 91, "\n", schema='separator') try: is_force = Options().args.is_force dispatcher.wait() dispatcher.wait_processes() - color_stdout('-' * 81, "\n", schema='separator') + color_stdout('-' * 91, "\n", schema='separator') has_failed = dispatcher.statistics.print_statistics() has_undone = dispatcher.report_undone( verbose=bool(is_force or not has_failed)) @@ -128,12 +129,12 @@ def main_loop_parallel(): if has_undone: return EXIT_NOTDONE_TEST except KeyboardInterrupt: - color_stdout('-' * 81, "\n", schema='separator') + color_stdout('-' * 91, "\n", schema='separator') dispatcher.statistics.print_statistics() dispatcher.report_undone(verbose=False) raise except HangError: - color_stdout('-' * 81, "\n", schema='separator') + color_stdout('-' * 91, "\n", schema='separator') dispatcher.statistics.print_statistics() dispatcher.report_undone(verbose=False) return EXIT_HANG