1 #!/usr/bin/env python3.4 2 # 3 # Copyright 2016 - The Android Open Source Project 4 # 5 # Licensed under the Apache License, Version 2.0 (the "License"); 6 # you may not use this file except in compliance with the License. 7 # You may obtain a copy of the License at 8 # 9 # http://www.apache.org/licenses/LICENSE-2.0 10 # 11 # Unless required by applicable law or agreed to in writing, software 12 # distributed under the License is distributed on an "AS IS" BASIS, 13 # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 14 # See the License for the specific language governing permissions and 15 # limitations under the License. 16 import logging 17 import os 18 import traceback 19 from concurrent.futures import ThreadPoolExecutor 20 21 from acts import asserts 22 from acts import keys 23 from acts import logger 24 from acts import records 25 from acts import signals 26 from acts import tracelogger 27 from acts import utils 28 29 # Macro strings for test result reporting 30 TEST_CASE_TOKEN = "[Test Case]" 31 RESULT_LINE_TEMPLATE = TEST_CASE_TOKEN + " %s %s" 32 33 34 class Error(Exception): 35 """Raised for exceptions that occured in BaseTestClass.""" 36 37 38 class BaseTestClass(object): 39 """Base class for all test classes to inherit from. 40 41 This class gets all the controller objects from test_runner and executes 42 the test cases requested within itself. 43 44 Most attributes of this class are set at runtime based on the configuration 45 provided. 46 47 Attributes: 48 tests: A list of strings, each representing a test case name. 49 TAG: A string used to refer to a test class. Default is the test class 50 name. 51 log: A logger object used for logging. 52 results: A records.TestResult object for aggregating test results from 53 the execution of test cases. 54 current_test_name: A string that's the name of the test case currently 55 being executed. If no test is executing, this should 56 be None. 57 """ 58 59 TAG = None 60 61 def __init__(self, configs): 62 self.tests = [] 63 if not self.TAG: 64 self.TAG = self.__class__.__name__ 65 # Set all the controller objects and params. 66 for name, value in configs.items(): 67 setattr(self, name, value) 68 self.results = records.TestResult() 69 self.current_test_name = None 70 self.log = tracelogger.TraceLogger(self.log) 71 self.size_limit_reached = False 72 if 'android_devices' in self.__dict__: 73 for ad in self.android_devices: 74 if ad.droid: 75 utils.set_location_service(ad, False) 76 utils.sync_device_time(ad) 77 78 def __enter__(self): 79 return self 80 81 def __exit__(self, *args): 82 self._exec_func(self.clean_up) 83 84 def unpack_userparams(self, 85 req_param_names=[], 86 opt_param_names=[], 87 **kwargs): 88 """An optional function that unpacks user defined parameters into 89 individual variables. 90 91 After unpacking, the params can be directly accessed with self.xxx. 92 93 If a required param is not provided, an exception is raised. If an 94 optional param is not provided, a warning line will be logged. 95 96 To provide a param, add it in the config file or pass it in as a kwarg. 97 If a param appears in both the config file and kwarg, the value in the 98 config file is used. 99 100 User params from the config file can also be directly accessed in 101 self.user_params. 102 103 Args: 104 req_param_names: A list of names of the required user params. 105 opt_param_names: A list of names of the optional user params. 106 **kwargs: Arguments that provide default values. 107 e.g. unpack_userparams(required_list, opt_list, arg_a="hello") 108 self.arg_a will be "hello" unless it is specified again in 109 required_list or opt_list. 110 111 Raises: 112 Error is raised if a required user params is not provided. 113 """ 114 for k, v in kwargs.items(): 115 if k in self.user_params: 116 v = self.user_params[k] 117 setattr(self, k, v) 118 for name in req_param_names: 119 if hasattr(self, name): 120 continue 121 if name not in self.user_params: 122 raise Error(("Missing required user param '%s' in test " 123 "configuration.") % name) 124 setattr(self, name, self.user_params[name]) 125 for name in opt_param_names: 126 if hasattr(self, name): 127 continue 128 if name in self.user_params: 129 setattr(self, name, self.user_params[name]) 130 else: 131 self.log.warning(("Missing optional user param '%s' in " 132 "configuration, continue."), name) 133 134 capablity_of_devices = utils.CapablityPerDevice 135 if "additional_energy_info_models" in self.user_params: 136 self.energy_info_models = (capablity_of_devices.energy_info_models 137 + self.additional_energy_info_models) 138 else: 139 self.energy_info_models = capablity_of_devices.energy_info_models 140 self.user_params["energy_info_models"] = self.energy_info_models 141 142 if "additional_tdls_models" in self.user_params: 143 self.tdls_models = (capablity_of_devices.energy_info_models + 144 self.additional_tdls_models) 145 else: 146 self.tdls_models = capablity_of_devices.energy_info_models 147 self.user_params["tdls_models"] = self.tdls_models 148 149 def _setup_class(self): 150 """Proxy function to guarantee the base implementation of setup_class 151 is called. 152 """ 153 return self.setup_class() 154 155 def setup_class(self): 156 """Setup function that will be called before executing any test case in 157 the test class. 158 159 To signal setup failure, return False or raise an exception. If 160 exceptions were raised, the stack trace would appear in log, but the 161 exceptions would not propagate to upper levels. 162 163 Implementation is optional. 164 """ 165 166 def teardown_class(self): 167 """Teardown function that will be called after all the selected test 168 cases in the test class have been executed. 169 170 Implementation is optional. 171 """ 172 173 def _setup_test(self, test_name): 174 """Proxy function to guarantee the base implementation of setup_test is 175 called. 176 """ 177 self.current_test_name = test_name 178 try: 179 # Write test start token to adb log if android device is attached. 180 if hasattr(self, 'android_devices'): 181 for ad in self.android_devices: 182 if not ad.skip_sl4a: 183 ad.droid.logV("%s BEGIN %s" % (TEST_CASE_TOKEN, 184 test_name)) 185 except Exception as e: 186 self.log.warning( 187 'Unable to send BEGIN log command to all devices.') 188 self.log.warning('Error: %s' % e) 189 return self.setup_test() 190 191 def setup_test(self): 192 """Setup function that will be called every time before executing each 193 test case in the test class. 194 195 To signal setup failure, return False or raise an exception. If 196 exceptions were raised, the stack trace would appear in log, but the 197 exceptions would not propagate to upper levels. 198 199 Implementation is optional. 200 """ 201 return True 202 203 def _teardown_test(self, test_name): 204 """Proxy function to guarantee the base implementation of teardown_test 205 is called. 206 """ 207 self.log.debug('Tearing down test %s' % test_name) 208 try: 209 # Write test end token to adb log if android device is attached. 210 for ad in self.android_devices: 211 ad.droid.logV("%s END %s" % (TEST_CASE_TOKEN, test_name)) 212 except Exception as e: 213 self.log.warning('Unable to send END log command to all devices.') 214 self.log.warning('Error: %s' % e) 215 try: 216 self.teardown_test() 217 finally: 218 self.current_test_name = None 219 220 def teardown_test(self): 221 """Teardown function that will be called every time a test case has 222 been executed. 223 224 Implementation is optional. 225 """ 226 227 def _on_fail(self, record): 228 """Proxy function to guarantee the base implementation of on_fail is 229 called. 230 231 Args: 232 record: The records.TestResultRecord object for the failed test 233 case. 234 """ 235 if record.details: 236 self.log.error(record.details) 237 self.log.info(RESULT_LINE_TEMPLATE, record.test_name, record.result) 238 self.on_fail(record.test_name, record.begin_time) 239 240 def on_fail(self, test_name, begin_time): 241 """A function that is executed upon a test case failure. 242 243 User implementation is optional. 244 245 Args: 246 test_name: Name of the test that triggered this function. 247 begin_time: Logline format timestamp taken when the test started. 248 """ 249 250 def _on_pass(self, record): 251 """Proxy function to guarantee the base implementation of on_pass is 252 called. 253 254 Args: 255 record: The records.TestResultRecord object for the passed test 256 case. 257 """ 258 msg = record.details 259 if msg: 260 self.log.info(msg) 261 self.log.info(RESULT_LINE_TEMPLATE, record.test_name, record.result) 262 self.on_pass(record.test_name, record.begin_time) 263 264 def on_pass(self, test_name, begin_time): 265 """A function that is executed upon a test case passing. 266 267 Implementation is optional. 268 269 Args: 270 test_name: Name of the test that triggered this function. 271 begin_time: Logline format timestamp taken when the test started. 272 """ 273 274 def _on_skip(self, record): 275 """Proxy function to guarantee the base implementation of on_skip is 276 called. 277 278 Args: 279 record: The records.TestResultRecord object for the skipped test 280 case. 281 """ 282 self.log.info(RESULT_LINE_TEMPLATE, record.test_name, record.result) 283 self.log.info("Reason to skip: %s", record.details) 284 self.on_skip(record.test_name, record.begin_time) 285 286 def on_skip(self, test_name, begin_time): 287 """A function that is executed upon a test case being skipped. 288 289 Implementation is optional. 290 291 Args: 292 test_name: Name of the test that triggered this function. 293 begin_time: Logline format timestamp taken when the test started. 294 """ 295 296 def _on_blocked(self, record): 297 """Proxy function to guarantee the base implementation of on_blocked 298 is called. 299 300 Args: 301 record: The records.TestResultRecord object for the blocked test 302 case. 303 """ 304 self.log.info(RESULT_LINE_TEMPLATE, record.test_name, record.result) 305 self.log.info("Reason to block: %s", record.details) 306 self.on_blocked(record.test_name, record.begin_time) 307 308 def on_blocked(self, test_name, begin_time): 309 """A function that is executed upon a test begin skipped. 310 311 Args: 312 test_name: Name of the test that triggered this function. 313 begin_time: Logline format timestamp taken when the test started. 314 """ 315 316 def _on_exception(self, record): 317 """Proxy function to guarantee the base implementation of on_exception 318 is called. 319 320 Args: 321 record: The records.TestResultRecord object for the failed test 322 case. 323 """ 324 self.log.exception(record.details) 325 self.on_exception(record.test_name, record.begin_time) 326 327 def on_exception(self, test_name, begin_time): 328 """A function that is executed upon an unhandled exception from a test 329 case. 330 331 Implementation is optional. 332 333 Args: 334 test_name: Name of the test that triggered this function. 335 begin_time: Logline format timestamp taken when the test started. 336 """ 337 338 def _exec_procedure_func(self, func, tr_record): 339 """Executes a procedure function like on_pass, on_fail etc. 340 341 This function will alternate the 'Result' of the test's record if 342 exceptions happened when executing the procedure function. 343 344 This will let signals.TestAbortAll through so abort_all works in all 345 procedure functions. 346 347 Args: 348 func: The procedure function to be executed. 349 tr_record: The TestResultRecord object associated with the test 350 case executed. 351 """ 352 try: 353 func(tr_record) 354 except signals.TestAbortAll: 355 raise 356 except Exception as e: 357 self.log.exception("Exception happened when executing %s for %s.", 358 func.__name__, self.current_test_name) 359 tr_record.add_error(func.__name__, e) 360 361 def exec_one_testcase(self, test_name, test_func, args, **kwargs): 362 """Executes one test case and update test results. 363 364 Executes one test case, create a records.TestResultRecord object with 365 the execution information, and add the record to the test class's test 366 results. 367 368 Args: 369 test_name: Name of the test. 370 test_func: The test function. 371 args: A tuple of params. 372 kwargs: Extra kwargs. 373 """ 374 is_generate_trigger = False 375 tr_record = records.TestResultRecord(test_name, self.TAG) 376 tr_record.test_begin() 377 self.begin_time = int(tr_record.begin_time) 378 self.log_begin_time = tr_record.log_begin_time 379 self.test_name = tr_record.test_name 380 self.log.info("%s %s", TEST_CASE_TOKEN, test_name) 381 verdict = None 382 try: 383 try: 384 if hasattr(self, 'android_devices'): 385 for ad in self.android_devices: 386 if not ad.is_adb_logcat_on: 387 ad.start_adb_logcat(cont_logcat_file=True) 388 ret = self._setup_test(self.test_name) 389 asserts.assert_true(ret is not False, 390 "Setup for %s failed." % test_name) 391 if args or kwargs: 392 verdict = test_func(*args, **kwargs) 393 else: 394 verdict = test_func() 395 finally: 396 try: 397 self._teardown_test(self.test_name) 398 except signals.TestAbortAll: 399 raise 400 except Exception as e: 401 self.log.error(traceback.format_exc()) 402 tr_record.add_error("teardown_test", e) 403 self._exec_procedure_func(self._on_exception, tr_record) 404 except (signals.TestFailure, AssertionError) as e: 405 if self.user_params.get( 406 keys.Config.key_test_failure_tracebacks.value, False): 407 self.log.exception(e) 408 else: 409 self.log.error(e) 410 tr_record.test_fail(e) 411 self._exec_procedure_func(self._on_fail, tr_record) 412 except signals.TestSkip as e: 413 # Test skipped. 414 tr_record.test_skip(e) 415 self._exec_procedure_func(self._on_skip, tr_record) 416 except (signals.TestAbortClass, signals.TestAbortAll) as e: 417 # Abort signals, pass along. 418 tr_record.test_fail(e) 419 self._exec_procedure_func(self._on_fail, tr_record) 420 raise e 421 except signals.TestPass as e: 422 # Explicit test pass. 423 tr_record.test_pass(e) 424 self._exec_procedure_func(self._on_pass, tr_record) 425 except signals.TestSilent as e: 426 # This is a trigger test for generated tests, suppress reporting. 427 is_generate_trigger = True 428 self.results.requested.remove(test_name) 429 except signals.TestBlocked as e: 430 tr_record.test_blocked(e) 431 self._exec_procedure_func(self._on_blocked, tr_record) 432 except Exception as e: 433 self.log.error(traceback.format_exc()) 434 # Exception happened during test. 435 tr_record.test_unknown(e) 436 self._exec_procedure_func(self._on_exception, tr_record) 437 self._exec_procedure_func(self._on_fail, tr_record) 438 else: 439 if verdict or (verdict is None): 440 # Test passed. 441 tr_record.test_pass() 442 self._exec_procedure_func(self._on_pass, tr_record) 443 return 444 tr_record.test_fail() 445 self._exec_procedure_func(self._on_fail, tr_record) 446 finally: 447 if not is_generate_trigger: 448 self.results.add_record(tr_record) 449 450 def run_generated_testcases(self, 451 test_func, 452 settings, 453 args=None, 454 kwargs=None, 455 tag="", 456 name_func=None, 457 format_args=False): 458 """Runs generated test cases. 459 460 Generated test cases are not written down as functions, but as a list 461 of parameter sets. This way we reduce code repetition and improve 462 test case scalability. 463 464 Args: 465 test_func: The common logic shared by all these generated test 466 cases. This function should take at least one argument, 467 which is a parameter set. 468 settings: A list of strings representing parameter sets. These are 469 usually json strings that get loaded in the test_func. 470 args: Iterable of additional position args to be passed to 471 test_func. 472 kwargs: Dict of additional keyword args to be passed to test_func 473 tag: Name of this group of generated test cases. Ignored if 474 name_func is provided and operates properly. 475 name_func: A function that takes a test setting and generates a 476 proper test name. The test name should be shorter than 477 utils.MAX_FILENAME_LEN. Names over the limit will be 478 truncated. 479 format_args: If True, args will be appended as the first argument 480 in the args list passed to test_func. 481 482 Returns: 483 A list of settings that did not pass. 484 """ 485 args = args or () 486 kwargs = kwargs or {} 487 failed_settings = [] 488 489 for setting in settings: 490 test_name = "{} {}".format(tag, setting) 491 492 if name_func: 493 try: 494 test_name = name_func(setting, *args, **kwargs) 495 except: 496 self.log.exception(("Failed to get test name from " 497 "test_func. Fall back to default %s"), 498 test_name) 499 500 self.results.requested.append(test_name) 501 502 if len(test_name) > utils.MAX_FILENAME_LEN: 503 test_name = test_name[:utils.MAX_FILENAME_LEN] 504 505 previous_success_cnt = len(self.results.passed) 506 507 if format_args: 508 self.exec_one_testcase(test_name, test_func, 509 args + (setting,), **kwargs) 510 else: 511 self.exec_one_testcase(test_name, test_func, 512 (setting,) + args, **kwargs) 513 514 if len(self.results.passed) - previous_success_cnt != 1: 515 failed_settings.append(setting) 516 517 return failed_settings 518 519 def _exec_func(self, func, *args): 520 """Executes a function with exception safeguard. 521 522 This will let signals.TestAbortAll through so abort_all works in all 523 procedure functions. 524 525 Args: 526 func: Function to be executed. 527 args: Arguments to be passed to the function. 528 529 Returns: 530 Whatever the function returns, or False if unhandled exception 531 occured. 532 """ 533 try: 534 return func(*args) 535 except signals.TestAbortAll: 536 raise 537 except: 538 self.log.exception("Exception happened when executing %s in %s.", 539 func.__name__, self.TAG) 540 return False 541 542 def _get_all_test_names(self): 543 """Finds all the function names that match the test case naming 544 convention in this class. 545 546 Returns: 547 A list of strings, each is a test case name. 548 """ 549 test_names = [] 550 for name in dir(self): 551 if name.startswith("test_"): 552 test_names.append(name) 553 return test_names 554 555 def _get_test_funcs(self, test_names): 556 """Obtain the actual functions of test cases based on test names. 557 558 Args: 559 test_names: A list of strings, each string is a test case name. 560 561 Returns: 562 A list of tuples of (string, function). String is the test case 563 name, function is the actual test case function. 564 565 Raises: 566 Error is raised if the test name does not follow 567 naming convention "test_*". This can only be caused by user input 568 here. 569 """ 570 test_funcs = [] 571 for test_name in test_names: 572 test_funcs.append(self._get_test_func(test_name)) 573 574 return test_funcs 575 576 def _get_test_func(self, test_name): 577 """Obtain the actual function of test cases based on the test name. 578 579 Args: 580 test_name: String, The name of the test. 581 582 Returns: 583 A tuples of (string, function). String is the test case 584 name, function is the actual test case function. 585 586 Raises: 587 Error is raised if the test name does not follow 588 naming convention "test_*". This can only be caused by user input 589 here. 590 """ 591 if not test_name.startswith("test_"): 592 raise Error(("Test case name %s does not follow naming " 593 "convention test_*, abort.") % test_name) 594 try: 595 return test_name, getattr(self, test_name) 596 except: 597 598 def test_skip_func(*args, **kwargs): 599 raise signals.TestSkip("Test %s does not exist" % test_name) 600 601 self.log.info("Test case %s not found in %s.", test_name, self.TAG) 602 return test_name, test_skip_func 603 604 def _block_all_test_cases(self, tests): 605 """ 606 Block all passed in test cases. 607 Args: 608 tests: The tests to block. 609 """ 610 for test_name, test_func in tests: 611 signal = signals.TestBlocked("Failed class setup") 612 record = records.TestResultRecord(test_name, self.TAG) 613 record.test_begin() 614 if hasattr(test_func, 'gather'): 615 signal.extras = test_func.gather() 616 record.test_blocked(signal) 617 self.results.add_record(record) 618 self._on_blocked(record) 619 620 def run(self, test_names=None, test_case_iterations=1): 621 """Runs test cases within a test class by the order they appear in the 622 execution list. 623 624 One of these test cases lists will be executed, shown here in priority 625 order: 626 1. The test_names list, which is passed from cmd line. Invalid names 627 are guarded by cmd line arg parsing. 628 2. The self.tests list defined in test class. Invalid names are 629 ignored. 630 3. All function that matches test case naming convention in the test 631 class. 632 633 Args: 634 test_names: A list of string that are test case names requested in 635 cmd line. 636 637 Returns: 638 The test results object of this class. 639 """ 640 self.log.info("==========> %s <==========", self.TAG) 641 # Devise the actual test cases to run in the test class. 642 if not test_names: 643 if self.tests: 644 # Specified by run list in class. 645 test_names = list(self.tests) 646 else: 647 # No test case specified by user, execute all in the test class 648 test_names = self._get_all_test_names() 649 self.results.requested = test_names 650 tests = self._get_test_funcs(test_names) 651 # A TestResultRecord used for when setup_class fails. 652 # Setup for the class. 653 try: 654 if self._setup_class() is False: 655 self.log.error("Failed to setup %s.", self.TAG) 656 self._block_all_test_cases(tests) 657 return self.results 658 except Exception as e: 659 self.log.exception("Failed to setup %s.", self.TAG) 660 self._exec_func(self.teardown_class) 661 self._block_all_test_cases(tests) 662 return self.results 663 # Run tests in order. 664 try: 665 for test_name, test_func in tests: 666 for _ in range(test_case_iterations): 667 self.exec_one_testcase(test_name, test_func, self.cli_args) 668 return self.results 669 except signals.TestAbortClass: 670 return self.results 671 except signals.TestAbortAll as e: 672 # Piggy-back test results on this exception object so we don't lose 673 # results from this test class. 674 setattr(e, "results", self.results) 675 raise e 676 finally: 677 self._exec_func(self.teardown_class) 678 self.log.info("Summary for test class %s: %s", self.TAG, 679 self.results.summary_str()) 680 681 def clean_up(self): 682 """A function that is executed upon completion of all tests cases 683 selected in the test class. 684 685 This function should clean up objects initialized in the constructor by 686 user. 687 """ 688 689 def _ad_take_bugreport(self, ad, test_name, begin_time): 690 for i in range(3): 691 try: 692 ad.take_bug_report(test_name, begin_time) 693 return True 694 except Exception as e: 695 ad.log.error("bugreport attempt %s error: %s", i + 1, e) 696 697 def _ad_take_extra_logs(self, ad, test_name, begin_time): 698 result = True 699 if getattr(ad, "qxdm_log", False): 700 # Gather qxdm log modified 3 minutes earlier than test start time 701 if begin_time: 702 qxdm_begin_time = begin_time - 1000 * 60 * 3 703 else: 704 qxdm_begin_time = None 705 try: 706 ad.get_qxdm_logs(test_name, qxdm_begin_time) 707 except Exception as e: 708 ad.log.error("Failed to get QXDM log for %s with error %s", 709 test_name, e) 710 result = False 711 712 try: 713 ad.check_crash_report(test_name, begin_time, log_crash_report=True) 714 except Exception as e: 715 ad.log.error("Failed to check crash report for %s with error %s", 716 test_name, e) 717 result = False 718 return result 719 720 def _skip_bug_report(self): 721 """A function to check whether we should skip creating a bug report.""" 722 if "no_bug_report_on_fail" in self.user_params: 723 return True 724 725 # Once we hit a certain log path size, it's not going to get smaller. 726 # We cache the result so we don't have to keep doing directory walks. 727 if self.size_limit_reached: 728 return True 729 try: 730 max_log_size = int( 731 self.user_params.get("soft_output_size_limit") or "invalid") 732 log_path = getattr(logging, "log_path", None) 733 if log_path: 734 curr_log_size = utils.get_directory_size(log_path) 735 if curr_log_size > max_log_size: 736 self.log.info( 737 "Skipping bug report, as we've reached the size limit." 738 ) 739 self.size_limit_reached = True 740 return True 741 except ValueError: 742 pass 743 return False 744 745 def _take_bug_report(self, test_name, begin_time): 746 if self._skip_bug_report(): 747 return 748 749 executor = ThreadPoolExecutor(max_workers=10) 750 for ad in getattr(self, 'android_devices', []): 751 executor.submit(self._ad_take_bugreport, ad, test_name, begin_time) 752 executor.submit(self._ad_take_extra_logs, ad, test_name, 753 begin_time) 754 executor.shutdown() 755 756 def _reboot_device(self, ad): 757 ad.log.info("Rebooting device.") 758 ad = ad.reboot() 759 760 def _cleanup_logger_sessions(self): 761 for (mylogger, session) in self.logger_sessions: 762 self.log.info("Resetting a diagnostic session %s, %s", mylogger, 763 session) 764 mylogger.reset() 765 self.logger_sessions = [] 766 767 def _pull_diag_logs(self, test_name, begin_time): 768 for (mylogger, session) in self.logger_sessions: 769 self.log.info("Pulling diagnostic session %s", mylogger) 770 mylogger.stop(session) 771 diag_path = os.path.join( 772 self.log_path, logger.epoch_to_log_line_timestamp(begin_time)) 773 utils.create_dir(diag_path) 774 mylogger.pull(session, diag_path) 775
