1#!/usr/bin/env python3 2# 3# Copyright 2019 - 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 17from abc import ABC 18from abc import abstractmethod 19from datetime import datetime 20import inspect 21import logging 22import os 23import pathlib 24import shutil 25import signal 26import subprocess 27import time 28from typing import List 29 30import grpc 31 32from google.protobuf import empty_pb2 as empty_proto 33 34from blueberry.tests.gd.cert import asserts 35from blueberry.tests.gd.cert.adb import BlueberryAdbProxy 36from blueberry.tests.gd.cert.adb import UTF_8 37from blueberry.tests.gd.cert.async_subprocess_logger import AsyncSubprocessLogger 38from blueberry.tests.gd.cert.context import get_current_context 39from blueberry.tests.gd.cert.logging_client_interceptor import LoggingClientInterceptor 40from blueberry.tests.gd.cert.os_utils import get_gd_root 41from blueberry.tests.gd.cert.os_utils import read_crash_snippet_and_log_tail 42from blueberry.tests.gd.cert.os_utils import is_subprocess_alive 43from blueberry.tests.gd.cert.os_utils import make_ports_available 44from blueberry.tests.gd.cert.os_utils import TerminalColor 45 46from blueberry.facade import rootservice_pb2_grpc as facade_rootservice_pb2_grpc 47from blueberry.facade.hal import hal_facade_pb2_grpc 48from blueberry.facade.hci import hci_facade_pb2_grpc 49from blueberry.facade.hci import acl_manager_facade_pb2_grpc 50from blueberry.facade.hci import controller_facade_pb2_grpc 51from blueberry.facade.hci import le_acl_manager_facade_pb2_grpc 52from blueberry.facade.hci import le_advertising_manager_facade_pb2_grpc 53from blueberry.facade.hci import le_initiator_address_facade_pb2_grpc 54from blueberry.facade.hci import le_scanning_manager_facade_pb2_grpc 55from blueberry.facade.l2cap.classic import facade_pb2_grpc as l2cap_facade_pb2_grpc 56from blueberry.facade.l2cap.le import facade_pb2_grpc as l2cap_le_facade_pb2_grpc 57from blueberry.facade.neighbor import facade_pb2_grpc as neighbor_facade_pb2_grpc 58from blueberry.facade.security import facade_pb2_grpc as security_facade_pb2_grpc 59 60from mobly import utils 61from mobly.controllers.android_device_lib.adb import AdbError 62 63ADB_FILE_NOT_EXIST_ERROR = "No such file or directory" 64GRPC_START_TIMEOUT_SEC = 15 65MOBLY_CONTROLLER_CONFIG_NAME = "GdDevice" 66PORT_FORWARDING_ERROR_MSG_PREFIX = "During port forwarding cleanup: " 67PULL_LOG_FILE_ERROR_MSG_PREFIX = "While trying to pull log files" 68 69 70def create(configs): 71 if not configs: 72 raise Exception("Configuration is empty") 73 elif not isinstance(configs, list): 74 raise Exception("Configuration should be a list") 75 return get_instances_with_configs(configs) 76 77 78def destroy(devices): 79 for device in devices: 80 try: 81 device.teardown() 82 except: 83 logging.exception("[%s] Failed to clean up properly due to" % device.label) 84 85 86def get_info(devices): 87 return [] 88 89 90def replace_vars(string, config): 91 serial_number = config.get("serial_number") 92 if serial_number is None: 93 serial_number = "" 94 rootcanal_port = config.get("rootcanal_port") 95 if rootcanal_port is None: 96 rootcanal_port = "" 97 if serial_number == "DUT" or serial_number == "CERT": 98 raise Exception("Did you forget to configure the serial number?") 99 return string.replace("$GD_ROOT", get_gd_root()) \ 100 .replace("$(grpc_port)", config.get("grpc_port")) \ 101 .replace("$(grpc_root_server_port)", config.get("grpc_root_server_port")) \ 102 .replace("$(rootcanal_port)", rootcanal_port) \ 103 .replace("$(signal_port)", config.get("signal_port")) \ 104 .replace("$(serial_number)", serial_number) 105 106 107def get_instances_with_configs(configs): 108 print(configs) 109 devices = [] 110 for config in configs: 111 resolved_cmd = [] 112 for arg in config["cmd"]: 113 logging.debug(arg) 114 resolved_cmd.append(replace_vars(arg, config)) 115 verbose_mode = bool(config.get('verbose_mode', False)) 116 if config.get("serial_number"): 117 device = GdAndroidDevice(config["grpc_port"], config["grpc_root_server_port"], config["signal_port"], 118 resolved_cmd, config["label"], MOBLY_CONTROLLER_CONFIG_NAME, config["name"], 119 config["serial_number"], verbose_mode) 120 else: 121 device = GdHostOnlyDevice(config["grpc_port"], config["grpc_root_server_port"], config["signal_port"], 122 resolved_cmd, config["label"], MOBLY_CONTROLLER_CONFIG_NAME, config["name"], 123 verbose_mode) 124 device.setup() 125 devices.append(device) 126 return devices 127 128 129class GdDeviceBase(ABC): 130 """ 131 Base GD device class that covers common traits which assumes that the 132 device must be driven by a driver-like backing process that takes following 133 command line arguments: 134 --grpc-port: main entry port for facade services 135 --root-server-port: management port for starting and stopping services 136 --btsnoop: path to btsnoop HCI log 137 --signal-port: signaling port to indicate that backing process is started 138 --rootcanal-port: root-canal HCI port, optional 139 """ 140 141 WAIT_CHANNEL_READY_TIMEOUT_SECONDS = 10 142 WAIT_SIGINT_TIMEOUT_SECONDS = 5 143 WAIT_SIGKILL_TIMEOUT_SECONDS = 1 144 145 def __init__(self, grpc_port: str, grpc_root_server_port: str, signal_port: str, cmd: List[str], label: str, 146 type_identifier: str, name: str, verbose_mode: bool): 147 """Verify arguments and log path, initialize Base GD device, common traits 148 for both device based and host only GD cert tests 149 :param grpc_port: main gRPC service port 150 :param grpc_root_server_port: gRPC root server port 151 :param signal_port: signaling port for backing process start up 152 :param cmd: list of arguments to run in backing process 153 :param label: device label used in logs 154 :param type_identifier: device type identifier used in logs 155 :param name: name of device used in logs 156 """ 157 # Must be at the first line of __init__ method 158 values = locals() 159 arguments = [values[arg] for arg in inspect.getfullargspec(GdDeviceBase.__init__).args if arg != "verbose_mode"] 160 asserts.assert_true(all(arguments), "All arguments to GdDeviceBase must not be None nor empty") 161 asserts.assert_true(all(cmd), "cmd list should not have None nor empty component") 162 self.verbose_mode = verbose_mode 163 self.host_only_device = False 164 self.grpc_root_server_port = int(grpc_root_server_port) 165 self.grpc_port = int(grpc_port) 166 self.signal_port = int(signal_port) 167 self.name = name 168 self.type_identifier = type_identifier 169 self.label = label 170 self.log_path_base = get_current_context().get_full_output_path() 171 self.test_runner_base_path = \ 172 get_current_context().get_base_output_path() 173 self.backing_process_log_path = os.path.join(self.log_path_base, 174 '%s_%s_backing_logs.txt' % (self.type_identifier, self.label)) 175 if "--btsnoop=" not in " ".join(cmd): 176 cmd.append("--btsnoop=%s" % os.path.join(self.log_path_base, '%s_btsnoop_hci.log' % self.label)) 177 if "--btsnooz=" not in " ".join(cmd): 178 cmd.append("--btsnooz=%s" % os.path.join(self.log_path_base, '%s_btsnooz_hci.log' % self.label)) 179 if "--btconfig=" not in " ".join(cmd): 180 cmd.append("--btconfig=%s" % os.path.join(self.log_path_base, '%s_bt_config.conf' % self.label)) 181 self.cmd = cmd 182 self.environment = os.environ.copy() 183 if "cert" in self.label: 184 self.terminal_color = TerminalColor.BLUE 185 else: 186 self.terminal_color = TerminalColor.YELLOW 187 188 def setup(self): 189 """Set up this device for test, ensure signal port is available and backing process is started and alive, 190 must run before using this device. 191 - After calling this, teardown() must be called when test finishes 192 - Should be executed after children classes' setup() methods 193 :return: 194 """ 195 # Start backing process 196 logging.debug("[%s] Running %s %s" % (self.type_identifier, self.label, " ".join(self.cmd))) 197 self.backing_process = subprocess.Popen(self.cmd, 198 cwd=get_gd_root(), 199 env=self.environment, 200 stdout=subprocess.PIPE, 201 stderr=subprocess.STDOUT, 202 universal_newlines=True) 203 204 self.backing_process_logger = AsyncSubprocessLogger(self.backing_process, [self.backing_process_log_path], 205 log_to_stdout=self.verbose_mode, 206 tag=self.label, 207 color=self.terminal_color) 208 209 asserts.assert_true(self.backing_process, 210 msg="[%s] failed to open backing process for %s" % (self.type_identifier, self.label)) 211 self.is_backing_process_alive = is_subprocess_alive(self.backing_process) 212 213 asserts.assert_true(self.is_backing_process_alive, 214 msg="[%s] backing process for %s died after starting" % (self.type_identifier, self.label)) 215 216 # If gRPC root server port is not specified, we can skip settings up the root server 217 if self.grpc_root_server_port != -1: 218 # Setup gRPC management channels 219 self.grpc_root_server_channel = grpc.insecure_channel("localhost:%d" % self.grpc_root_server_port) 220 221 self.grpc_root_server_ready = False 222 223 try: 224 logging.info("[%s] Waiting to connect to gRPC root server for %s, timeout is %d seconds" % 225 (self.type_identifier, self.label, GRPC_START_TIMEOUT_SEC)) 226 grpc.channel_ready_future(self.grpc_root_server_channel).result(timeout=GRPC_START_TIMEOUT_SEC) 227 logging.info("[%s] Successfully connected to gRPC root server for %s" % 228 (self.type_identifier, self.label)) 229 self.grpc_root_server_ready = True 230 except grpc.FutureTimeoutError: 231 logging.error("[%s] Failed to connect to gRPC root server for %s" % (self.type_identifier, self.label)) 232 233 asserts.assert_true(self.grpc_root_server_ready, 234 msg="gRPC root server did not start after running " + " ".join(self.cmd)) 235 236 self.grpc_channel = grpc.insecure_channel("localhost:%d" % self.grpc_port) 237 238 if self.verbose_mode: 239 self.grpc_channel = grpc.intercept_channel(self.grpc_channel, LoggingClientInterceptor(self.label)) 240 241 # Establish services from facades 242 if self.grpc_root_server_port != -1: 243 self.rootservice = facade_rootservice_pb2_grpc.RootFacadeStub(self.grpc_root_server_channel) 244 245 self.hal = hal_facade_pb2_grpc.HciHalFacadeStub(self.grpc_channel) 246 self.controller_read_only_property = facade_rootservice_pb2_grpc.ReadOnlyPropertyStub(self.grpc_channel) 247 self.hci = hci_facade_pb2_grpc.HciFacadeStub(self.grpc_channel) 248 self.l2cap = l2cap_facade_pb2_grpc.L2capClassicModuleFacadeStub(self.grpc_channel) 249 self.l2cap_le = l2cap_le_facade_pb2_grpc.L2capLeModuleFacadeStub(self.grpc_channel) 250 self.hci_acl_manager = acl_manager_facade_pb2_grpc.AclManagerFacadeStub(self.grpc_channel) 251 self.hci_le_acl_manager = le_acl_manager_facade_pb2_grpc.LeAclManagerFacadeStub(self.grpc_channel) 252 self.hci_le_initiator_address = le_initiator_address_facade_pb2_grpc.LeInitiatorAddressFacadeStub( 253 self.grpc_channel) 254 self.hci_controller = controller_facade_pb2_grpc.ControllerFacadeStub(self.grpc_channel) 255 self.hci_controller.GetMacAddressSimple = lambda: self.hci_controller.GetMacAddress(empty_proto.Empty()).address 256 self.hci_controller.GetLocalNameSimple = lambda: self.hci_controller.GetLocalName(empty_proto.Empty()).name 257 self.hci_le_advertising_manager = le_advertising_manager_facade_pb2_grpc.LeAdvertisingManagerFacadeStub( 258 self.grpc_channel) 259 self.hci_le_scanning_manager = le_scanning_manager_facade_pb2_grpc.LeScanningManagerFacadeStub( 260 self.grpc_channel) 261 self.neighbor = neighbor_facade_pb2_grpc.NeighborFacadeStub(self.grpc_channel) 262 self.security = security_facade_pb2_grpc.SecurityModuleFacadeStub(self.grpc_channel) 263 264 def get_crash_snippet_and_log_tail(self): 265 if is_subprocess_alive(self.backing_process): 266 return None, None 267 268 return read_crash_snippet_and_log_tail(self.backing_process_log_path) 269 270 def teardown(self): 271 """Tear down this device and clean up any resources. 272 - Must be called after setup() 273 - Should be executed before children classes' teardown() 274 :return: 275 """ 276 self.grpc_channel.close() 277 if self.grpc_root_server_port != -1: 278 self.grpc_root_server_channel.close() 279 stop_signal = self.gracefully_stop_backing_process() 280 try: 281 if stop_signal == 0: 282 raise RuntimeError("Failed to gracefully shutdown backing process") 283 return_code = self.backing_process.wait(timeout=self.WAIT_SIGINT_TIMEOUT_SECONDS) 284 except (subprocess.TimeoutExpired, RuntimeError): 285 logging.error("[%s] Failed to interrupt backing process via SIGINT, sending SIGKILL" % self.label) 286 stop_signal = signal.SIGKILL 287 self.backing_process.kill() 288 try: 289 return_code = self.backing_process.wait(timeout=self.WAIT_SIGKILL_TIMEOUT_SECONDS) 290 except subprocess.TimeoutExpired: 291 logging.error("Failed to kill backing process") 292 return_code = -65536 293 if return_code not in [-stop_signal, 0]: 294 logging.error("backing process %s stopped with code: %d" % (self.label, return_code)) 295 self.backing_process_logger.stop() 296 297 def wait_channel_ready(self): 298 future = grpc.channel_ready_future(self.grpc_channel) 299 try: 300 future.result(timeout=self.WAIT_CHANNEL_READY_TIMEOUT_SECONDS) 301 except grpc.FutureTimeoutError: 302 asserts.fail("[%s] wait channel ready timeout" % self.label) 303 304 @abstractmethod 305 def gracefully_stop_backing_process(self): 306 return NotImplemented 307 308 309class GdHostOnlyDevice(GdDeviceBase): 310 """ 311 Host only device where the backing process is running on the host machine 312 """ 313 314 def __init__(self, grpc_port: str, grpc_root_server_port: str, signal_port: str, cmd: List[str], label: str, 315 type_identifier: str, name: str, verbose_mode: bool): 316 super().__init__(grpc_port, grpc_root_server_port, signal_port, cmd, label, MOBLY_CONTROLLER_CONFIG_NAME, name, 317 verbose_mode) 318 self.host_only_device = True 319 # Enable LLVM code coverage output for host only tests 320 self.backing_process_profraw_path = pathlib.Path(self.log_path_base).joinpath( 321 "%s_%s_backing_coverage.profraw" % (self.type_identifier, self.label)) 322 self.environment["LLVM_PROFILE_FILE"] = str(self.backing_process_profraw_path) 323 llvm_binutils = pathlib.Path(get_gd_root()).joinpath("llvm_binutils").joinpath("bin") 324 llvm_symbolizer = llvm_binutils.joinpath("llvm-symbolizer") 325 if llvm_symbolizer.is_file(): 326 self.environment["ASAN_SYMBOLIZER_PATH"] = llvm_symbolizer 327 else: 328 logging.warning("[%s] Cannot find LLVM symbolizer at %s" % (self.label, str(llvm_symbolizer))) 329 self.profdata_path = self.get_coverage_profdata_path_for_host(self.test_runner_base_path, self.type_identifier, 330 self.label) 331 332 def setup(self): 333 # Ensure ports are available 334 # Only check on host only test, for Android devices, these ports will 335 # be opened on Android device and host machine ports will be occupied 336 # by sshd or adb forwarding 337 ports_needed = [self.grpc_port, self.grpc_root_server_port 338 ] if self.grpc_root_server_port != -1 else [self.grpc_port] 339 asserts.assert_true(make_ports_available(ports_needed), 340 "[%s] Failed to make backing process ports available" % self.label) 341 super().setup() 342 343 def teardown(self): 344 super().teardown() 345 self.merge_coverage_profdata_for_host(self.backing_process_profraw_path, self.profdata_path, self.label) 346 347 def get_coverage_info(self): 348 """ 349 Get information needed for coverage reporting 350 :return: a dictionary with all information needed for coverage reporting 351 """ 352 return { 353 "profdata_path": self.profdata_path, 354 "label": self.label, 355 "test_runner_base_path": self.test_runner_base_path, 356 "type_identifier": self.type_identifier, 357 "stack_bin": self.cmd[0] 358 } 359 360 def get_coverage_profdata_path_for_host(self, test_runner_base_path, type_identifier, label) -> pathlib.Path: 361 return pathlib.Path(test_runner_base_path).parent.parent.joinpath("%s_%s_backing_process_coverage.profdata" % 362 (type_identifier, label)) 363 364 def merge_coverage_profdata_for_host(self, backing_process_profraw_path, profdata_path: pathlib.Path, label): 365 if not backing_process_profraw_path.is_file(): 366 logging.info("[%s] Skip coverage report as there is no profraw file at %s" % 367 (label, str(backing_process_profraw_path))) 368 return 369 try: 370 if backing_process_profraw_path.stat().st_size <= 0: 371 logging.info("[%s] Skip coverage report as profraw file is empty at %s" % 372 (label, str(backing_process_profraw_path))) 373 return 374 except OSError: 375 logging.info("[%s] Skip coverage report as profraw file is inaccessible at %s" % 376 (label, str(backing_process_profraw_path))) 377 return 378 llvm_binutils = pathlib.Path(get_gd_root()).joinpath("llvm_binutils").joinpath("bin") 379 llvm_profdata = llvm_binutils.joinpath("llvm-profdata") 380 if not llvm_profdata.is_file(): 381 logging.info("[%s] Skip coverage report as llvm-profdata is not found at %s" % (label, str(llvm_profdata))) 382 return 383 logging.info("[%s] Merging coverage profdata" % label) 384 profdata_path_tmp = profdata_path.parent / (profdata_path.stem + "_tmp" + profdata_path.suffix) 385 # Merge with existing profdata if possible 386 profdata_cmd = [str(llvm_profdata), "merge", "-sparse", str(backing_process_profraw_path)] 387 if profdata_path.is_file(): 388 profdata_cmd.append(str(profdata_path)) 389 profdata_cmd += ["-o", str(profdata_path_tmp)] 390 logging.debug("Running llvm_profdata: %s" % " ".join(profdata_cmd)) 391 result = subprocess.run(profdata_cmd, stdout=subprocess.PIPE, stderr=subprocess.STDOUT) 392 if result.returncode != 0: 393 logging.warning("[%s] Failed to index profdata, cmd result: %r" % (label, result)) 394 profdata_path.unlink(missing_ok=True) 395 return 396 shutil.move(profdata_path_tmp, profdata_path) 397 398 def generate_coverage_report_for_host(self, coverage_info): 399 label = coverage_info["label"] 400 test_runner_base_path = coverage_info["test_runner_base_path"] 401 type_identifier = coverage_info["type_identifier"] 402 profdata_path = coverage_info["profdata_path"] 403 stack_bin = coverage_info["stack_bin"] 404 llvm_binutils = pathlib.Path(get_gd_root()).joinpath("llvm_binutils").joinpath("bin") 405 llvm_cov = llvm_binutils.joinpath("llvm-cov") 406 if not llvm_cov.is_file(): 407 logging.info("[%s] Skip coverage report as llvm-cov is not found at %s" % (label, str(llvm_cov))) 408 return 409 logging.info("[%s] Generating coverage report in JSON" % label) 410 coverage_result_path = pathlib.Path(test_runner_base_path).parent.parent.joinpath( 411 "%s_%s_backing_process_coverage.json" % (type_identifier, label)) 412 with coverage_result_path.open("w") as coverage_result_file: 413 llvm_cov_export_cmd = [ 414 str(llvm_cov), "export", "--format=text", "--ignore-filename-regex", "(external|out).*", 415 "--instr-profile", 416 str(profdata_path), 417 str(stack_bin) 418 ] 419 logging.debug("Running llvm_cov export: %s" % " ".join(llvm_cov_export_cmd)) 420 result = subprocess.run(llvm_cov_export_cmd, 421 stderr=subprocess.PIPE, 422 stdout=coverage_result_file, 423 cwd=os.path.join(get_gd_root())) 424 if result.returncode != 0: 425 logging.warning("[%s] Failed to generated coverage report, cmd result: %r" % (label, result)) 426 coverage_result_path.unlink(missing_ok=True) 427 return 428 logging.info("[%s] Generating coverage summary in text" % label) 429 coverage_summary_path = pathlib.Path(test_runner_base_path).parent.parent.joinpath( 430 "%s_%s_backing_process_coverage_summary.txt" % (type_identifier, label)) 431 with coverage_summary_path.open("w") as coverage_summary_file: 432 llvm_cov_report_cmd = [ 433 str(llvm_cov), "report", "--ignore-filename-regex", "(external|out).*", "--instr-profile", 434 str(profdata_path), 435 str(stack_bin) 436 ] 437 logging.debug("Running llvm_cov report: %s" % " ".join(llvm_cov_report_cmd)) 438 result = subprocess.run(llvm_cov_report_cmd, 439 stderr=subprocess.PIPE, 440 stdout=coverage_summary_file, 441 cwd=os.path.join(get_gd_root())) 442 if result.returncode != 0: 443 logging.warning("[%s] Failed to generated coverage summary, cmd result: %r" % (label, result)) 444 coverage_summary_path.unlink(missing_ok=True) 445 446 def gracefully_stop_backing_process(self): 447 stop_signal = signal.SIGINT 448 self.backing_process.send_signal(stop_signal) 449 return stop_signal 450 451 452class GdAndroidDevice(GdDeviceBase): 453 """Real Android device where the backing process is running on it 454 """ 455 456 WAIT_FOR_DEVICE_TIMEOUT_SECONDS = 180 457 WAIT_FOR_DEVICE_SIGINT_TIMEOUT_SECONDS = 1 458 ADB_ABORT_EXIT_CODE = 134 459 DEVICE_LIB_DIR = "/system/lib64" 460 DEVICE_BIN_DIR = "/system/bin" 461 462 def __init__(self, grpc_port: str, grpc_root_server_port: str, signal_port: str, cmd: List[str], label: str, 463 type_identifier: str, name: str, serial_number: str, verbose_mode: bool): 464 super().__init__(grpc_port, grpc_root_server_port, signal_port, cmd, label, type_identifier, name, verbose_mode) 465 asserts.assert_true(serial_number, "serial_number must not be None nor empty") 466 self.serial_number = serial_number 467 self.adb = BlueberryAdbProxy(serial_number) 468 469 def setup(self): 470 logging.info("Setting up device %s %s" % (self.label, self.serial_number)) 471 asserts.assert_true(self.adb.ensure_root(), "device %s cannot run as root", self.serial_number) 472 self.ensure_verity_disabled() 473 logging.info("Confirmed that verity is disabled on device %s %s" % (self.label, self.serial_number)) 474 475 # Try freeing ports and ignore results 476 asserts.assert_true(make_ports_available((self.grpc_port, self.grpc_root_server_port, self.signal_port)), 477 "[%s] Failed to make backing process ports available" % self.label) 478 self.cleanup_port_forwarding() 479 self.sync_device_time() 480 logging.info("Ports cleaned up and clock is set for device %s %s" % (self.label, self.serial_number)) 481 482 # Set up port forwarding or reverse or die 483 self.tcp_forward_or_die(self.grpc_port, self.grpc_port) 484 if self.grpc_root_server_port != -1: 485 self.tcp_forward_or_die(self.grpc_root_server_port, self.grpc_root_server_port) 486 self.tcp_reverse_or_die(self.signal_port, self.signal_port) 487 logging.info("Port forwarding done on device %s %s" % (self.label, self.serial_number)) 488 489 # Push test binaries 490 local_dir = os.path.join(get_gd_root(), "target") 491 492 def generate_dir_pair(local_dir, device_dir, filename): 493 return os.path.join(local_dir, filename), os.path.join(device_dir, filename) 494 495 # Do not override exist libraries shared by other binaries on the Android device to avoid corrupting the Android device 496 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_BIN_DIR, "bluetooth_stack_with_facade")) 497 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "android.hardware.bluetooth@1.0.so"), 498 overwrite_existing=False) 499 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "android.hardware.bluetooth@1.1.so"), 500 overwrite_existing=False) 501 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libandroid_runtime_lazy.so"), 502 overwrite_existing=False) 503 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libbase.so"), overwrite_existing=False) 504 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libbinder_ndk.so"), 505 overwrite_existing=False) 506 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libbinder.so"), overwrite_existing=False) 507 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libc++.so"), overwrite_existing=False) 508 # libclang_rt.asan-aarch64-android.so is only needed for ASAN build and is automatically included on device 509 #self.push_or_die( 510 # *generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libclang_rt.asan-aarch64-android.so"), 511 # overwrite_existing=False) 512 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libcrypto.so"), overwrite_existing=False) 513 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libcutils.so"), overwrite_existing=False) 514 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libgrpc_wrap.so"), 515 overwrite_existing=False) 516 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libgrpc++.so")) 517 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libhidlbase.so"), overwrite_existing=False) 518 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "liblog.so"), overwrite_existing=False) 519 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "liblzma.so"), overwrite_existing=False) 520 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libprotobuf-cpp-full.so")) 521 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libssl.so"), overwrite_existing=False) 522 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libgrpc++.so")) 523 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libunwindstack.so"), 524 overwrite_existing=False) 525 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libutils.so"), overwrite_existing=False) 526 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libgrpc++.so")) 527 self.push_or_die(*generate_dir_pair(local_dir, self.DEVICE_LIB_DIR, "libz.so"), overwrite_existing=False) 528 529 logging.info("Binaries pushed to device %s %s" % (self.label, self.serial_number)) 530 531 try: 532 self.adb.shell("rm /data/misc/bluetooth/logs/btsnoop_hci.log") 533 except AdbError as error: 534 if ADB_FILE_NOT_EXIST_ERROR not in str(error): 535 logging.error("Error during setup: " + str(error)) 536 537 try: 538 self.adb.shell("rm /data/misc/bluetooth/logs/btsnooz_hci.log") 539 except AdbError as error: 540 if ADB_FILE_NOT_EXIST_ERROR not in str(error): 541 logging.error("Error during setup: " + str(error)) 542 543 try: 544 self.adb.shell("rm /data/misc/bluedroid/bt_config.conf") 545 except AdbError as error: 546 if ADB_FILE_NOT_EXIST_ERROR not in str(error): 547 logging.error("Error during setup: " + str(error)) 548 549 logging.info("Old logs removed from device %s %s" % (self.label, self.serial_number)) 550 551 # Ensure Bluetooth is disabled 552 self.ensure_no_output(self.adb.shell("settings put global ble_scan_always_enabled 0")) 553 self.adb.shell("cmd bluetooth_manager disable") 554 device_bt_state = int(self.adb.shell("settings get global bluetooth_on")) 555 asserts.assert_equal(device_bt_state, 0, 556 "Failed to disable Bluetooth on device %s %s" % (self.label, self.serial_number)) 557 logging.info("Bluetooth disabled on device %s %s" % (self.label, self.serial_number)) 558 559 # Start logcat logging 560 self.logcat_output_path = os.path.join( 561 self.log_path_base, '%s_%s_%s_logcat_logs.txt' % (self.type_identifier, self.label, self.serial_number)) 562 self.logcat_cmd = ["adb", "-s", self.serial_number, "logcat", "-T", "1", "-v", "year", "-v", "uid"] 563 logging.debug("Running %s", " ".join(self.logcat_cmd)) 564 self.logcat_process = subprocess.Popen(self.logcat_cmd, 565 stdout=subprocess.PIPE, 566 stderr=subprocess.STDOUT, 567 universal_newlines=True) 568 asserts.assert_true(self.logcat_process, msg="Cannot start logcat_process at " + " ".join(self.logcat_cmd)) 569 asserts.assert_true(is_subprocess_alive(self.logcat_process), 570 msg="logcat_process stopped immediately after running " + " ".join(self.logcat_cmd)) 571 self.logcat_logger = AsyncSubprocessLogger(self.logcat_process, [self.logcat_output_path], 572 log_to_stdout=self.verbose_mode, 573 tag="%s_%s" % (self.label, self.serial_number), 574 color=self.terminal_color) 575 576 # Done run parent setup 577 logging.info("Done preparation for %s, starting backing process" % self.serial_number) 578 super().setup() 579 580 def teardown(self): 581 super().teardown() 582 stop_signal = signal.SIGINT 583 self.logcat_process.send_signal(stop_signal) 584 try: 585 return_code = self.logcat_process.wait(timeout=self.WAIT_FOR_DEVICE_SIGINT_TIMEOUT_SECONDS) 586 except subprocess.TimeoutExpired: 587 logging.error("[%s_%s] Failed to interrupt logcat process via SIGINT, sending SIGKILL" % 588 (self.label, self.serial_number)) 589 stop_signal = signal.SIGKILL 590 self.logcat_process.kill() 591 try: 592 return_code = self.logcat_process.wait(timeout=self.WAIT_SIGKILL_TIMEOUT_SECONDS) 593 except subprocess.TimeoutExpired: 594 logging.error("Failed to kill logcat_process %s %s" % (self.label, self.serial_number)) 595 return_code = -65536 596 if return_code not in [-stop_signal, 0]: 597 logging.error("logcat_process %s_%s stopped with code: %d" % (self.label, self.serial_number, return_code)) 598 self.logcat_logger.stop() 599 self.cleanup_port_forwarding() 600 self.pull_logs(self.log_path_base) 601 602 def pull_logs(self, base_dir): 603 try: 604 self.adb.pull([ 605 "/data/misc/bluetooth/logs/btsnoop_hci.log", 606 str(os.path.join(base_dir, "%s_btsnoop_hci.log" % self.label)) 607 ]) 608 except AdbError as error: 609 # Some tests have no snoop logs, and that's OK 610 if ADB_FILE_NOT_EXIST_ERROR not in str(error): 611 logging.error(PULL_LOG_FILE_ERROR_MSG_PREFIX + str(error)) 612 try: 613 self.adb.pull( 614 ["/data/misc/bluedroid/bt_config.conf", 615 str(os.path.join(base_dir, "%s_bt_config.conf" % self.label))]) 616 except AdbError as error: 617 # Some tests have no config file, and that's OK 618 if ADB_FILE_NOT_EXIST_ERROR not in str(error): 619 logging.error(PULL_LOG_FILE_ERROR_MSG_PREFIX + str(error)) 620 621 def cleanup_port_forwarding(self): 622 try: 623 self.adb.remove_tcp_forward(self.grpc_port) 624 except AdbError as error: 625 msg = PORT_FORWARDING_ERROR_MSG_PREFIX + str(error) 626 if "not found" in msg: 627 logging.debug(msg) 628 else: 629 logging.error(msg) 630 631 try: 632 if self.grpc_root_server_port != -1: 633 self.adb.remove_tcp_forward(self.grpc_root_server_port) 634 except AdbError as error: 635 msg = PORT_FORWARDING_ERROR_MSG_PREFIX + str(error) 636 if "not found" in msg: 637 logging.debug(msg) 638 else: 639 logging.error(msg) 640 641 try: 642 self.adb.reverse(["--remove", "tcp:%d" % self.signal_port]) 643 except AdbError as error: 644 msg = PORT_FORWARDING_ERROR_MSG_PREFIX + str(error) 645 if "not found" in msg: 646 logging.debug(msg) 647 else: 648 logging.error(msg) 649 650 @staticmethod 651 def ensure_no_output(result): 652 """ 653 Ensure a command has not output 654 """ 655 asserts.assert_true(result is None or len(result) == 0, 656 msg="command returned something when it shouldn't: %s" % result) 657 658 def sync_device_time(self): 659 self.adb.shell("settings put global auto_time 0") 660 self.adb.shell("settings put global auto_time_zone 0") 661 device_tz = self.adb.shell("date +%z").decode(UTF_8).rstrip() 662 asserts.assert_true(device_tz, "date +%z must return device timezone, " 663 "but returned {} instead".format(device_tz)) 664 host_tz = time.strftime("%z") 665 if device_tz != host_tz: 666 target_timezone = utils.get_timezone_olson_id() 667 logging.debug("Device timezone %s does not match host timezone %s, " 668 "syncing them by setting timezone to %s" % (device_tz, host_tz, target_timezone)) 669 self.adb.shell("setprop persist.sys.timezone %s" % target_timezone) 670 self.reboot() 671 self.adb.remount() 672 device_tz = self.adb.shell("date +%z").decode(UTF_8).rstrip() 673 asserts.assert_equal( 674 host_tz, device_tz, "Device timezone %s still does not match host " 675 "timezone %s after reset" % (device_tz, host_tz)) 676 self.adb.shell("date %s" % time.strftime("%m%d%H%M%Y.%S")) 677 datetime_format = "%Y-%m-%dT%H:%M:%S%z" 678 try: 679 device_time = datetime.strptime( 680 self.adb.shell("date +'%s'" % datetime_format).decode(UTF_8).rstrip(), datetime_format) 681 except ValueError: 682 asserts.fail("Failed to get time after sync") 683 return 684 # Include ADB delay that might be longer in SSH environment 685 max_delta_seconds = 3 686 host_time = datetime.now(tz=device_time.tzinfo) 687 asserts.assert_almost_equal((device_time - host_time).total_seconds(), 688 0, 689 msg="Device time %s and host time %s off by >%dms after sync" % 690 (device_time.isoformat(), host_time.isoformat(), int(max_delta_seconds * 1000)), 691 delta=max_delta_seconds) 692 693 def push_or_die(self, src_file_path, dst_file_path, push_timeout=300, overwrite_existing=True): 694 """Pushes a file to the Android device 695 696 Args: 697 src_file_path: The path to the file to install. 698 dst_file_path: The destination of the file. 699 push_timeout: How long to wait for the push to finish in seconds 700 """ 701 if not overwrite_existing and self.adb.path_exists(dst_file_path): 702 logging.debug("Skip pushing {} to {} as it already exists on device".format(src_file_path, dst_file_path)) 703 return 704 out = self.adb.push([src_file_path, dst_file_path], timeout=push_timeout).decode(UTF_8).rstrip() 705 if 'error' in out: 706 asserts.fail('Unable to push file %s to %s due to %s' % (src_file_path, dst_file_path, out)) 707 708 def tcp_forward_or_die(self, host_port, device_port, num_retry=1): 709 """ 710 Forward a TCP port from host to device or fail 711 :param host_port: host port, int, 0 for adb to assign one 712 :param device_port: device port, int 713 :param num_retry: number of times to reboot and retry this before dying 714 :return: host port int 715 """ 716 error_or_port = self.adb.tcp_forward(host_port, device_port) 717 if not error_or_port: 718 logging.debug("host port %d was already forwarded" % host_port) 719 return host_port 720 if not isinstance(error_or_port, int): 721 if num_retry > 0: 722 # If requested, reboot an retry 723 num_retry -= 1 724 logging.warning("[%s] Failed to TCP forward host port %d to " 725 "device port %d, num_retries left is %d" % 726 (self.label, host_port, device_port, num_retry)) 727 self.reboot() 728 self.adb.remount() 729 return self.tcp_forward_or_die(host_port, device_port, num_retry=num_retry) 730 asserts.fail('Unable to forward host port %d to device port %d, error %s' % 731 (host_port, device_port, error_or_port)) 732 return error_or_port 733 734 def tcp_reverse_or_die(self, device_port, host_port, num_retry=1): 735 """ 736 Forward a TCP port from device to host or fail 737 :param device_port: device port, int, 0 for adb to assign one 738 :param host_port: host port, int 739 :param num_retry: number of times to reboot and retry this before dying 740 :return: device port int 741 """ 742 error_or_port = self.adb.reverse(["tcp:%d" % device_port, "tcp:%d" % host_port]) 743 if not error_or_port: 744 logging.debug("device port %d was already reversed" % device_port) 745 return device_port 746 try: 747 error_or_port = int(error_or_port) 748 except ValueError: 749 if num_retry > 0: 750 # If requested, reboot an retry 751 num_retry -= 1 752 logging.warning("[%s] Failed to TCP reverse device port %d to " 753 "host port %d, num_retries left is %d" % 754 (self.label, device_port, host_port, num_retry)) 755 self.reboot() 756 self.adb.remount() 757 return self.tcp_reverse_or_die(device_port, host_port, num_retry=num_retry) 758 asserts.fail('Unable to reverse device port %d to host port %d, error %s' % 759 (device_port, host_port, error_or_port)) 760 return error_or_port 761 762 def ensure_verity_disabled(self): 763 """Ensures that verity is enabled. 764 765 If verity is not enabled, this call will reboot the phone. Note that 766 this only works on debuggable builds. 767 """ 768 logging.debug("Disabling verity and remount for %s", self.serial_number) 769 # The below properties will only exist if verity has been enabled. 770 system_verity = self.adb.getprop('partition.system.verified') 771 vendor_verity = self.adb.getprop('partition.vendor.verified') 772 if system_verity or vendor_verity: 773 self.adb.disable_verity() 774 self.reboot() 775 self.adb.remount() 776 self.adb.wait_for_device(timeout=self.WAIT_FOR_DEVICE_TIMEOUT_SECONDS) 777 778 def reboot(self, timeout_minutes=15.0): 779 """Reboots the device. 780 781 Reboot the device, wait for device to complete booting. 782 """ 783 logging.debug("Rebooting %s", self.serial_number) 784 self.adb.reboot() 785 786 timeout_start = time.time() 787 timeout = timeout_minutes * 60 788 # Android sometimes return early after `adb reboot` is called. This 789 # means subsequent calls may make it to the device before the reboot 790 # goes through, return false positives for getprops such as 791 # sys.boot_completed. 792 while time.time() < timeout_start + timeout: 793 try: 794 logging.debug("waiting for device %s to turn off", self.serial_number) 795 self.adb.get_state() 796 logging.debug("device %s not turned off yet", self.serial_number) 797 time.sleep(.1) 798 except AdbError: 799 # get_state will raise an error if the device is not found. We 800 # want the device to be missing to prove the device has kicked 801 # off the reboot. 802 logging.debug("device %s is turned off, waiting for it to boot", self.serial_number) 803 break 804 minutes_left = timeout_minutes - (time.time() - timeout_start) / 60.0 805 self.wait_for_boot_completion(timeout_minutes=minutes_left) 806 asserts.assert_true(self.adb.ensure_root(), "device %s cannot run as root after reboot" % self.serial_number) 807 808 def wait_for_boot_completion(self, timeout_minutes=15.0): 809 """ 810 Waits for Android framework to broadcast ACTION_BOOT_COMPLETED. 811 :param timeout_minutes: number of minutes to wait 812 """ 813 timeout_start = time.time() 814 timeout = timeout_minutes * 60 815 816 self.adb.wait_for_device(timeout=self.WAIT_FOR_DEVICE_TIMEOUT_SECONDS) 817 while time.time() < timeout_start + timeout: 818 try: 819 completed = self.adb.getprop("sys.boot_completed") 820 if completed == '1': 821 return 822 except AdbError: 823 # adb shell calls may fail during certain period of booting 824 # process, which is normal. Ignoring these errors. 825 pass 826 time.sleep(5) 827 asserts.fail(msg='Device %s booting process timed out.' % self.serial_number) 828 829 def gracefully_stop_backing_process(self): 830 """ 831 Gracefully stops backing process 832 :return: expected backing process exit code on success, 0 on error 833 """ 834 backing_process_pid = None 835 # Since we do not know which segment of self.cmd is the command running 836 # on the Android device. We have to iterate with trial and error. 837 cmd = self.cmd 838 if len(self.cmd) >= 5: 839 # skip adb -s serial shell to speed up the search 840 # we don't know if any environment variables are set up before the 841 # actual command and hence has to try from the 4th argument 842 cmd = self.cmd[4:] + self.cmd[:4] 843 for segment in cmd: 844 try: 845 # pgrep only takes 16 bytes including null terminator 846 # -f cannot be used because that include the full command args 847 current_cmd = pathlib.Path(segment).stem[:15] 848 # -x matches whole command, cannot avoid as short segment may partially match 849 # -n returnes the newest command matched 850 backing_process_pid = int(self.adb.shell("pgrep -n -x {}".format(current_cmd))) 851 logging.debug("Found backing process name on Android as {}, pid is {}".format( 852 segment, backing_process_pid)) 853 except (AdbError, ValueError) as e: 854 logging.debug("Failed to run pgrep {}".format(e)) 855 if backing_process_pid is not None: 856 break 857 if backing_process_pid is None: 858 logging.warning("Failed to get pid for cmd {}".format(self.cmd)) 859 try: 860 logging.debug(self.adb.shell("ps -A | grep bluetooth")) 861 except AdbError: 862 pass 863 return 0 864 stop_signal = signal.SIGINT 865 self.adb.shell("kill -{} {}".format(stop_signal, backing_process_pid)) 866 logging.debug("Sent SIGINT to backing process at pid {}".format(backing_process_pid)) 867 stop_signal = -self.ADB_ABORT_EXIT_CODE 868 return stop_signal 869