1# Lint as: python2, python3 2# Copyright 2019 The Chromium OS Authors. All rights reserved. 3# Use of this source code is governed by a BSD-style license that can be 4# found in the LICENSE file. 5 6""" 7This class provides wrapper functions for Bluetooth quick health test 8batches or packages 9""" 10 11from __future__ import absolute_import 12from __future__ import division 13from __future__ import print_function 14 15import functools 16import logging 17import tempfile 18import threading 19import time 20 21import common 22from autotest_lib.client.common_lib import error 23from autotest_lib.client.common_lib.cros.bluetooth import bluetooth_quick_tests_base 24from autotest_lib.server import site_utils 25from autotest_lib.server.cros.bluetooth import bluetooth_peer_update 26from autotest_lib.server.cros.bluetooth import bluetooth_adapter_tests 27from autotest_lib.server.cros.bluetooth import bluetooth_attenuator 28from autotest_lib.server.cros.multimedia import remote_facade_factory 29from autotest_lib.client.bin import utils 30from six.moves import range 31 32PROFILE_CONNECT_WAIT = 15 33SUSPEND_SEC = 15 34EXPECT_NO_WAKE_SUSPEND_SEC = 30 35EXPECT_PEER_WAKE_SUSPEND_SEC = 60 36EXPECT_PEER_WAKE_RESUME_BY = 30 37 38 39class BluetoothAdapterQuickTests( 40 bluetooth_adapter_tests.BluetoothAdapterTests, 41 bluetooth_quick_tests_base.BluetoothQuickTestsBase): 42 """Bluetooth quick test implementation for server tests.""" 43 44 GCS_MTBF_BUCKET = 'gs://chromeos-mtbf-bt-results/' 45 46 47 def restart_peers(self): 48 """Restart and clear peer devices""" 49 # Restart the link to device 50 logging.info('Restarting peer devices...') 51 52 # Grab current device list for initialization 53 connected_devices = self.devices 54 self.cleanup_bt_test(test_state='MID') 55 56 for device_type, device_list in connected_devices.items(): 57 for device in device_list: 58 if device is not None: 59 logging.info('Restarting %s', device_type) 60 self.get_device(device_type, on_start=False) 61 62 63 def start_peers(self, devices): 64 """Start peer devices""" 65 # Start the link to devices 66 if self.use_btpeer: 67 logging.info('Starting peer devices...') 68 self.get_device_rasp(devices) 69 70 # Grab all the devices to verify RSSI 71 devices = [] 72 for device_type, device_list in self.devices.items(): 73 # Skip bluetooth_tester since it won't be discoverable 74 if 'TESTER' in device_type: 75 continue 76 77 for device in device_list: 78 devices.append(device) 79 self.start_agent(device) 80 81 if self.rssi_check: 82 # Make sure device RSSI is sufficient 83 self.verify_device_rssi(devices) 84 else: 85 logging.info('Skip RSSI check.') 86 87 @staticmethod 88 def _get_bool_arg(arg, args_dict, default_value): 89 """Get the target bool argument from args_dict. 90 91 @param arg: the target argument to query 92 @param args_dict: the argument dictionary 93 @param default_value: the default value of the argument 94 if the arg is not in args_dict or 95 if arg is neither 'true' nor 'false' 96 97 @returns: the bool value of the target argument 98 """ 99 if args_dict is not None and arg in args_dict: 100 arg_value = args_dict[arg].lower() 101 if arg_value == 'true': 102 return True 103 elif arg_value == 'false': 104 return False 105 return default_value 106 107 @staticmethod 108 def _get_clean_kernel_log_arguments(args_dict=None): 109 """Parse the clean_kernel_log argument""" 110 key = 'clean_kernel_log' 111 if args_dict is not None and key in args_dict: 112 return args_dict[key].upper() 113 return 'DEBUG' 114 115 def quick_test_init(self, 116 host, 117 use_btpeer=True, 118 flag='Quick Health', 119 args_dict=None, 120 start_browser=False, 121 floss=False): 122 """Inits the test batch""" 123 124 super().quick_test_init(flag) 125 126 self.host = host 127 self.start_browser = start_browser 128 self.use_btpeer = use_btpeer 129 self.floss = floss 130 self.local_host_ip = None 131 132 logging.debug('args_dict %s', args_dict) 133 update_btpeers = self._get_bool_arg('update_btpeers', args_dict, True) 134 self.rssi_check = self._get_bool_arg('rssi_check', args_dict, True) 135 clean_log = self._get_clean_kernel_log_arguments(args_dict) 136 btpeer_args = [] 137 if args_dict is not None: 138 btpeer_args = self.host.get_btpeer_arguments(args_dict) 139 ip_args = self.host.get_local_host_ip(args_dict) 140 if ip_args: 141 self.local_host_ip = ip_args['local_host_ip'] 142 143 #factory can not be declared as local variable, otherwise 144 #factory._proxy.__del__ will be invoked, which shutdown the xmlrpc 145 # server, which log out the user. 146 147 self.factory = remote_facade_factory.RemoteFacadeFactory( 148 host, 149 no_chrome=not self.start_browser, 150 disable_arc=True, 151 force_python3=True) 152 try: 153 self.bluetooth_facade = self.factory.create_bluetooth_facade( 154 self.floss) 155 except Exception as e: 156 logging.error('Exception %s while creating bluetooth_facade', 157 str(e)) 158 raise error.TestFail('Unable to create bluetooth_facade') 159 160 if clean_log is not 'FALSE': 161 # Clean Bluetooth kernel logs in the DUT to prevent 162 # /var/log/messages occupying too much space 163 self.clean_bluetooth_kernel_log(clean_log) 164 165 # Some test beds has a attenuator for Bluetooth. If Bluetooth 166 # attenuator is present, set its attenuation to 0 167 self.bt_attenuator = bluetooth_attenuator.init_btattenuator( 168 self.host, args_dict) 169 170 logging.debug("Bluetooth attenuator is %s", self.bt_attenuator) 171 172 # Check whether this device supports floss 173 if self.floss: 174 self.check_floss_support() 175 176 if self.use_btpeer: 177 self.input_facade = self.factory.create_input_facade() 178 179 self.host.initialize_btpeer(btpeer_args=btpeer_args) 180 logging.info('%s Bluetooth peers found', 181 len(self.host.btpeer_list)) 182 logging.info('labels: %s', self.host.get_labels()) 183 184 if len(self.host.btpeer_list) == 0: 185 raise error.TestFail('Unable to find a Bluetooth peer') 186 187 # Check the chameleond version on the peer and update if necessary 188 if update_btpeers: 189 if not bluetooth_peer_update.update_all_peers(self.host): 190 logging.error('Updating btpeers failed. Ignored') 191 else: 192 logging.info('No attempting peer update.') 193 194 # Query connected devices on our btpeer at init time 195 self.available_devices = self.list_devices_available() 196 197 for btpeer in self.host.btpeer_list: 198 btpeer.register_raspPi_log(self.outputdir) 199 200 self.btpeer_group = dict() 201 # Create copy of btpeer_group 202 self.btpeer_group_copy = dict() 203 self.group_btpeers_type() 204 205 # Clear the active devices for this test 206 self.active_test_devices = {} 207 208 self.enable_disable_debug_log(enable=True) 209 210 # Disable cellular services, as they can sometimes interfere with 211 # suspend/resume, i.e. b/161920740 212 self.enable_disable_cellular(enable=False) 213 214 self.enable_disable_ui(enable=False) 215 216 # Delete files created in previous run 217 self.host.run('[ ! -d {0} ] || rm -rf {0} || true'.format( 218 self.BTMON_DIR_LOG_PATH)) 219 self.host.run('[ ! -d {0} ] || rm -rf {0} || true'.format( 220 self.USBMON_DIR_LOG_PATH)) 221 222 self.dut_btmon_log_path = self.start_new_btmon() 223 self.start_new_usbmon() 224 225 self.identify_platform_failure_reasons() 226 227 self.mtbf_end = False 228 self.mtbf_end_lock = threading.Lock() 229 230 def quick_test_get_model_name(self): 231 """Returns the model name. 232 233 Needed by BluetoothQuickTestsBase.quick_test_test_decorator. 234 """ 235 return self.get_base_platform_name() 236 237 def quick_test_get_chipset_name(self): 238 """Returns the chipset name. 239 240 Needed by BluetoothQuickTestsBase.quick_test_test_decorator. 241 """ 242 return self.bluetooth_facade.get_chipset_name() 243 244 @staticmethod 245 def quick_test_test_decorator(test_name, 246 devices={}, 247 flags=['All'], 248 model_testNA=[], 249 model_testWarn=[], 250 skip_models=[], 251 skip_chipsets=[], 252 skip_common_errors=False, 253 supports_floss=False, 254 use_all_peers=False): 255 """A decorator providing a wrapper to a quick test. 256 Using the decorator a test method can implement only the core 257 test and let the decorator handle the quick test wrapper methods 258 (reset/cleanup/logging). 259 260 @param test_name: the name of the test to log. 261 @param devices: map of the device types and the quantities needed for 262 the test. 263 For example, {'BLE_KEYBOARD':1, 'BLE_MOUSE':1}. 264 @param flags: list of string to describe who should run the 265 test. The string could be one of the following: 266 ['AVL', 'Quick Health', 'All']. 267 @param model_testNA: If the current platform is in this list, 268 failures are emitted as TestNAError. 269 @param model_testWarn: If the current platform is in this list, 270 failures are emitted as TestWarn. 271 @param skip_models: Raises TestNA on these models and doesn't attempt 272 to run the tests. 273 @param skip_chipsets: Raises TestNA on these chipset and doesn't 274 attempt to run the tests. 275 @param skip_common_errors: If the test encounters a common error 276 (such as USB disconnect or daemon crash), 277 mark the test as TESTNA instead. 278 USE THIS SPARINGLY, it may mask bugs. This 279 is available for tests that require state 280 to be properly retained throughout the 281 whole test (i.e. advertising) and any 282 outside failure will cause the test to 283 fail. 284 @param supports_floss: Does this test support running on Floss? 285 @param use_all_peers: Set number of devices to be used to the 286 maximum available. This is used for tests 287 like bluetooth_PeerVerify which uses all 288 available peers. Specify only one device type 289 if this is set to true 290 """ 291 292 base_class = bluetooth_quick_tests_base.BluetoothQuickTestsBase 293 return base_class.quick_test_test_decorator( 294 test_name, 295 flags=flags, 296 check_runnable_func=lambda self: self.quick_test_test_runnable( 297 supports_floss), 298 pretest_func=lambda self: self.quick_test_test_pretest( 299 test_name, devices, use_all_peers), 300 posttest_func=lambda self: self.quick_test_test_posttest(), 301 model_testNA=model_testNA, 302 model_testWarn=model_testWarn, 303 skip_models=skip_models, 304 skip_chipsets=skip_chipsets, 305 skip_common_errors=skip_common_errors) 306 307 def quick_test_test_runnable(self, supports_floss): 308 """Checks if the test could be run.""" 309 310 # If the current test was to run with Floss, the test must 311 # support running with Floss. 312 if self.floss: 313 return supports_floss 314 315 return True 316 317 def quick_test_test_pretest(self, 318 test_name=None, 319 devices={}, 320 use_all_peers=False): 321 """Runs pretest checks and resets DUT's adapter and peer devices. 322 323 @param test_name: the name of the test to log. 324 @param devices: map of the device types and the quantities needed for 325 the test. 326 For example, {'BLE_KEYBOARD':1, 'BLE_MOUSE':1}. 327 @param use_all_peers: Set number of devices to be used to the 328 maximum available. This is used for tests 329 like bluetooth_PeerVerify which uses all 330 available peers. Specify only one device type 331 if this is set to true 332 """ 333 334 def _is_enough_peers_present(self): 335 """Checks if enough peer devices are available.""" 336 337 # Check that btpeer has all required devices before running 338 for device_type, number in devices.items(): 339 if self.available_devices.get(device_type, 0) < number: 340 logging.info('SKIPPING TEST %s', test_name) 341 logging.info('%s not available', device_type) 342 self._print_delimiter() 343 return False 344 345 # Check if there are enough peers 346 total_num_devices = sum(devices.values()) 347 if total_num_devices > len(self.host.btpeer_list): 348 logging.info('SKIPPING TEST %s', test_name) 349 logging.info( 350 'Number of devices required %s is greater' 351 'than number of peers available %d', total_num_devices, 352 len(self.host.btpeer_list)) 353 self._print_delimiter() 354 return False 355 return True 356 357 if use_all_peers: 358 if devices != {}: 359 devices[list(devices.keys())[0]] = len(self.host.btpeer_list) 360 361 if not _is_enough_peers_present(self): 362 logging.info('Not enough peer available') 363 raise error.TestNAError('Not enough peer available') 364 365 # Every test_method should pass by default. 366 self._expected_result = True 367 368 # Bluetoothd could have crashed behind the scenes; check to see if 369 # everything is still ok and recover if needed. 370 self.test_is_facade_valid() 371 self.test_is_adapter_valid() 372 373 # Reset the adapter 374 self.test_reset_on_adapter() 375 376 # Reset the policy allowlist so that all UUIDs are allowed. 377 self.test_reset_allowlist() 378 379 # Reset power/wakeup to disabled. 380 self.test_adapter_set_wake_disabled() 381 382 # Initialize bluetooth_adapter_tests class (also clears self.fails) 383 self.initialize() 384 # Start and peer HID devices 385 self.start_peers(devices) 386 387 time.sleep(self.TEST_SLEEP_SECS) 388 self.log_message('Starting test: %s' % test_name) 389 390 def quick_test_test_posttest(self): 391 """Runs posttest cleanups.""" 392 393 logging.info('Cleanning up and restarting towards next test...') 394 self.log_message(self.bat_tests_results[-1]) 395 396 # Every test_method should pass by default. 397 self._expected_result = True 398 399 # Bluetoothd could have crashed behind the scenes; check if everything 400 # is ok and recover if needed. This is done as part of clean-up as well 401 # to make sure we can fully remove pairing info between tests 402 self.test_is_facade_valid() 403 404 self.bluetooth_facade.stop_discovery() 405 406 # Catch possible exceptions in test_reset_allowlist(). 407 # Refer to b/184947150 for more context. 408 try: 409 # Reset the policy allowlist so that all UUIDs are allowed. 410 self.test_reset_allowlist() 411 except: 412 msg = ('Failed to reset the policy allowlist.\n' 413 '### Note: reset the allowlist manually if needed. ###\n\n' 414 'dbus-send --system --print-reply --dest=org.bluez ' 415 '/org/bluez/hci0 org.bluez.AdminPolicy1.SetServiceAllowList ' 416 'array:string:"" \n') 417 logging.error(msg) 418 419 # Store a copy of active devices for raspi reset in the final step 420 self.active_test_devices = self.devices 421 422 # Disconnect devices used in the test, and remove the pairing. 423 for device_list in self.devices.values(): 424 for device in device_list: 425 if device is not None: 426 self.stop_agent(device) 427 logging.info('Clear device %s from DUT', device.name) 428 self.bluetooth_facade.disconnect_device(device.address) 429 device_is_paired = self.bluetooth_facade.device_is_paired( 430 device.address) 431 if device_is_paired: 432 self.bluetooth_facade.remove_device_object( 433 device.address) 434 435 # Also remove pairing on Peer 436 logging.info('Clearing DUT from %s', device.name) 437 try: 438 device.RemoveDevice(self.bluetooth_facade.address) 439 except Exception as e: 440 # If peer doesn't expose RemoveDevice, ignore failure 441 if not (e.__class__.__name__ == 'Fault' and 442 'is not supported' in str(e)): 443 logging.info('Couldn\'t Remove: {}'.format(e)) 444 raise 445 446 447 # Repopulate btpeer_group for next tests 448 # Clear previous tets's leftover entries. Don't delete the 449 # btpeer_group dictionary though, it'll be used as it is. 450 if self.use_btpeer: 451 for device_type in self.btpeer_group: 452 if len(self.btpeer_group[device_type]) > 0: 453 del self.btpeer_group[device_type][:] 454 455 # Repopulate 456 self.group_btpeers_type() 457 458 # Close the connection between peers 459 self.cleanup_bt_test(test_state='NEW') 460 461 462 def quick_test_cleanup(self): 463 """ Cleanup any state test server and all device""" 464 465 # Clear any raspi devices at very end of test 466 for device_list in self.active_test_devices.values(): 467 for device in device_list: 468 if device is not None: 469 self.clear_raspi_device(device) 470 self.device_set_powered(device, False) 471 472 # Reset the adapter 473 self.test_reset_on_adapter() 474 # Initialize bluetooth_adapter_tests class (also clears self.fails) 475 self.initialize() 476 477 478 @staticmethod 479 def quick_test_mtbf_decorator(timeout_mins, test_name): 480 """A decorator enabling a test to be run as a MTBF test, it will run 481 the underlying test in a infinite loop until it fails or timeout is 482 reached, in both cases the time elapsed time will be reported. 483 484 @param timeout_mins: the max execution time of the test, once the 485 time is up the test will report success and exit 486 @param test_name: the MTBF test name to be output to the dashboard 487 """ 488 489 def decorator(batch_method): 490 """A decorator wrapper of the decorated batch_method. 491 @param batch_method: the batch method being decorated. 492 @returns the wrapper of the batch method. 493 """ 494 495 @functools.wraps(batch_method) 496 def wrapper(self, *args, **kwargs): 497 """A wrapper of the decorated method""" 498 self.mtbf_end = False 499 mtbf_timer = threading.Timer( 500 timeout_mins * 60, self.mtbf_timeout) 501 mtbf_timer.start() 502 start_time = time.time() 503 board = self.host.get_board().split(':')[1] 504 model = self.host.get_model_from_cros_config() 505 build = self.host.get_release_version() 506 milestone = 'M' + self.host.get_chromeos_release_milestone() 507 in_lab = site_utils.host_in_lab(self.host.hostname) 508 while True: 509 with self.mtbf_end_lock: 510 # The test ran the full duration without failure 511 if self.mtbf_end: 512 self.report_mtbf_result( 513 True, start_time, test_name, model, build, 514 milestone, board, in_lab) 515 break 516 try: 517 batch_method(self, *args, **kwargs) 518 except Exception as e: 519 logging.info("Caught a failure: %r", e) 520 self.report_mtbf_result( 521 False, start_time, test_name, model, build, 522 milestone, board, in_lab) 523 # Don't report the test run as failed for MTBF 524 self.fails = [] 525 break 526 527 mtbf_timer.cancel() 528 529 return wrapper 530 531 return decorator 532 533 534 def mtbf_timeout(self): 535 """Handle time out event of a MTBF test""" 536 with self.mtbf_end_lock: 537 self.mtbf_end = True 538 539 540 def report_mtbf_result(self, success, start_time, test_name, model, build, 541 milestone, board, in_lab): 542 """Report MTBF result by uploading it to GCS""" 543 duration_secs = int(time.time() - start_time) 544 start_time = int(start_time) 545 gm_time_struct = time.localtime(start_time) 546 output_file_name = self.GCS_MTBF_BUCKET + \ 547 time.strftime('%Y-%m-%d/', gm_time_struct) + \ 548 time.strftime('%H-%M-%S.csv', gm_time_struct) 549 550 mtbf_result = '{0},{1},{2},{3},{4},{5},{6},{7}'.format( 551 model, build, milestone, start_time * 1000000, duration_secs, 552 success, test_name, board) 553 with tempfile.NamedTemporaryFile() as tmp_file: 554 tmp_file.write(mtbf_result.encode('utf-8')) 555 tmp_file.flush() 556 cmd = 'gsutil cp {0} {1}'.format(tmp_file.name, output_file_name) 557 logging.info('Result to upload %s %s', mtbf_result, cmd) 558 # Only upload the result when running in the lab. 559 if in_lab: 560 logging.info('Uploading result') 561 utils.run(cmd) 562 563 564 # --------------------------------------------------------------- 565 # Wake from suspend tests 566 # --------------------------------------------------------------- 567 568 def run_peer_wakeup_device(self, 569 device_type, 570 device, 571 device_test=None, 572 iterations=1, 573 should_wake=True, 574 should_pair=True, 575 keep_paired=False): 576 """ Uses paired peer device to wake the device from suspend. 577 578 @param device_type: the device type (used to determine if it's LE) 579 @param device: the meta device with the paired device 580 @param device_test: What to test to run after waking and connecting the 581 adapter/host 582 @param iterations: Number of suspend + peer wake loops to run 583 @param should_wake: Whether wakeup should occur on this test. With HID 584 peers, this should be True. With non-HID peers, this 585 should be false. 586 @param should_pair: Pair and connect the device first before running 587 the wakeup test. 588 @param keep_paired: Keep the paried devices after test. 589 """ 590 boot_id = self.host.get_boot_id() 591 592 if should_wake: 593 sleep_time = EXPECT_PEER_WAKE_SUSPEND_SEC 594 resume_time = EXPECT_PEER_WAKE_RESUME_BY 595 resume_slack = 5 # Allow 5s slack for resume timeout 596 measure_resume = True 597 else: 598 sleep_time = EXPECT_NO_WAKE_SUSPEND_SEC 599 resume_time = EXPECT_NO_WAKE_SUSPEND_SEC 600 # Negative resume slack lets us wake a bit earlier than expected 601 # If suspend takes a while to enter, this may be necessary to get 602 # the timings right. 603 resume_slack = -5 604 measure_resume = False 605 606 try: 607 if should_pair: 608 # Clear wake before testing 609 self.test_adapter_set_wake_disabled() 610 self.assert_discover_and_pair(device) 611 self.assert_on_fail( 612 self.test_device_set_discoverable(device, False)) 613 614 # Confirm connection completed 615 self.assert_on_fail( 616 self.test_device_is_connected(device.address)) 617 618 # Profile connection may not have completed yet and this will 619 # race with a subsequent disconnection (due to suspend). Use the 620 # device test to force profile connect or wait if no test was 621 # given. 622 if device_test is not None: 623 self.assert_on_fail(device_test(device)) 624 else: 625 time.sleep(PROFILE_CONNECT_WAIT) 626 627 for it in range(iterations): 628 logging.info( 629 'Running iteration {}/{} of suspend peer wake'.format( 630 it + 1, iterations)) 631 632 # Start a new suspend instance 633 suspend = self.suspend_async(suspend_time=sleep_time, 634 expect_bt_wake=should_wake) 635 start_time = self.bluetooth_facade.get_device_utc_time() 636 637 if should_wake: 638 self.test_device_wake_allowed(device.address) 639 # Also wait until powerd marks adapter as wake enabled 640 self.test_adapter_wake_enabled() 641 else: 642 self.test_device_wake_not_allowed(device.address) 643 644 # Trigger suspend, asynchronously wake and wait for resume 645 adapter_address = self.bluetooth_facade.address 646 self.test_suspend_and_wait_for_sleep(suspend, 647 sleep_timeout=SUSPEND_SEC) 648 649 # Trigger peer wakeup 650 peer_wake = self.device_connect_async(device_type, 651 device, 652 adapter_address, 653 delay_wake=5, 654 should_wake=should_wake) 655 peer_wake.start() 656 657 # Expect a quick resume. If a timeout occurs, test fails. Since 658 # we delay sending the wake signal, we should accommodate that 659 # in our expected timeout. 660 self.test_wait_for_resume(boot_id, 661 suspend, 662 resume_timeout=resume_time, 663 test_start_time=start_time, 664 resume_slack=resume_slack, 665 fail_on_timeout=should_wake, 666 fail_early_wake=not should_wake, 667 collect_resume_time=measure_resume) 668 669 # Finish peer wake process 670 peer_wake.join() 671 672 # Only check peer device connection state if we expected to wake 673 # from it. Otherwise, we may or may not be connected based on 674 # the specific profile's reconnection policy. 675 if should_wake: 676 # Make sure we're actually connected 677 self.test_device_is_connected(device.address) 678 679 # Verify the profile is working 680 if device_test is not None: 681 device_test(device) 682 683 finally: 684 if should_pair and not keep_paired: 685 self.test_remove_pairing(device.address) 686