1# Copyright 2018, The Android Open Source Project 2# 3# Licensed under the Apache License, Version 2.0 (the "License"); 4# you may not use this file except in compliance with the License. 5# You may obtain a copy of the License at 6# 7# http://www.apache.org/licenses/LICENSE-2.0 8# 9# Unless required by applicable law or agreed to in writing, software 10# distributed under the License is distributed on an "AS IS" BASIS, 11# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 12# See the License for the specific language governing permissions and 13# limitations under the License. 14 15# pylint: disable=line-too-long 16 17""" 18Result Reporter 19 20The result reporter formats and prints test results. 21 22---- 23Example Output for command to run following tests: 24CtsAnimationTestCases:EvaluatorTest, HelloWorldTests, and WmTests 25 26Running Tests ... 27 28CtsAnimationTestCases 29--------------------- 30 31android.animation.cts.EvaluatorTest.UnitTests (7 Tests) 32[1/7] android.animation.cts.EvaluatorTest#testRectEvaluator: PASSED (153ms) 33[2/7] android.animation.cts.EvaluatorTest#testIntArrayEvaluator: PASSED (0ms) 34[3/7] android.animation.cts.EvaluatorTest#testIntEvaluator: PASSED (0ms) 35[4/7] android.animation.cts.EvaluatorTest#testFloatArrayEvaluator: PASSED (1ms) 36[5/7] android.animation.cts.EvaluatorTest#testPointFEvaluator: PASSED (1ms) 37[6/7] android.animation.cts.EvaluatorTest#testArgbEvaluator: PASSED (0ms) 38[7/7] android.animation.cts.EvaluatorTest#testFloatEvaluator: PASSED (1ms) 39 40HelloWorldTests 41--------------- 42 43android.test.example.helloworld.UnitTests(2 Tests) 44[1/2] android.test.example.helloworld.HelloWorldTest#testHalloWelt: PASSED (0ms) 45[2/2] android.test.example.helloworld.HelloWorldTest#testHelloWorld: PASSED (1ms) 46 47WmTests 48------- 49 50com.android.tradefed.targetprep.UnitTests (1 Test) 51RUNNER ERROR: com.android.tradefed.targetprep.TargetSetupError: 52Failed to install WmTests.apk on 127.0.0.1:54373. Reason: 53 error message ... 54 55 56Summary 57------- 58CtsAnimationTestCases: Passed: 7, Failed: 0 59HelloWorldTests: Passed: 2, Failed: 0 60WmTests: Passed: 0, Failed: 0 (Completed With ERRORS) 61 621 test failed 63""" 64 65from __future__ import print_function 66 67from collections import OrderedDict 68 69import constants 70import atest_utils as au 71 72from test_runners import test_runner_base 73 74UNSUPPORTED_FLAG = 'UNSUPPORTED_RUNNER' 75FAILURE_FLAG = 'RUNNER_FAILURE' 76BENCHMARK_ESSENTIAL_KEYS = {'repetition_index', 'cpu_time', 'name', 'repetitions', 77 'run_type', 'threads', 'time_unit', 'iterations', 78 'run_name', 'real_time'} 79# TODO(b/146875480): handle the optional benchmark events 80BENCHMARK_OPTIONAL_KEYS = {'bytes_per_second', 'label'} 81BENCHMARK_EVENT_KEYS = BENCHMARK_ESSENTIAL_KEYS.union(BENCHMARK_OPTIONAL_KEYS) 82INT_KEYS = {'cpu_time', 'real_time'} 83 84class PerfInfo(): 85 """Class for storing performance test of a test run.""" 86 87 def __init__(self): 88 """Initialize a new instance of PerfInfo class.""" 89 # perf_info: A list of benchmark_info(dict). 90 self.perf_info = [] 91 92 def update_perf_info(self, test): 93 """Update perf_info with the given result of a single test. 94 95 Args: 96 test: A TestResult namedtuple. 97 """ 98 all_additional_keys = set(test.additional_info.keys()) 99 # Ensure every key is in all_additional_keys. 100 if not BENCHMARK_ESSENTIAL_KEYS.issubset(all_additional_keys): 101 return 102 benchmark_info = {} 103 benchmark_info['test_name'] = test.test_name 104 for key, data in test.additional_info.items(): 105 if key in INT_KEYS: 106 data_to_int = data.split('.')[0] 107 benchmark_info[key] = data_to_int 108 elif key in BENCHMARK_EVENT_KEYS: 109 benchmark_info[key] = data 110 if benchmark_info: 111 self.perf_info.append(benchmark_info) 112 113 def print_perf_info(self): 114 """Print summary of a perf_info.""" 115 if not self.perf_info: 116 return 117 classify_perf_info, max_len = self._classify_perf_info() 118 separator = '-' * au.get_terminal_size()[0] 119 print(separator) 120 print("{:{name}} {:^{real_time}} {:^{cpu_time}} " 121 "{:>{iterations}}".format( 122 'Benchmark', 'Time', 'CPU', 'Iteration', 123 name=max_len['name']+3, 124 real_time=max_len['real_time']+max_len['time_unit']+1, 125 cpu_time=max_len['cpu_time']+max_len['time_unit']+1, 126 iterations=max_len['iterations'])) 127 print(separator) 128 for module_name, module_perf_info in classify_perf_info.items(): 129 print("{}:".format(module_name)) 130 for benchmark_info in module_perf_info: 131 # BpfBenchMark/MapWriteNewEntry/1 1530 ns 1522 ns 460517 132 print(" #{:{name}} {:>{real_time}} {:{time_unit}} " 133 "{:>{cpu_time}} {:{time_unit}} " 134 "{:>{iterations}}".format(benchmark_info['name'], 135 benchmark_info['real_time'], 136 benchmark_info['time_unit'], 137 benchmark_info['cpu_time'], 138 benchmark_info['time_unit'], 139 benchmark_info['iterations'], 140 name=max_len['name'], 141 real_time=max_len['real_time'], 142 time_unit=max_len['time_unit'], 143 cpu_time=max_len['cpu_time'], 144 iterations=max_len['iterations'])) 145 146 def _classify_perf_info(self): 147 """Classify the perf_info by test module name. 148 149 Returns: 150 A tuple of (classified_perf_info, max_len), where 151 classified_perf_info: A dict of perf_info and each perf_info are 152 belong to different modules. 153 e.g. 154 { module_name_01: [perf_info of module_1], 155 module_name_02: [perf_info of module_2], ...} 156 max_len: A dict which stores the max length of each event. 157 It contains the max string length of 'name', real_time', 158 'time_unit', 'cpu_time', 'iterations'. 159 e.g. 160 {name: 56, real_time: 9, time_unit: 2, cpu_time: 8, 161 iterations: 12} 162 """ 163 module_categories = set() 164 max_len = {} 165 all_name = [] 166 all_real_time = [] 167 all_time_unit = [] 168 all_cpu_time = [] 169 all_iterations = ['Iteration'] 170 for benchmark_info in self.perf_info: 171 module_categories.add(benchmark_info['test_name'].split('#')[0]) 172 all_name.append(benchmark_info['name']) 173 all_real_time.append(benchmark_info['real_time']) 174 all_time_unit.append(benchmark_info['time_unit']) 175 all_cpu_time.append(benchmark_info['cpu_time']) 176 all_iterations.append(benchmark_info['iterations']) 177 classified_perf_info = {} 178 for module_name in module_categories: 179 module_perf_info = [] 180 for benchmark_info in self.perf_info: 181 if benchmark_info['test_name'].split('#')[0] == module_name: 182 module_perf_info.append(benchmark_info) 183 classified_perf_info[module_name] = module_perf_info 184 max_len = {'name': len(max(all_name, key=len)), 185 'real_time': len(max(all_real_time, key=len)), 186 'time_unit': len(max(all_time_unit, key=len)), 187 'cpu_time': len(max(all_cpu_time, key=len)), 188 'iterations': len(max(all_iterations, key=len))} 189 return classified_perf_info, max_len 190 191 192class RunStat: 193 """Class for storing stats of a test run.""" 194 195 def __init__(self, passed=0, failed=0, ignored=0, run_errors=False, 196 assumption_failed=0): 197 """Initialize a new instance of RunStat class. 198 199 Args: 200 passed: Count of passing tests. 201 failed: Count of failed tests. 202 ignored: Count of ignored tests. 203 assumption_failed: Count of assumption failure tests. 204 run_errors: A boolean if there were run errors 205 """ 206 # TODO(b/109822985): Track group and run estimated totals for updating 207 # summary line 208 self.passed = passed 209 self.failed = failed 210 self.ignored = ignored 211 self.assumption_failed = assumption_failed 212 self.perf_info = PerfInfo() 213 # Run errors are not for particular tests, they are runner errors. 214 self.run_errors = run_errors 215 216 @property 217 def total(self): 218 """Getter for total tests actually ran. Accessed via self.total""" 219 return self.passed + self.failed 220 221 222class ResultReporter: 223 """Result Reporter class. 224 225 As each test is run, the test runner will call self.process_test_result() 226 with a TestResult namedtuple that contains the following information: 227 - runner_name: Name of the test runner 228 - group_name: Name of the test group if any. 229 In Tradefed that's the Module name. 230 - test_name: Name of the test. 231 In Tradefed that's qualified.class#Method 232 - status: The strings FAILED or PASSED. 233 - stacktrace: The stacktrace if the test failed. 234 - group_total: The total tests scheduled to be run for a group. 235 In Tradefed this is provided when the Module starts. 236 - runner_total: The total tests scheduled to be run for the runner. 237 In Tradefed this is not available so is None. 238 239 The Result Reporter will print the results of this test and then update 240 its stats state. 241 242 Test stats are stored in the following structure: 243 - self.run_stats: Is RunStat instance containing stats for the overall run. 244 This include pass/fail counts across ALL test runners. 245 246 - self.runners: Is of the form: {RunnerName: {GroupName: RunStat Instance}} 247 Where {} is an ordered dict. 248 249 The stats instance contains stats for each test group. 250 If the runner doesn't support groups, then the group 251 name will be None. 252 253 For example this could be a state of ResultReporter: 254 255 run_stats: RunStat(passed:10, failed:5) 256 runners: {'AtestTradefedTestRunner': 257 {'Module1': RunStat(passed:1, failed:1), 258 'Module2': RunStat(passed:0, failed:4)}, 259 'RobolectricTestRunner': {None: RunStat(passed:5, failed:0)}, 260 'VtsTradefedTestRunner': {'Module1': RunStat(passed:4, failed:0)}} 261 """ 262 263 def __init__(self, silent=False): 264 """Init ResultReporter. 265 266 Args: 267 silent: A boolean of silence or not. 268 """ 269 self.run_stats = RunStat() 270 self.runners = OrderedDict() 271 self.failed_tests = [] 272 self.all_test_results = [] 273 self.pre_test = None 274 self.log_path = None 275 self.silent = silent 276 self.rerun_options = '' 277 278 def process_test_result(self, test): 279 """Given the results of a single test, update stats and print results. 280 281 Args: 282 test: A TestResult namedtuple. 283 """ 284 if test.runner_name not in self.runners: 285 self.runners[test.runner_name] = OrderedDict() 286 assert self.runners[test.runner_name] != FAILURE_FLAG 287 self.all_test_results.append(test) 288 if test.group_name not in self.runners[test.runner_name]: 289 self.runners[test.runner_name][test.group_name] = RunStat() 290 self._print_group_title(test) 291 self._update_stats(test, 292 self.runners[test.runner_name][test.group_name]) 293 self._print_result(test) 294 295 def runner_failure(self, runner_name, failure_msg): 296 """Report a runner failure. 297 298 Use instead of process_test_result() when runner fails separate from 299 any particular test, e.g. during setup of runner. 300 301 Args: 302 runner_name: A string of the name of the runner. 303 failure_msg: A string of the failure message to pass to user. 304 """ 305 self.runners[runner_name] = FAILURE_FLAG 306 print('\n', runner_name, '\n', '-' * len(runner_name), sep='') 307 print('Runner encountered a critical failure. Skipping.\n' 308 'FAILURE: %s' % failure_msg) 309 310 def register_unsupported_runner(self, runner_name): 311 """Register an unsupported runner. 312 313 Prints the following to the screen: 314 315 RunnerName 316 ---------- 317 This runner does not support normal results formatting. 318 Below is the raw output of the test runner. 319 320 RAW OUTPUT: 321 <Raw Runner Output> 322 323 Args: 324 runner_name: A String of the test runner's name. 325 """ 326 assert runner_name not in self.runners 327 self.runners[runner_name] = UNSUPPORTED_FLAG 328 print('\n', runner_name, '\n', '-' * len(runner_name), sep='') 329 print('This runner does not support normal results formatting. Below ' 330 'is the raw output of the test runner.\n\nRAW OUTPUT:') 331 332 def print_starting_text(self): 333 """Print starting text for running tests.""" 334 print(au.colorize('\nRunning Tests...', constants.CYAN)) 335 336 def print_summary(self, is_collect_tests_only=False): 337 """Print summary of all test runs. 338 339 Args: 340 is_collect_tests_only: A boolean of collect_tests_only. 341 342 Returns: 343 0 if all tests pass, non-zero otherwise. 344 345 """ 346 if is_collect_tests_only: 347 return self.print_collect_tests() 348 tests_ret = constants.EXIT_CODE_SUCCESS 349 if not self.runners: 350 return tests_ret 351 print('\n{}'.format(au.colorize('Summary', constants.CYAN))) 352 print(au.delimiter('-', 7)) 353 if self.rerun_options: 354 print(self.rerun_options) 355 failed_sum = len(self.failed_tests) 356 for runner_name, groups in self.runners.items(): 357 if groups == UNSUPPORTED_FLAG: 358 print(runner_name, 'Unsupported. See raw output above.') 359 continue 360 if groups == FAILURE_FLAG: 361 tests_ret = constants.EXIT_CODE_TEST_FAILURE 362 print(runner_name, 'Crashed. No results to report.') 363 failed_sum += 1 364 continue 365 for group_name, stats in groups.items(): 366 name = group_name if group_name else runner_name 367 summary = self.process_summary(name, stats) 368 if stats.failed > 0: 369 tests_ret = constants.EXIT_CODE_TEST_FAILURE 370 if stats.run_errors: 371 tests_ret = constants.EXIT_CODE_TEST_FAILURE 372 failed_sum += 1 if not stats.failed else 0 373 print(summary) 374 self.run_stats.perf_info.print_perf_info() 375 print() 376 if tests_ret == constants.EXIT_CODE_SUCCESS: 377 print(au.colorize('All tests passed!', constants.GREEN)) 378 else: 379 message = '%d %s failed' % (failed_sum, 380 'tests' if failed_sum > 1 else 'test') 381 print(au.colorize(message, constants.RED)) 382 print('-'*len(message)) 383 self.print_failed_tests() 384 if self.log_path: 385 print('Test Logs have saved in %s' % self.log_path) 386 return tests_ret 387 388 def print_collect_tests(self): 389 """Print summary of collect tests only. 390 391 Returns: 392 0 if all tests collection done. 393 394 """ 395 tests_ret = constants.EXIT_CODE_SUCCESS 396 if not self.runners: 397 return tests_ret 398 print('\n{}'.format(au.colorize('Summary:' + constants.COLLECT_TESTS_ONLY, 399 constants.CYAN))) 400 print(au.delimiter('-', 26)) 401 for runner_name, groups in self.runners.items(): 402 for group_name, _ in groups.items(): 403 name = group_name if group_name else runner_name 404 print(name) 405 print() 406 if self.log_path: 407 print('Test Logs have saved in %s' % self.log_path) 408 return constants.EXIT_CODE_SUCCESS 409 410 def print_failed_tests(self): 411 """Print the failed tests if existed.""" 412 if self.failed_tests: 413 for test_name in self.failed_tests: 414 print('%s' % test_name) 415 416 def process_summary(self, name, stats): 417 """Process the summary line. 418 419 Strategy: 420 Error status happens -> 421 SomeTests: Passed: 2, Failed: 0 <red>(Completed With ERRORS)</red> 422 SomeTests: Passed: 2, <red>Failed</red>: 2 <red>(Completed With ERRORS)</red> 423 More than 1 test fails -> 424 SomeTests: Passed: 2, <red>Failed</red>: 5 425 No test fails -> 426 SomeTests: <green>Passed</green>: 2, Failed: 0 427 428 Args: 429 name: A string of test name. 430 stats: A RunStat instance for a test group. 431 432 Returns: 433 A summary of the test result. 434 """ 435 passed_label = 'Passed' 436 failed_label = 'Failed' 437 ignored_label = 'Ignored' 438 assumption_failed_label = 'Assumption Failed' 439 error_label = '' 440 if stats.failed > 0: 441 failed_label = au.colorize(failed_label, constants.RED) 442 if stats.run_errors: 443 error_label = au.colorize('(Completed With ERRORS)', constants.RED) 444 elif stats.failed == 0: 445 passed_label = au.colorize(passed_label, constants.GREEN) 446 summary = '%s: %s: %s, %s: %s, %s: %s, %s: %s %s' % (name, 447 passed_label, 448 stats.passed, 449 failed_label, 450 stats.failed, 451 ignored_label, 452 stats.ignored, 453 assumption_failed_label, 454 stats.assumption_failed, 455 error_label) 456 return summary 457 458 def _update_stats(self, test, group): 459 """Given the results of a single test, update test run stats. 460 461 Args: 462 test: a TestResult namedtuple. 463 group: a RunStat instance for a test group. 464 """ 465 # TODO(109822985): Track group and run estimated totals for updating 466 # summary line 467 if test.status == test_runner_base.PASSED_STATUS: 468 self.run_stats.passed += 1 469 group.passed += 1 470 elif test.status == test_runner_base.IGNORED_STATUS: 471 self.run_stats.ignored += 1 472 group.ignored += 1 473 elif test.status == test_runner_base.ASSUMPTION_FAILED: 474 self.run_stats.assumption_failed += 1 475 group.assumption_failed += 1 476 elif test.status == test_runner_base.FAILED_STATUS: 477 self.run_stats.failed += 1 478 self.failed_tests.append(test.test_name) 479 group.failed += 1 480 elif test.status == test_runner_base.ERROR_STATUS: 481 self.run_stats.run_errors = True 482 group.run_errors = True 483 self.run_stats.perf_info.update_perf_info(test) 484 485 def _print_group_title(self, test): 486 """Print the title line for a test group. 487 488 Test Group/Runner Name 489 ---------------------- 490 491 Args: 492 test: A TestResult namedtuple. 493 """ 494 if self.silent: 495 return 496 title = test.group_name or test.runner_name 497 underline = '-' * (len(title)) 498 print('\n%s\n%s' % (title, underline)) 499 500 def _print_result(self, test): 501 """Print the results of a single test. 502 503 Looks like: 504 fully.qualified.class#TestMethod: PASSED/FAILED 505 506 Args: 507 test: a TestResult namedtuple. 508 """ 509 if self.silent: 510 return 511 if not self.pre_test or (test.test_run_name != 512 self.pre_test.test_run_name): 513 print('%s (%s %s)' % (au.colorize(test.test_run_name, 514 constants.BLUE), 515 test.group_total, 516 'Test' if test.group_total <= 1 else 'Tests')) 517 if test.status == test_runner_base.ERROR_STATUS: 518 print('RUNNER ERROR: %s\n' % test.details) 519 self.pre_test = test 520 return 521 if test.test_name: 522 if test.status == test_runner_base.PASSED_STATUS: 523 # Example of output: 524 # [78/92] test_name: PASSED (92ms) 525 print('[%s/%s] %s: %s %s' % (test.test_count, 526 test.group_total, 527 test.test_name, 528 au.colorize( 529 test.status, 530 constants.GREEN), 531 test.test_time)) 532 for key, data in test.additional_info.items(): 533 if key not in BENCHMARK_EVENT_KEYS: 534 print('\t%s: %s' % (au.colorize(key, constants.BLUE), data)) 535 elif test.status == test_runner_base.IGNORED_STATUS: 536 # Example: [33/92] test_name: IGNORED (12ms) 537 print('[%s/%s] %s: %s %s' % (test.test_count, test.group_total, 538 test.test_name, au.colorize( 539 test.status, constants.MAGENTA), 540 test.test_time)) 541 elif test.status == test_runner_base.ASSUMPTION_FAILED: 542 # Example: [33/92] test_name: ASSUMPTION_FAILED (12ms) 543 print('[%s/%s] %s: %s %s' % (test.test_count, test.group_total, 544 test.test_name, au.colorize( 545 test.status, constants.MAGENTA), 546 test.test_time)) 547 else: 548 # Example: [26/92] test_name: FAILED (32ms) 549 print('[%s/%s] %s: %s %s' % (test.test_count, test.group_total, 550 test.test_name, au.colorize( 551 test.status, constants.RED), 552 test.test_time)) 553 if test.status == test_runner_base.FAILED_STATUS: 554 print('\nSTACKTRACE:\n%s' % test.details) 555 self.pre_test = test 556