From 56774f9c4938077ce4dd8159f5c770c64804ffb1 Mon Sep 17 00:00:00 2001 From: Azat Khuzhin Date: Wed, 14 Apr 2021 09:08:47 +0300 Subject: [PATCH] clickhouse-test: print database name on failures Useful for debugging, i.e. to distingiush test failures for flaky check --- tests/clickhouse-test | 59 +++++++++++++++++++++++++++++-------------- 1 file changed, 40 insertions(+), 19 deletions(-) diff --git a/tests/clickhouse-test b/tests/clickhouse-test index 5ae894cc55f..d236b01e57a 100755 --- a/tests/clickhouse-test +++ b/tests/clickhouse-test @@ -6,6 +6,7 @@ import os import os.path import re import json +import copy import traceback from argparse import ArgumentParser @@ -113,14 +114,14 @@ def get_db_engine(args, database_name): return " ENGINE=" + args.db_engine return "" # Will use default engine -def run_single_test(args, ext, server_logs_level, client_options, case_file, stdout_file, stderr_file, suite_tmp_dir): - # print(client_options) +def configure_testcase_args(args, case_file, suite_tmp_dir): + testcase_args = copy.deepcopy(args) - client = f"{args.client} --log_comment='{case_file}'" + testcase_args.testcase_start_time = datetime.now() + testcase_args.testcase_client = f"{testcase_args.client} --log_comment='{case_file}'" - start_time = datetime.now() - if args.database: - database = args.database + if testcase_args.database: + database = testcase_args.database os.environ.setdefault("CLICKHOUSE_DATABASE", database) os.environ.setdefault("CLICKHOUSE_TMP", suite_tmp_dir) @@ -132,20 +133,29 @@ def run_single_test(args, ext, server_logs_level, client_options, case_file, std return ''.join(random.choice(alphabet) for _ in range(length)) database = 'test_{suffix}'.format(suffix=random_str()) - clickhouse_proc_create = Popen(shlex.split(client), stdin=PIPE, stdout=PIPE, stderr=None, universal_newlines=True) + clickhouse_proc_create = Popen(shlex.split(testcase_args.testcase_client), stdin=PIPE, stdout=PIPE, stderr=None, universal_newlines=True) try: - clickhouse_proc_create.communicate(("CREATE DATABASE " + database + get_db_engine(args, database)), timeout=args.timeout) + clickhouse_proc_create.communicate(("CREATE DATABASE " + database + get_db_engine(testcase_args, database)), timeout=testcase_args.timeout) except TimeoutExpired: - total_time = (datetime.now() - start_time).total_seconds() + total_time = (datetime.now() - testcase_args.testcase_start_time).total_seconds() return clickhouse_proc_create, "", "Timeout creating database {} before test".format(database), total_time os.environ["CLICKHOUSE_DATABASE"] = database # Set temporary directory to match the randomly generated database, # because .sh tests also use it for temporary files and we want to avoid # collisions. - test_tmp_dir = os.path.join(suite_tmp_dir, database) - os.mkdir(test_tmp_dir) - os.environ.setdefault("CLICKHOUSE_TMP", test_tmp_dir) + testcase_args.test_tmp_dir = os.path.join(suite_tmp_dir, database) + os.mkdir(testcase_args.test_tmp_dir) + os.environ.setdefault("CLICKHOUSE_TMP", testcase_args.test_tmp_dir) + + testcase_args.testcase_database = database + + return testcase_args + +def run_single_test(args, ext, server_logs_level, client_options, case_file, stdout_file, stderr_file): + client = args.client + start_time = args.testcase_start_time + database = args.testcase_database # This is for .sh tests os.environ["CLICKHOUSE_LOG_COMMENT"] = case_file @@ -198,7 +208,7 @@ def run_single_test(args, ext, server_logs_level, client_options, case_file, std total_time = (datetime.now() - start_time).total_seconds() return clickhouse_proc_create, "", "Timeout dropping database {} after test".format(database), total_time - shutil.rmtree(test_tmp_dir) + shutil.rmtree(args.test_tmp_dir) total_time = (datetime.now() - start_time).total_seconds() @@ -391,7 +401,10 @@ def run_tests_array(all_tests_with_params): stdout_file = os.path.join(suite_tmp_dir, name) + file_suffix + '.stdout' stderr_file = os.path.join(suite_tmp_dir, name) + file_suffix + '.stderr' - proc, stdout, stderr, total_time = run_single_test(args, ext, server_logs_level, client_options, case_file, stdout_file, stderr_file, suite_tmp_dir) + + testcase_args = configure_testcase_args(args, case_file, suite_tmp_dir) + + proc, stdout, stderr, total_time = run_single_test(testcase_args, ext, server_logs_level, client_options, case_file, stdout_file, stderr_file) if proc.returncode is None: try: @@ -406,10 +419,11 @@ def run_tests_array(all_tests_with_params): status += " - Timeout!\n" if stderr: status += stderr + status += 'Database: ' + testcase_args.testcase_database else: counter = 1 while need_retry(stderr): - proc, stdout, stderr, total_time = run_single_test(args, ext, server_logs_level, client_options, case_file, stdout_file, stderr_file, suite_tmp_dir) + proc, stdout, stderr, total_time = run_single_test(testcase_args, ext, server_logs_level, client_options, case_file, stdout_file, stderr_file) sleep(2**counter) counter += 1 if counter > 6: @@ -429,7 +443,7 @@ def run_tests_array(all_tests_with_params): if ' ' in stderr: SERVER_DIED = True - if args.stop and ('Connection refused' in stderr or 'Attempt to read after eof' in stderr) and not 'Received exception from server' in stderr: + if testcase_args.stop and ('Connection refused' in stderr or 'Attempt to read after eof' in stderr) and not 'Received exception from server' in stderr: SERVER_DIED = True if os.path.isfile(stdout_file): @@ -438,6 +452,8 @@ def run_tests_array(all_tests_with_params): open(stdout_file).read().split('\n')[:100]) status += '\n' + status += 'Database: ' + testcase_args.testcase_database + elif stderr: failures += 1 failures_chain += 1 @@ -445,6 +461,7 @@ def run_tests_array(all_tests_with_params): status += print_test_time(total_time) status += " - having stderror:\n{}\n".format( '\n'.join(stderr.split('\n')[:100])) + status += 'Database: ' + testcase_args.testcase_database elif 'Exception' in stdout: failures += 1 failures_chain += 1 @@ -452,27 +469,31 @@ def run_tests_array(all_tests_with_params): status += print_test_time(total_time) status += " - having exception:\n{}\n".format( '\n'.join(stdout.split('\n')[:100])) + status += 'Database: ' + testcase_args.testcase_database elif not os.path.isfile(reference_file): status += MSG_UNKNOWN status += print_test_time(total_time) status += " - no reference file\n" + status += 'Database: ' + testcase_args.testcase_database else: result_is_different = subprocess.call(['diff', '-q', reference_file, stdout_file], stdout=PIPE) if result_is_different: - diff = Popen(['diff', '-U', str(args.unified), reference_file, stdout_file], stdout=PIPE, universal_newlines=True).communicate()[0] + diff = Popen(['diff', '-U', str(testcase_args.unified), reference_file, stdout_file], stdout=PIPE, universal_newlines=True).communicate()[0] failures += 1 status += MSG_FAIL status += print_test_time(total_time) status += " - result differs with reference:\n{}\n".format(diff) + status += 'Database: ' + testcase_args.testcase_database else: - if args.test_runs > 1 and total_time > 30 and 'long' not in name: + if testcase_args.test_runs > 1 and total_time > 30 and 'long' not in name: # We're in Flaky Check mode, check the run time as well while we're at it. failures += 1 failures_chain += 1 status += MSG_FAIL status += print_test_time(total_time) status += " - Test runs too long (> 30s). Make it faster." + status += 'Database: ' + testcase_args.testcase_database else: passed_total += 1 failures_chain = 0 @@ -782,7 +803,7 @@ def main(args): all_tests = os.listdir(suite_dir) all_tests = [case for case in all_tests if is_test_from_dir(suite_dir, case)] if args.test: - all_tests = [t for t in all_tests if any([re.search(r, t) for r in args.test])] + all_tests = [t for t in all_tests if any(re.search(r, t) for r in args.test)] all_tests = all_tests * args.test_runs all_tests.sort(key=key_func)