class GdDeviceBase: def __init__(self, grpc_port, grpc_root_server_port, signal_port, cmd, label, type_identifier, serial_number): self.label = label if label is not None else grpc_port # logging.log_path only exists when this is used in an ACTS test run. self.log_path_base = context.get_current_context( ).get_full_output_path() backing_process_logpath = os.path.join( self.log_path_base, '%s_%s_backing_logs.txt' % (type_identifier, label)) self.backing_process_logs = open(backing_process_logpath, 'w') cmd_str = json.dumps(cmd) if "--btsnoop=" not in cmd_str: btsnoop_path = os.path.join(self.log_path_base, '%s_btsnoop_hci.log' % label) cmd.append("--btsnoop=" + btsnoop_path) self.serial_number = serial_number if self.serial_number: self.ad = AdbProxy(serial_number) self.ad.shell("date " + time.strftime("%m%d%H%M%Y.%S")) self.ad.tcp_forward(int(grpc_port), int(grpc_port)) self.ad.tcp_forward(int(grpc_root_server_port), int(grpc_root_server_port)) self.ad.reverse("tcp:%s tcp:%s" % (signal_port, signal_port)) self.ad.push( os.path.join(ANDROID_PRODUCT_OUT, "system/bin/bluetooth_stack_with_facade"), "system/bin") self.ad.push( os.path.join(ANDROID_PRODUCT_OUT, "system/lib64/libbluetooth_gd.so"), "system/lib64") self.ad.push( os.path.join(ANDROID_PRODUCT_OUT, "system/lib64/libgrpc++_unsecure.so"), "system/lib64") self.ad.shell("logcat -c") self.ad.shell("rm /data/misc/bluetooth/logs/btsnoop_hci.log") self.ad.shell("svc bluetooth disable") tester_signal_socket = socket.socket(socket.AF_INET, socket.SOCK_STREAM) tester_signal_socket.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1) socket_address = ('localhost', int(signal_port)) tester_signal_socket.bind(socket_address) tester_signal_socket.listen(1) self.backing_process = subprocess.Popen( cmd, cwd=os.getcwd(), env=os.environ.copy(), stdout=self.backing_process_logs, stderr=self.backing_process_logs) tester_signal_socket.accept() tester_signal_socket.close() self.grpc_root_server_channel = grpc.insecure_channel( "localhost:" + grpc_root_server_port) self.grpc_port = int(grpc_port) self.grpc_channel = grpc.insecure_channel("localhost:" + grpc_port) def clean_up(self): self.grpc_channel.close() self.grpc_root_server_channel.close() stop_signal = signal.SIGINT self.backing_process.send_signal(stop_signal) backing_process_return_code = self.backing_process.wait() self.backing_process_logs.close() if backing_process_return_code not in [-stop_signal, 0]: logging.error("backing process %s stopped with code: %d" % (self.label, backing_process_return_code)) if self.serial_number: self.ad.shell("logcat -d -f /data/misc/bluetooth/logs/system_log") self.ad.pull( "/data/misc/bluetooth/logs/btsnoop_hci.log %s" % os.path.join( self.log_path_base, "%s_btsnoop_hci.log" % self.label)) self.ad.pull( "/data/misc/bluetooth/logs/system_log %s" % os.path.join(self.log_path_base, "%s_system_log" % self.label)) def wait_channel_ready(self): future = grpc.channel_ready_future(self.grpc_channel) try: future.result(timeout=WAIT_CHANNEL_READY_TIMEOUT) except grpc.FutureTimeoutError: logging.error("wait channel ready timeout")
class GdAndroidDevice(GdDeviceBase): """Real Android device where the backing process is running on it """ WAIT_FOR_DEVICE_TIMEOUT_SECONDS = 180 def __init__(self, grpc_port: str, grpc_root_server_port: str, signal_port: str, cmd: List[str], label: str, type_identifier: str, name: str, serial_number: str, verbose_mode: bool): super().__init__(grpc_port, grpc_root_server_port, signal_port, cmd, label, type_identifier, name, verbose_mode) asserts.assert_true(serial_number, "serial_number must not be None nor empty") self.serial_number = serial_number self.adb = AdbProxy(serial_number) def setup(self): logging.info("Setting up device %s %s" % (self.label, self.serial_number)) asserts.assert_true(self.adb.ensure_root(), "device %s cannot run as root", self.serial_number) # Try freeing ports and ignore results self.cleanup_port_forwarding() self.sync_device_time() # Set up port forwarding or reverse or die self.tcp_forward_or_die(self.grpc_port, self.grpc_port) self.tcp_forward_or_die(self.grpc_root_server_port, self.grpc_root_server_port) self.tcp_reverse_or_die(self.signal_port, self.signal_port) # Push test binaries self.ensure_verity_disabled() self.push_or_die(os.path.join(get_gd_root(), "target", "bluetooth_stack_with_facade"), "system/bin") self.push_or_die(os.path.join(get_gd_root(), "target", "libbluetooth_gd.so"), "system/lib64") self.push_or_die(os.path.join(get_gd_root(), "target", "libgrpc++_unsecure.so"), "system/lib64") try: self.adb.shell("rm /data/misc/bluetooth/logs/btsnoop_hci.log") except AdbCommandError as error: logging.warning("Failed to remove old btsnoop log: " + str(error)) try: self.adb.shell("rm /data/misc/bluetooth/logs/btsnooz_hci.log") except AdbCommandError as error: logging.warning("Failed to remove old btsnooz log: " + str(error)) try: self.adb.shell("rm /data/misc/bluedroid/bt_config.conf") except AdbCommandError as error: logging.warning("Failed to remove old bt config: " + str(error)) try: self.adb.shell("rm /data/misc/bluedroid/bt_config.bak") except AdbCommandError as error: logging.warning("Failed to remove back up config: " + str(error)) self.ensure_no_output(self.adb.shell("svc bluetooth disable")) # Start logcat logging self.logcat_output_path = os.path.join( self.log_path_base, '%s_%s_%s_logcat_logs.txt' % (self.type_identifier, self.label, self.serial_number)) self.logcat_cmd = ["adb", "-s", self.serial_number, "logcat", "-T", "1", "-v", "year", "-v", "uid"] logging.debug("Running %s", " ".join(self.logcat_cmd)) self.logcat_process = subprocess.Popen( self.logcat_cmd, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, universal_newlines=True) asserts.assert_true(self.logcat_process, msg="Cannot start logcat_process at " + " ".join(self.logcat_cmd)) asserts.assert_true( is_subprocess_alive(self.logcat_process), msg="logcat_process stopped immediately after running " + " ".join(self.logcat_cmd)) self.logcat_logger = AsyncSubprocessLogger( self.logcat_process, [self.logcat_output_path], log_to_stdout=self.verbose_mode, tag="%s_%s" % (self.label, self.serial_number), color=self.terminal_color) # Done run parent setup logging.info("Done preparation for %s, starting backing process" % self.serial_number) super().setup() def teardown(self): super().teardown() stop_signal = signal.SIGINT self.logcat_process.send_signal(stop_signal) try: return_code = self.logcat_process.wait(timeout=self.WAIT_CHANNEL_READY_TIMEOUT_SECONDS) except subprocess.TimeoutExpired: logging.error("[%s_%s] Failed to interrupt logcat process via SIGINT, sending SIGKILL" % (self.label, self.serial_number)) stop_signal = signal.SIGKILL self.logcat_process.kill() try: return_code = self.logcat_process.wait(timeout=self.WAIT_CHANNEL_READY_TIMEOUT_SECONDS) except subprocess.TimeoutExpired: logging.error("Failed to kill logcat_process %s %s" % (self.label, self.serial_number)) return_code = -65536 if return_code not in [-stop_signal, 0]: logging.error("logcat_process %s_%s stopped with code: %d" % (self.label, self.serial_number, return_code)) self.logcat_logger.stop() self.cleanup_port_forwarding() self.pull_logs(self.log_path_base) def pull_logs(self, base_dir): try: self.adb.pull("/data/misc/bluetooth/logs/btsnoop_hci.log %s" % os.path.join( base_dir, "%s_btsnoop_hci.log" % self.label)) self.adb.pull( "/data/misc/bluedroid/bt_config.conf %s" % os.path.join(base_dir, "%s_bt_config.conf" % self.label)) self.adb.pull( "/data/misc/bluedroid/bt_config.bak %s" % os.path.join(base_dir, "%s_bt_config.bak" % self.label)) except AdbCommandError as error: logging.warning("Failed to pull logs from device: " + str(error)) def cleanup_port_forwarding(self): try: self.adb.remove_tcp_forward(self.grpc_port) except AdbError as error: logging.warning("Failed to cleanup gRPC port: " + str(error)) try: self.adb.remove_tcp_forward(self.grpc_root_server_port) except AdbError as error: logging.warning("Failed to cleanup gRPC server port: " + str(error)) try: self.adb.reverse("--remove tcp:%d" % self.signal_port) except AdbError as error: logging.warning("Failed to cleanup signal port: " + str(error)) @staticmethod def ensure_no_output(result): """ Ensure a command has not output """ asserts.assert_true( result is None or len(result) == 0, msg="command returned something when it shouldn't: %s" % result) def sync_device_time(self): self.adb.shell("settings put global auto_time 0") self.adb.shell("settings put global auto_time_zone 0") device_tz = self.adb.shell("date +%z") asserts.assert_true(device_tz, "date +%z must return device timezone, " "but returned {} instead".format(device_tz)) host_tz = time.strftime("%z") if device_tz != host_tz: target_timezone = utils.get_timezone_olson_id() logging.debug("Device timezone %s does not match host timezone %s, " "syncing them by setting timezone to %s" % (device_tz, host_tz, target_timezone)) self.adb.shell("setprop persist.sys.timezone %s" % target_timezone) self.reboot() device_tz = self.adb.shell("date +%z") asserts.assert_equal( host_tz, device_tz, "Device timezone %s still does not match host " "timezone %s after reset" % (device_tz, host_tz)) self.adb.shell("date %s" % time.strftime("%m%d%H%M%Y.%S")) datetime_format = "%Y-%m-%dT%H:%M:%S%z" try: device_time = datetime.strptime(self.adb.shell("date +'%s'" % datetime_format), datetime_format) except ValueError: asserts.fail("Failed to get time after sync") return # Include ADB delay that might be longer in SSH environment max_delta_seconds = 3 host_time = datetime.now(tz=device_time.tzinfo) asserts.assert_almost_equal( (device_time - host_time).total_seconds(), 0, msg="Device time %s and host time %s off by >%dms after sync" % (device_time.isoformat(), host_time.isoformat(), int(max_delta_seconds * 1000)), delta=max_delta_seconds) def push_or_die(self, src_file_path, dst_file_path, push_timeout=300): """Pushes a file to the Android device Args: src_file_path: The path to the file to install. dst_file_path: The destination of the file. push_timeout: How long to wait for the push to finish in seconds """ out = self.adb.push('%s %s' % (src_file_path, dst_file_path), timeout=push_timeout) if 'error' in out: asserts.fail('Unable to push file %s to %s due to %s' % (src_file_path, dst_file_path, out)) def tcp_forward_or_die(self, host_port, device_port, num_retry=1): """ Forward a TCP port from host to device or fail :param host_port: host port, int, 0 for adb to assign one :param device_port: device port, int :param num_retry: number of times to reboot and retry this before dying :return: host port int """ error_or_port = self.adb.tcp_forward(host_port, device_port) if not error_or_port: logging.debug("host port %d was already forwarded" % host_port) return host_port if not isinstance(error_or_port, int): if num_retry > 0: # If requested, reboot an retry num_retry -= 1 logging.warning( "[%s] Failed to TCP forward host port %d to " "device port %d, num_retries left is %d" % (self.label, host_port, device_port, num_retry)) self.reboot() return self.tcp_forward_or_die(host_port, device_port, num_retry=num_retry) asserts.fail( 'Unable to forward host port %d to device port %d, error %s' % (host_port, device_port, error_or_port)) return error_or_port def tcp_reverse_or_die(self, device_port, host_port, num_retry=1): """ Forward a TCP port from device to host or fail :param device_port: device port, int, 0 for adb to assign one :param host_port: host port, int :param num_retry: number of times to reboot and retry this before dying :return: device port int """ error_or_port = self.adb.reverse("tcp:%d tcp:%d" % (device_port, host_port)) if not error_or_port: logging.debug("device port %d was already reversed" % device_port) return device_port try: error_or_port = int(error_or_port) except ValueError: if num_retry > 0: # If requested, reboot an retry num_retry -= 1 logging.warning( "[%s] Failed to TCP reverse device port %d to " "host port %d, num_retries left is %d" % (self.label, device_port, host_port, num_retry)) self.reboot() return self.tcp_reverse_or_die(device_port, host_port, num_retry=num_retry) asserts.fail( 'Unable to reverse device port %d to host port %d, error %s' % (device_port, host_port, error_or_port)) return error_or_port def ensure_verity_disabled(self): """Ensures that verity is enabled. If verity is not enabled, this call will reboot the phone. Note that this only works on debuggable builds. """ logging.debug("Disabling verity and remount for %s", self.serial_number) # The below properties will only exist if verity has been enabled. system_verity = self.adb.getprop('partition.system.verified') vendor_verity = self.adb.getprop('partition.vendor.verified') if system_verity or vendor_verity: self.adb.disable_verity() self.reboot() self.adb.remount() self.adb.wait_for_device(timeout=self.WAIT_FOR_DEVICE_TIMEOUT_SECONDS) def reboot(self, timeout_minutes=15.0): """Reboots the device. Reboot the device, wait for device to complete booting. """ logging.debug("Rebooting %s", self.serial_number) self.adb.reboot() timeout_start = time.time() timeout = timeout_minutes * 60 # Android sometimes return early after `adb reboot` is called. This # means subsequent calls may make it to the device before the reboot # goes through, return false positives for getprops such as # sys.boot_completed. while time.time() < timeout_start + timeout: try: self.adb.get_state() time.sleep(.1) except AdbError: # get_state will raise an error if the device is not found. We # want the device to be missing to prove the device has kicked # off the reboot. break minutes_left = timeout_minutes - (time.time() - timeout_start) / 60.0 self.wait_for_boot_completion(timeout_minutes=minutes_left) asserts.assert_true(self.adb.ensure_root(), "device %s cannot run as root after reboot", self.serial_number) def wait_for_boot_completion(self, timeout_minutes=15.0): """ Waits for Android framework to broadcast ACTION_BOOT_COMPLETED. :param timeout_minutes: number of minutes to wait """ timeout_start = time.time() timeout = timeout_minutes * 60 self.adb.wait_for_device(timeout=self.WAIT_FOR_DEVICE_TIMEOUT_SECONDS) while time.time() < timeout_start + timeout: try: completed = self.adb.getprop("sys.boot_completed") if completed == '1': return except AdbError: # adb shell calls may fail during certain period of booting # process, which is normal. Ignoring these errors. pass time.sleep(5) asserts.fail(msg='Device %s booting process timed out.' % self.serial_number)
class GdAndroidDevice(GdDeviceBase): """Real Android device where the backing process is running on it """ WAIT_FOR_DEVICE_TIMEOUT_SECONDS = 180 def __init__(self, grpc_port: str, grpc_root_server_port: str, signal_port: str, cmd: List[str], label: str, type_identifier: str, name: str, serial_number: str): super().__init__(grpc_port, grpc_root_server_port, signal_port, cmd, label, type_identifier, name) asserts.assert_true(serial_number, "serial_number must not be None nor empty") self.serial_number = serial_number self.adb = AdbProxy(serial_number) def setup(self): self.ensure_verity_disabled() asserts.assert_true( self.adb.ensure_root(), msg="device %s cannot run as root after enabling verity" % self.serial_number) self.adb.shell("date " + time.strftime("%m%d%H%M%Y.%S")) # Try freeing ports and ignore results self.adb.remove_tcp_forward(self.grpc_port) self.adb.remove_tcp_forward(self.grpc_root_server_port) self.adb.reverse("--remove tcp:%d" % self.signal_port) # Set up port forwarding or reverse or die self.tcp_forward_or_die(self.grpc_port, self.grpc_port) self.tcp_forward_or_die(self.grpc_root_server_port, self.grpc_root_server_port) self.tcp_reverse_or_die(self.signal_port, self.signal_port) # Puh test binaries self.push_or_die( os.path.join(get_gd_root(), "target", "bluetooth_stack_with_facade"), "system/bin") self.push_or_die( os.path.join(get_gd_root(), "target", "libbluetooth_gd.so"), "system/lib64") self.push_or_die( os.path.join(get_gd_root(), "target", "libgrpc++_unsecure.so"), "system/lib64") self.ensure_no_output(self.adb.shell("logcat -c")) self.adb.shell("rm /data/misc/bluetooth/logs/btsnoop_hci.log") self.ensure_no_output(self.adb.shell("svc bluetooth disable")) super().setup() def teardown(self): super().teardown() self.adb.remove_tcp_forward(self.grpc_port) self.adb.remove_tcp_forward(self.grpc_root_server_port) self.adb.reverse("--remove tcp:%d" % self.signal_port) self.adb.shell("logcat -d -f /data/misc/bluetooth/logs/system_log") self.adb.pull( "/data/misc/bluetooth/logs/btsnoop_hci.log %s" % os.path.join( self.log_path_base, "%s_btsnoop_hci.log" % self.label)) self.adb.pull("/data/misc/bluetooth/logs/system_log %s" % os.path.join( self.log_path_base, "%s_system_log" % self.label)) @staticmethod def ensure_no_output(result): """ Ensure a command has not output """ asserts.assert_true( result is None or len(result) == 0, msg="command returned something when it shouldn't: %s" % result) def push_or_die(self, src_file_path, dst_file_path, push_timeout=300): """Pushes a file to the Android device Args: src_file_path: The path to the file to install. dst_file_path: The destination of the file. push_timeout: How long to wait for the push to finish in seconds """ try: self.adb.ensure_root() self.ensure_verity_disabled() out = self.adb.push( '%s %s' % (src_file_path, dst_file_path), timeout=push_timeout) if 'error' in out: asserts.fail('Unable to push file %s to %s due to %s' % (src_file_path, dst_file_path, out)) except Exception as e: asserts.fail( msg='Unable to push file %s to %s due to %s' % (src_file_path, dst_file_path, e), extras=e) def tcp_forward_or_die(self, host_port, device_port, num_retry=1): """ Forward a TCP port from host to device or fail :param host_port: host port, int, 0 for adb to assign one :param device_port: device port, int :param num_retry: number of times to reboot and retry this before dying :return: host port int """ error_or_port = self.adb.tcp_forward(host_port, device_port) if not error_or_port: logging.debug("host port %d was already forwarded" % host_port) return host_port if not isinstance(error_or_port, int): if num_retry > 0: # If requested, reboot an retry num_retry -= 1 logging.warning("[%s] Failed to TCP forward host port %d to " "device port %d, num_retries left is %d" % (self.label, host_port, device_port, num_retry)) self.reboot() return self.tcp_forward_or_die( host_port, device_port, num_retry=num_retry) asserts.fail( 'Unable to forward host port %d to device port %d, error %s' % (host_port, device_port, error_or_port)) return error_or_port def tcp_reverse_or_die(self, device_port, host_port, num_retry=1): """ Forward a TCP port from device to host or fail :param device_port: device port, int, 0 for adb to assign one :param host_port: host port, int :param num_retry: number of times to reboot and retry this before dying :return: device port int """ error_or_port = self.adb.reverse( "tcp:%d tcp:%d" % (device_port, host_port)) if not error_or_port: logging.debug("device port %d was already reversed" % device_port) return device_port try: error_or_port = int(error_or_port) except ValueError: if num_retry > 0: # If requested, reboot an retry num_retry -= 1 logging.warning("[%s] Failed to TCP reverse device port %d to " "host port %d, num_retries left is %d" % (self.label, device_port, host_port, num_retry)) self.reboot() return self.tcp_reverse_or_die( device_port, host_port, num_retry=num_retry) asserts.fail( 'Unable to reverse device port %d to host port %d, error %s' % (device_port, host_port, error_or_port)) return error_or_port def ensure_verity_disabled(self): """Ensures that verity is enabled. If verity is not enabled, this call will reboot the phone. Note that this only works on debuggable builds. """ logging.debug("Disabling verity and remount for %s", self.serial_number) asserts.assert_true(self.adb.ensure_root(), "device %s cannot run as root", self.serial_number) # The below properties will only exist if verity has been enabled. system_verity = self.adb.getprop('partition.system.verified') vendor_verity = self.adb.getprop('partition.vendor.verified') if system_verity or vendor_verity: self.adb.disable_verity() self.reboot() self.adb.remount() self.adb.wait_for_device(timeout=self.WAIT_FOR_DEVICE_TIMEOUT_SECONDS) def reboot(self, timeout_minutes=15.0): """Reboots the device. Reboot the device, wait for device to complete booting. """ logging.debug("Rebooting %s", self.serial_number) self.adb.reboot() timeout_start = time.time() timeout = timeout_minutes * 60 # Android sometimes return early after `adb reboot` is called. This # means subsequent calls may make it to the device before the reboot # goes through, return false positives for getprops such as # sys.boot_completed. while time.time() < timeout_start + timeout: try: self.adb.get_state() time.sleep(.1) except AdbError: # get_state will raise an error if the device is not found. We # want the device to be missing to prove the device has kicked # off the reboot. break minutes_left = timeout_minutes - (time.time() - timeout_start) / 60.0 self.wait_for_boot_completion(timeout_minutes=minutes_left) def wait_for_boot_completion(self, timeout_minutes=15.0): """ Waits for Android framework to broadcast ACTION_BOOT_COMPLETED. :param timeout_minutes: number of minutes to wait """ timeout_start = time.time() timeout = timeout_minutes * 60 self.adb.wait_for_device(timeout=self.WAIT_FOR_DEVICE_TIMEOUT_SECONDS) while time.time() < timeout_start + timeout: try: completed = self.adb.getprop("sys.boot_completed") if completed == '1': return except AdbError: # adb shell calls may fail during certain period of booting # process, which is normal. Ignoring these errors. pass time.sleep(5) asserts.fail(msg='Device %s booting process timed out.' % self.serial_number)