diff --git a/engine/src/flutter/testing/run_tests.py b/engine/src/flutter/testing/run_tests.py index a22579b6e0c..4f75b6e5492 100755 --- a/engine/src/flutter/testing/run_tests.py +++ b/engine/src/flutter/testing/run_tests.py @@ -13,12 +13,17 @@ from pathlib import Path import argparse import errno import glob +import logging +import logging.handlers import multiprocessing import os import re import shutil import subprocess -import sys +# Explicitly import the parts of sys that are needed. This is to avoid using +# sys.stdout and sys.stderr directly. Instead, only the logger defined below +# should be used for output. +from sys import exit as sys_exit, platform as sys_platform import tempfile import time import typing @@ -39,12 +44,20 @@ FONT_SUBSET_DIR = os.path.join(BUILDROOT_DIR, 'flutter', 'tools', 'font-subset') FML_UNITTESTS_FILTER = '--gtest_filter=-*TimeSensitiveTest*' ENCODING = 'UTF-8' +logger = logging.getLogger(__name__) +logger_handler = logging.StreamHandler() + + +# Override print so that it uses the logger instead of stdout directly. +def print(*args, **kwargs): # pylint: disable=redefined-builtin + logger.info(*args, **kwargs) + def print_divider(char='='): - print('\n') + logger.info('\n') for _ in range(4): - print(''.join([char for _ in range(80)])) - print('\n') + logger.info(''.join([char for _ in range(80)])) + logger.info('\n') def is_asan(build_dir): @@ -71,7 +84,7 @@ def run_cmd( command_string = ' '.join(cmd) print_divider('>') - print(f'Running command "{command_string}"') + logger.info('Running command "%s"', command_string) start_time = time.time() @@ -87,17 +100,17 @@ def run_cmd( for line in iter(process.stdout.readline, ''): output += line - sys.stdout.write(line) + logger.info(line.rstrip()) - sys.stdout.flush() process.wait() end_time = time.time() if process.returncode != 0 and not expect_failure: print_divider('!') - print( - f'Failed Command:\n\n{command_string}\n\nExit Code: {process.returncode}\n' + logger.error( + 'Failed Command:\n\n%s\n\nExit Code: %s\n\nOutput:\n%s', command_string, + process.returncode, output ) print_divider('!') @@ -109,23 +122,26 @@ def run_cmd( if not allowed_failure: raise RuntimeError( - f'Command "{command_string}" exited with code {process.returncode}.' + 'Command "%s" exited with code %s.' % + (command_string, process.returncode) ) for forbidden_string in forbidden_output: if forbidden_string in output: raise RuntimeError( - f'command "{command_string}" contained forbidden string {forbidden_string}' + 'command "%s" contained forbidden string "%s"' % + (command_string, forbidden_string) ) print_divider('<') - print( - f'Command run successfully in {end_time - start_time:.2f} seconds: {command_string}' + logger.info( + 'Command run successfully in %.2f seconds: %s', end_time - start_time, + command_string ) def is_mac(): - return sys.platform == 'darwin' + return sys_platform == 'darwin' def is_aarm64(): @@ -139,11 +155,11 @@ def is_aarm64(): def is_linux(): - return sys.platform.startswith('linux') + return sys_platform.startswith('linux') def is_windows(): - return sys.platform.startswith(('cygwin', 'win')) + return sys_platform.startswith(('cygwin', 'win')) def executable_suffix(): @@ -217,7 +233,7 @@ def run_engine_executable( # pylint: disable=too-many-arguments gtest=False, ): if executable_filter is not None and executable_name not in executable_filter: - print('Skipping %s due to filter.' % executable_name) + logger.info('Skipping %s due to filter.', executable_name) return if flags is None: @@ -250,7 +266,7 @@ def run_engine_executable( # pylint: disable=too-many-arguments else: env['PATH'] = build_dir + ':' + env['PATH'] - print('Running %s in %s' % (executable_name, cwd)) + logger.info('Running %s in %s', executable_name, cwd) test_command = build_engine_executable_command( build_dir, @@ -283,9 +299,9 @@ def run_engine_executable( # pylint: disable=too-many-arguments if luci_test_outputs_path and os.path.exists(core_path) and os.path.exists( unstripped_exe): dump_path = os.path.join( - luci_test_outputs_path, '%s_%s.txt' % (executable_name, sys.platform) + luci_test_outputs_path, '%s_%s.txt' % (executable_name, sys_platform) ) - print('Writing core dump analysis to %s' % dump_path) + logger.error('Writing core dump analysis to %s', dump_path) subprocess.call([ os.path.join( BUILDROOT_DIR, 'flutter', 'testing', 'analyze_core_dump.sh' @@ -356,7 +372,7 @@ shuffle_flags = [ def run_cc_tests(build_dir, executable_filter, coverage, capture_core_dump): - print('Running Engine Unit-tests.') + logger.info('Running Engine Unit-tests.') if capture_core_dump and is_linux(): import resource # pylint: disable=import-outside-toplevel @@ -510,7 +526,7 @@ def run_cc_tests(build_dir, executable_filter, coverage, capture_core_dump): def run_engine_benchmarks(build_dir, executable_filter): - print('Running Engine Benchmarks.') + logger.info('Running Engine Benchmarks.') icu_flags = [ '--icu-data-file-path=%s' % os.path.join(build_dir, 'icudtl.dat') @@ -583,9 +599,9 @@ def gather_dart_test( threading = 'single-threaded' tester_name = 'flutter_tester' - print( - "Running test '%s' using '%s' (%s)" % - (kernel_file_name, tester_name, threading) + logger.info( + "Running test '%s' using '%s' (%s)", kernel_file_name, tester_name, + threading ) forbidden_output = [] if 'unopt' in build_dir or expect_failure else [ '[ERROR' @@ -810,10 +826,10 @@ def gather_dart_tests(build_dir, test_filter): for dart_test_file in dart_observatory_tests: if test_filter is not None and os.path.basename(dart_test_file ) not in test_filter: - print("Skipping '%s' due to filter." % dart_test_file) + logger.info("Skipping '%s' due to filter.", dart_test_file) else: - print( - "Gathering dart test '%s' with observatory enabled" % dart_test_file + logger.info( + "Gathering dart test '%s' with observatory enabled", dart_test_file ) yield gather_dart_test(build_dir, dart_test_file, True, True) yield gather_dart_test(build_dir, dart_test_file, False, True) @@ -821,9 +837,9 @@ def gather_dart_tests(build_dir, test_filter): for dart_test_file in dart_tests: if test_filter is not None and os.path.basename(dart_test_file ) not in test_filter: - print("Skipping '%s' due to filter." % dart_test_file) + logger.info("Skipping '%s' due to filter.", dart_test_file) else: - print("Gathering dart test '%s'" % dart_test_file) + logger.info("Gathering dart test '%s'", dart_test_file) yield gather_dart_test(build_dir, dart_test_file, True) yield gather_dart_test(build_dir, dart_test_file, False) @@ -1053,6 +1069,13 @@ def gather_ci_tests(build_dir): ) +def worker_init(queue, level): + queue_handler = logging.handlers.QueueHandler(queue) + log = logging.getLogger(__name__) + log.setLevel(level) + log.addHandler(queue_handler) + + def run_engine_tasks_in_parallel(tasks): # Work around a bug in Python. # @@ -1064,23 +1087,33 @@ def run_engine_tasks_in_parallel(tasks): # # See: https://bugs.python.org/issue26903 max_processes = multiprocessing.cpu_count() - if sys.platform.startswith(('cygwin', 'win')) and max_processes > 60: + if sys_platform.startswith(('cygwin', 'win')) and max_processes > 60: max_processes = 60 - pool = multiprocessing.Pool(processes=max_processes) - async_results = [(t, pool.apply_async(t, ())) for t in tasks] + queue = multiprocessing.Queue() + queue_listener = logging.handlers.QueueListener(queue, logger_handler) + queue_listener.start() + failures = [] - for task, async_result in async_results: - try: - async_result.get() - except Exception as exn: # pylint: disable=broad-except - failures += [(task, exn)] + try: + with multiprocessing.Pool(max_processes, worker_init, + [queue, logger.getEffectiveLevel()]) as pool: + async_results = [(t, pool.apply_async(t, ())) for t in tasks] + for task, async_result in async_results: + try: + async_result.get() + except Exception as exn: # pylint: disable=broad-except + failures += [(task, exn)] + finally: + queue_listener.stop() if len(failures) > 0: - print('The following commands failed:') + logger.error('The following commands failed:') for task, exn in failures: - print('%s\n%s\n' % (str(task), str(exn))) - raise Exception() + logger.error('%s\n', str(task)) + return False + + return True class DirectoryChange(): @@ -1230,9 +1263,20 @@ Flutter Wiki page on the subject: https://github.com/flutter/flutter/wiki/Testin default=None, help='Provide the path of adb used for android tests. By default it looks on $PATH.' ) + parser.add_argument( + '--quiet', + dest='quiet', + action='store_true', + default=False, + help='Only emit output when there is an error.' + ) args = parser.parse_args() + logger.addHandler(logger_handler) + if not args.quiet: + logger.setLevel(logging.INFO) + if args.type == 'all': types = all_types else: @@ -1259,6 +1303,8 @@ Flutter Wiki page on the subject: https://github.com/flutter/flutter/wiki/Testin os.environ[key] = value process.communicate() # Avoid pipe deadlock while waiting for termination. + success = True + engine_filter = args.engine_filter.split(',') if args.engine_filter else None if 'engine' in types: run_cc_tests( @@ -1296,14 +1342,14 @@ Flutter Wiki page on the subject: https://github.com/flutter/flutter/wiki/Testin tasks += list(gather_front_end_server_tests(build_dir)) tasks += list(gather_ci_tests(build_dir)) tasks += list(gather_dart_tests(build_dir, dart_filter)) - run_engine_tasks_in_parallel(tasks) + success = success and run_engine_tasks_in_parallel(tasks) if 'java' in types: assert not is_windows( ), "Android engine files can't be compiled on Windows." java_filter = args.java_filter if ',' in java_filter or '*' in java_filter: - print( + logger.wraning( 'Can only filter JUnit4 tests by single entire class name, ' 'eg "io.flutter.SmokeTest". Ignoring filter=' + java_filter ) @@ -1332,6 +1378,8 @@ Flutter Wiki page on the subject: https://github.com/flutter/flutter/wiki/Testin if 'impeller-golden' in types: run_impeller_golden_tests(build_dir) + return 0 if success else 1 + if __name__ == '__main__': - sys.exit(main()) + sys_exit(main())