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 datetime import datetime
19import inspect
20import logging
21import os
22import pathlib
23import shutil
24import signal
25import socket
26import subprocess
27import time
28from typing import List
29
30import grpc
31
32from acts import asserts
33from acts import utils
34from acts.context import get_current_context
35from acts.controllers.adb import AdbProxy
36from acts.controllers.adb import AdbError
37from acts.controllers.adb_lib.error import AdbCommandError
38
39from google.protobuf import empty_pb2 as empty_proto
40
41from cert.async_subprocess_logger import AsyncSubprocessLogger
42from cert.logging_client_interceptor import LoggingClientInterceptor
43from cert.os_utils import get_gd_root
44from cert.os_utils import read_crash_snippet_and_log_tail
45from cert.os_utils import is_subprocess_alive
46from cert.os_utils import make_ports_available
47from cert.os_utils import TerminalColor
48from facade import rootservice_pb2_grpc as facade_rootservice_pb2_grpc
49from hal import hal_facade_pb2_grpc
50from hci.facade import hci_facade_pb2_grpc
51from hci.facade import acl_manager_facade_pb2_grpc
52from hci.facade import controller_facade_pb2_grpc
53from hci.facade import le_acl_manager_facade_pb2_grpc
54from hci.facade import le_advertising_manager_facade_pb2_grpc
55from hci.facade import le_initiator_address_facade_pb2_grpc
56from hci.facade import le_scanning_manager_facade_pb2_grpc
57from l2cap.classic import facade_pb2_grpc as l2cap_facade_pb2_grpc
58from l2cap.le import facade_pb2_grpc as l2cap_le_facade_pb2_grpc
59from iso import facade_pb2_grpc as iso_facade_pb2_grpc
60from neighbor.facade import facade_pb2_grpc as neighbor_facade_pb2_grpc
61from security import facade_pb2_grpc as security_facade_pb2_grpc
62from shim.facade import facade_pb2_grpc as shim_facade_pb2_grpc
63
64MOBLY_CONTROLLER_CONFIG_NAME = "GdDevice"
65ACTS_CONTROLLER_REFERENCE_NAME = "gd_devices"
66
67
68def create(configs):
69    if not configs:
70        raise Exception("Configuration is empty")
71    elif not isinstance(configs, list):
72        raise Exception("Configuration should be a list")
73    return get_instances_with_configs(configs)
74
75
76def destroy(devices):
77    for device in devices:
78        try:
79            device.teardown()
80        except:
81            logging.exception("[%s] Failed to clean up properly due to" % device.label)
82
83
84def get_info(devices):
85    return []
86
87
88def get_instances_with_configs(configs):
89    print(configs)
90    devices = []
91    for config in configs:
92        resolved_cmd = []
93        for arg in config["cmd"]:
94            logging.debug(arg)
95            resolved_cmd.append(replace_vars(arg, config))
96        verbose_mode = bool(config.get('verbose_mode', False))
97        if config.get("serial_number"):
98            device = GdAndroidDevice(config["grpc_port"], config["grpc_root_server_port"], config["signal_port"],
99                                     resolved_cmd, config["label"], MOBLY_CONTROLLER_CONFIG_NAME, config["name"],
100                                     config["serial_number"], verbose_mode)
101        else:
102            device = GdHostOnlyDevice(config["grpc_port"], config["grpc_root_server_port"], config["signal_port"],
103                                      resolved_cmd, config["label"], MOBLY_CONTROLLER_CONFIG_NAME, config["name"],
104                                      verbose_mode)
105        device.setup()
106        devices.append(device)
107    return devices
108
109
110def replace_vars(string, config):
111    serial_number = config.get("serial_number")
112    if serial_number is None:
113        serial_number = ""
114    rootcanal_port = config.get("rootcanal_port")
115    if rootcanal_port is None:
116        rootcanal_port = ""
117    if serial_number == "DUT" or serial_number == "CERT":
118        raise Exception("Did you forget to configure the serial number?")
119    return string.replace("$GD_ROOT", get_gd_root()) \
120                 .replace("$(grpc_port)", config.get("grpc_port")) \
121                 .replace("$(grpc_root_server_port)", config.get("grpc_root_server_port")) \
122                 .replace("$(rootcanal_port)", rootcanal_port) \
123                 .replace("$(signal_port)", config.get("signal_port")) \
124                 .replace("$(serial_number)", serial_number)
125
126
127class GdDeviceBase(ABC):
128    """
129    Base GD device class that covers common traits which assumes that the
130    device must be driven by a driver-like backing process that takes following
131    command line arguments:
132    --grpc-port: main entry port for facade services
133    --root-server-port: management port for starting and stopping services
134    --btsnoop: path to btsnoop HCI log
135    --signal-port: signaling port to indicate that backing process is started
136    --rootcanal-port: root-canal HCI port, optional
137    """
138
139    WAIT_CHANNEL_READY_TIMEOUT_SECONDS = 10
140
141    def __init__(self, grpc_port: str, grpc_root_server_port: str, signal_port: str, cmd: List[str], label: str,
142                 type_identifier: str, name: str, verbose_mode: bool):
143        """Base GD device, common traits for both device based and host only GD
144        cert tests
145        :param grpc_port: main gRPC service port
146        :param grpc_root_server_port: gRPC root server port
147        :param signal_port: signaling port for backing process start up
148        :param cmd: list of arguments to run in backing process
149        :param label: device label used in logs
150        :param type_identifier: device type identifier used in logs
151        :param name: name of device used in logs
152        """
153        # Must be at the first line of __init__ method
154        values = locals()
155        arguments = [values[arg] for arg in inspect.getfullargspec(GdDeviceBase.__init__).args if arg != "verbose_mode"]
156        asserts.assert_true(all(arguments), "All arguments to GdDeviceBase must not be None nor empty")
157        asserts.assert_true(all(cmd), "cmd list should not have None nor empty component")
158        self.verbose_mode = verbose_mode
159        self.grpc_root_server_port = int(grpc_root_server_port)
160        self.grpc_port = int(grpc_port)
161        self.signal_port = int(signal_port)
162        self.name = name
163        self.type_identifier = type_identifier
164        self.label = label
165        # logging.log_path only exists when this is used in an ACTS test run.
166        self.log_path_base = get_current_context().get_full_output_path()
167        self.test_runner_base_path = \
168            get_current_context().get_base_output_path()
169        self.backing_process_log_path = os.path.join(self.log_path_base,
170                                                     '%s_%s_backing_logs.txt' % (self.type_identifier, self.label))
171        if "--btsnoop=" not in " ".join(cmd):
172            cmd.append("--btsnoop=%s" % os.path.join(self.log_path_base, '%s_btsnoop_hci.log' % self.label))
173        if "--btsnooz=" not in " ".join(cmd):
174            cmd.append("--btsnooz=%s" % os.path.join(self.log_path_base, '%s_btsnooz_hci.log' % self.label))
175        if "--btconfig=" not in " ".join(cmd):
176            cmd.append("--btconfig=%s" % os.path.join(self.log_path_base, '%s_bt_config.conf' % self.label))
177        self.cmd = cmd
178        self.environment = os.environ.copy()
179        if "cert" in self.label:
180            self.terminal_color = TerminalColor.BLUE
181        else:
182            self.terminal_color = TerminalColor.YELLOW
183
184    def setup(self):
185        """Set up this device for test, must run before using this device
186        - After calling this, teardown() must be called when test finishes
187        - Should be executed after children classes' setup() methods
188        :return:
189        """
190        # Ensure signal port is available
191        # signal port is the only port that always listen on the host machine
192        asserts.assert_true(
193            make_ports_available([self.signal_port]), "[%s] Failed to make signal port available" % self.label)
194        # Start backing process
195        with socket.socket(socket.AF_INET, socket.SOCK_STREAM) as signal_socket:
196            # Setup signaling socket
197            signal_socket.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
198            signal_socket.bind(("localhost", self.signal_port))
199            signal_socket.listen(1)
200            signal_socket.settimeout(300)  # 5 minute timeout for blocking socket operations
201
202            # Start backing process
203            logging.debug("Running %s" % " ".join(self.cmd))
204            self.backing_process = subprocess.Popen(
205                self.cmd,
206                cwd=get_gd_root(),
207                env=self.environment,
208                stdout=subprocess.PIPE,
209                stderr=subprocess.STDOUT,
210                universal_newlines=True)
211            asserts.assert_true(self.backing_process, msg="Cannot start backing_process at " + " ".join(self.cmd))
212            asserts.assert_true(
213                is_subprocess_alive(self.backing_process),
214                msg="backing_process stopped immediately after running " + " ".join(self.cmd))
215
216            # Wait for process to be ready
217            logging.debug("Waiting for backing_process accept.")
218            signal_socket.accept()
219
220        self.backing_process_logger = AsyncSubprocessLogger(
221            self.backing_process, [self.backing_process_log_path],
222            log_to_stdout=self.verbose_mode,
223            tag=self.label,
224            color=self.terminal_color)
225
226        # Setup gRPC management channels
227        self.grpc_root_server_channel = grpc.insecure_channel("localhost:%d" % self.grpc_root_server_port)
228        self.grpc_channel = grpc.insecure_channel("localhost:%d" % self.grpc_port)
229
230        if self.verbose_mode:
231            self.grpc_channel = grpc.intercept_channel(self.grpc_channel, LoggingClientInterceptor(self.label))
232
233        # Establish services from facades
234        self.rootservice = facade_rootservice_pb2_grpc.RootFacadeStub(self.grpc_root_server_channel)
235        self.hal = hal_facade_pb2_grpc.HciHalFacadeStub(self.grpc_channel)
236        self.controller_read_only_property = facade_rootservice_pb2_grpc.ReadOnlyPropertyStub(self.grpc_channel)
237        self.hci = hci_facade_pb2_grpc.HciFacadeStub(self.grpc_channel)
238        self.l2cap = l2cap_facade_pb2_grpc.L2capClassicModuleFacadeStub(self.grpc_channel)
239        self.l2cap_le = l2cap_le_facade_pb2_grpc.L2capLeModuleFacadeStub(self.grpc_channel)
240        self.iso = iso_facade_pb2_grpc.IsoModuleFacadeStub(self.grpc_channel)
241        self.hci_acl_manager = acl_manager_facade_pb2_grpc.AclManagerFacadeStub(self.grpc_channel)
242        self.hci_le_acl_manager = le_acl_manager_facade_pb2_grpc.LeAclManagerFacadeStub(self.grpc_channel)
243        self.hci_le_initiator_address = le_initiator_address_facade_pb2_grpc.LeInitiatorAddressFacadeStub(
244            self.grpc_channel)
245        self.hci_controller = controller_facade_pb2_grpc.ControllerFacadeStub(self.grpc_channel)
246        self.hci_controller.GetMacAddressSimple = lambda: self.hci_controller.GetMacAddress(empty_proto.Empty()).address
247        self.hci_controller.GetLocalNameSimple = lambda: self.hci_controller.GetLocalName(empty_proto.Empty()).name
248        self.hci_le_advertising_manager = le_advertising_manager_facade_pb2_grpc.LeAdvertisingManagerFacadeStub(
249            self.grpc_channel)
250        self.hci_le_scanning_manager = le_scanning_manager_facade_pb2_grpc.LeScanningManagerFacadeStub(
251            self.grpc_channel)
252        self.neighbor = neighbor_facade_pb2_grpc.NeighborFacadeStub(self.grpc_channel)
253        self.security = security_facade_pb2_grpc.SecurityModuleFacadeStub(self.grpc_channel)
254        self.shim = shim_facade_pb2_grpc.ShimFacadeStub(self.grpc_channel)
255
256    def get_crash_snippet_and_log_tail(self):
257        if is_subprocess_alive(self.backing_process):
258            return None, None
259
260        return read_crash_snippet_and_log_tail(self.backing_process_log_path)
261
262    def teardown(self):
263        """Tear down this device and clean up any resources.
264        - Must be called after setup()
265        - Should be executed before children classes' teardown()
266        :return:
267        """
268        self.grpc_channel.close()
269        self.grpc_root_server_channel.close()
270        stop_signal = signal.SIGINT
271        self.backing_process.send_signal(stop_signal)
272        try:
273            return_code = self.backing_process.wait(timeout=self.WAIT_CHANNEL_READY_TIMEOUT_SECONDS)
274        except subprocess.TimeoutExpired:
275            logging.error("[%s] Failed to interrupt backing process via SIGINT, sending SIGKILL" % self.label)
276            stop_signal = signal.SIGKILL
277            self.backing_process.kill()
278            try:
279                return_code = self.backing_process.wait(timeout=self.WAIT_CHANNEL_READY_TIMEOUT_SECONDS)
280            except subprocess.TimeoutExpired:
281                logging.error("Failed to kill backing process")
282                return_code = -65536
283        if return_code not in [-stop_signal, 0]:
284            logging.error("backing process %s stopped with code: %d" % (self.label, return_code))
285        self.backing_process_logger.stop()
286
287    def wait_channel_ready(self):
288        future = grpc.channel_ready_future(self.grpc_channel)
289        try:
290            future.result(timeout=self.WAIT_CHANNEL_READY_TIMEOUT_SECONDS)
291        except grpc.FutureTimeoutError:
292            asserts.fail("[%s] wait channel ready timeout" % self.label)
293
294
295class GdHostOnlyDevice(GdDeviceBase):
296    """
297    Host only device where the backing process is running on the host machine
298    """
299
300    def __init__(self, grpc_port: str, grpc_root_server_port: str, signal_port: str, cmd: List[str], label: str,
301                 type_identifier: str, name: str, verbose_mode: bool):
302        super().__init__(grpc_port, grpc_root_server_port, signal_port, cmd, label, MOBLY_CONTROLLER_CONFIG_NAME, name,
303                         verbose_mode)
304        # Enable LLVM code coverage output for host only tests
305        self.backing_process_profraw_path = pathlib.Path(self.log_path_base).joinpath(
306            "%s_%s_backing_coverage.profraw" % (self.type_identifier, self.label))
307        self.environment["LLVM_PROFILE_FILE"] = str(self.backing_process_profraw_path)
308        llvm_binutils = pathlib.Path(get_gd_root()).joinpath("llvm_binutils").joinpath("bin")
309        llvm_symbolizer = llvm_binutils.joinpath("llvm-symbolizer")
310        if llvm_symbolizer.is_file():
311            self.environment["ASAN_SYMBOLIZER_PATH"] = llvm_symbolizer
312        else:
313            logging.warning("[%s] Cannot find LLVM symbolizer at %s" % (self.label, str(llvm_symbolizer)))
314
315    def teardown(self):
316        super().teardown()
317        self.generate_coverage_report()
318
319    def generate_coverage_report(self):
320        if not self.backing_process_profraw_path.is_file():
321            logging.info("[%s] Skip coverage report as there is no profraw file at %s" %
322                         (self.label, str(self.backing_process_profraw_path)))
323            return
324        try:
325            if self.backing_process_profraw_path.stat().st_size <= 0:
326                logging.info("[%s] Skip coverage report as profraw file is empty at %s" %
327                             (self.label, str(self.backing_process_profraw_path)))
328                return
329        except OSError:
330            logging.info("[%s] Skip coverage report as profraw file is inaccessible at %s" %
331                         (self.label, str(self.backing_process_profraw_path)))
332            return
333        llvm_binutils = pathlib.Path(get_gd_root()).joinpath("llvm_binutils").joinpath("bin")
334        llvm_profdata = llvm_binutils.joinpath("llvm-profdata")
335        if not llvm_profdata.is_file():
336            logging.info(
337                "[%s] Skip coverage report as llvm-profdata is not found at %s" % (self.label, str(llvm_profdata)))
338            return
339        llvm_cov = llvm_binutils.joinpath("llvm-cov")
340        if not llvm_cov.is_file():
341            logging.info("[%s] Skip coverage report as llvm-cov is not found at %s" % (self.label, str(llvm_cov)))
342            return
343        logging.info("[%s] Generating coverage report" % self.label)
344        profdata_path = pathlib.Path(self.test_runner_base_path).joinpath(
345            "%s_%s_backing_process_coverage.profdata" % (self.type_identifier, self.label))
346        profdata_path_tmp = pathlib.Path(self.test_runner_base_path).joinpath(
347            "%s_%s_backing_process_coverage_tmp.profdata" % (self.type_identifier, self.label))
348        # Merge with existing profdata if possible
349        profdata_cmd = [str(llvm_profdata), "merge", "-sparse", str(self.backing_process_profraw_path)]
350        if profdata_path.is_file():
351            profdata_cmd.append(str(profdata_path))
352        profdata_cmd += ["-o", str(profdata_path_tmp)]
353        result = subprocess.run(profdata_cmd, stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
354        if result.returncode != 0:
355            logging.warning("[%s] Failed to index profdata, cmd result: %r" % (self.label, result))
356            profdata_path.unlink(missing_ok=True)
357            return
358        shutil.move(profdata_path_tmp, profdata_path)
359        coverage_result_path = pathlib.Path(self.test_runner_base_path).joinpath(
360            "%s_%s_backing_process_coverage.json" % (self.type_identifier, self.label))
361        with coverage_result_path.open("w") as coverage_result_file:
362            result = subprocess.run(
363                [str(llvm_cov), "export", "--format=text", "--instr-profile", profdata_path, self.cmd[0]],
364                stderr=subprocess.PIPE,
365                stdout=coverage_result_file,
366                cwd=os.path.join(get_gd_root()))
367        if result.returncode != 0:
368            logging.warning("[%s] Failed to generated coverage report, cmd result: %r" % (self.label, result))
369            coverage_result_path.unlink(missing_ok=True)
370            return
371        coverage_summary_path = pathlib.Path(self.test_runner_base_path).joinpath(
372            "%s_%s_backing_process_coverage_summary.txt" % (self.type_identifier, self.label))
373        with coverage_summary_path.open("w") as coverage_summary_file:
374            result = subprocess.run(
375                [llvm_cov, "report", "--instr-profile", profdata_path, self.cmd[0]],
376                stderr=subprocess.PIPE,
377                stdout=coverage_summary_file,
378                cwd=os.path.join(get_gd_root()))
379        if result.returncode != 0:
380            logging.warning("[%s] Failed to generated coverage summary, cmd result: %r" % (self.label, result))
381            coverage_summary_path.unlink(missing_ok=True)
382
383    def setup(self):
384        # Ensure ports are available
385        # Only check on host only test, for Android devices, these ports will
386        # be opened on Android device and host machine ports will be occupied
387        # by sshd or adb forwarding
388        asserts.assert_true(
389            make_ports_available((self.grpc_port, self.grpc_root_server_port)),
390            "[%s] Failed to make backing process ports available" % self.label)
391        super().setup()
392
393
394class GdAndroidDevice(GdDeviceBase):
395    """Real Android device where the backing process is running on it
396    """
397
398    WAIT_FOR_DEVICE_TIMEOUT_SECONDS = 180
399
400    def __init__(self, grpc_port: str, grpc_root_server_port: str, signal_port: str, cmd: List[str], label: str,
401                 type_identifier: str, name: str, serial_number: str, verbose_mode: bool):
402        super().__init__(grpc_port, grpc_root_server_port, signal_port, cmd, label, type_identifier, name, verbose_mode)
403        asserts.assert_true(serial_number, "serial_number must not be None nor empty")
404        self.serial_number = serial_number
405        self.adb = AdbProxy(serial_number)
406
407    def setup(self):
408        logging.info("Setting up device %s %s" % (self.label, self.serial_number))
409        asserts.assert_true(self.adb.ensure_root(), "device %s cannot run as root", self.serial_number)
410
411        # Try freeing ports and ignore results
412        self.cleanup_port_forwarding()
413        self.sync_device_time()
414
415        # Set up port forwarding or reverse or die
416        self.tcp_forward_or_die(self.grpc_port, self.grpc_port)
417        self.tcp_forward_or_die(self.grpc_root_server_port, self.grpc_root_server_port)
418        self.tcp_reverse_or_die(self.signal_port, self.signal_port)
419
420        # Push test binaries
421        self.ensure_verity_disabled()
422        self.push_or_die(os.path.join(get_gd_root(), "target", "bluetooth_stack_with_facade"), "system/bin")
423        self.push_or_die(os.path.join(get_gd_root(), "target", "libbluetooth_gd.so"), "system/lib64")
424        self.push_or_die(os.path.join(get_gd_root(), "target", "libgrpc++_unsecure.so"), "system/lib64")
425
426        try:
427            self.adb.shell("rm /data/misc/bluetooth/logs/btsnoop_hci.log")
428        except AdbCommandError as error:
429            logging.error("Error during setup: " + str(error))
430
431        try:
432            self.adb.shell("rm /data/misc/bluetooth/logs/btsnooz_hci.log")
433        except AdbCommandError as error:
434            logging.error("Error during setup: " + str(error))
435
436        try:
437            self.adb.shell("rm /data/misc/bluedroid/bt_config.conf")
438        except AdbCommandError as error:
439            logging.error("Error during setup: " + str(error))
440
441        try:
442            self.adb.shell("rm /data/misc/bluedroid/bt_config.bak")
443        except AdbCommandError as error:
444            logging.error("Error during setup: " + str(error))
445
446        self.ensure_no_output(self.adb.shell("svc bluetooth disable"))
447
448        # Start logcat logging
449        self.logcat_output_path = os.path.join(
450            self.log_path_base, '%s_%s_%s_logcat_logs.txt' % (self.type_identifier, self.label, self.serial_number))
451        self.logcat_cmd = ["adb", "-s", self.serial_number, "logcat", "-T", "1", "-v", "year", "-v", "uid"]
452        logging.debug("Running %s", " ".join(self.logcat_cmd))
453        self.logcat_process = subprocess.Popen(
454            self.logcat_cmd, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, universal_newlines=True)
455        asserts.assert_true(self.logcat_process, msg="Cannot start logcat_process at " + " ".join(self.logcat_cmd))
456        asserts.assert_true(
457            is_subprocess_alive(self.logcat_process),
458            msg="logcat_process stopped immediately after running " + " ".join(self.logcat_cmd))
459        self.logcat_logger = AsyncSubprocessLogger(
460            self.logcat_process, [self.logcat_output_path],
461            log_to_stdout=self.verbose_mode,
462            tag="%s_%s" % (self.label, self.serial_number),
463            color=self.terminal_color)
464
465        # Done run parent setup
466        logging.info("Done preparation for %s, starting backing process" % self.serial_number)
467        super().setup()
468
469    def teardown(self):
470        super().teardown()
471        stop_signal = signal.SIGINT
472        self.logcat_process.send_signal(stop_signal)
473        try:
474            return_code = self.logcat_process.wait(timeout=self.WAIT_CHANNEL_READY_TIMEOUT_SECONDS)
475        except subprocess.TimeoutExpired:
476            logging.error("[%s_%s] Failed to interrupt logcat process via SIGINT, sending SIGKILL" %
477                          (self.label, self.serial_number))
478            stop_signal = signal.SIGKILL
479            self.logcat_process.kill()
480            try:
481                return_code = self.logcat_process.wait(timeout=self.WAIT_CHANNEL_READY_TIMEOUT_SECONDS)
482            except subprocess.TimeoutExpired:
483                logging.error("Failed to kill logcat_process %s %s" % (self.label, self.serial_number))
484                return_code = -65536
485        if return_code not in [-stop_signal, 0]:
486            logging.error("logcat_process %s_%s stopped with code: %d" % (self.label, self.serial_number, return_code))
487        self.logcat_logger.stop()
488        self.cleanup_port_forwarding()
489        self.adb.pull("/data/misc/bluetooth/logs/btsnoop_hci.log %s" % os.path.join(self.log_path_base,
490                                                                                    "%s_btsnoop_hci.log" % self.label))
491        self.adb.pull("/data/misc/bluedroid/bt_config.conf %s" % os.path.join(self.log_path_base,
492                                                                              "%s_bt_config.conf" % self.label))
493        self.adb.pull(
494            "/data/misc/bluedroid/bt_config.bak %s" % os.path.join(self.log_path_base, "%s_bt_config.bak" % self.label))
495
496    def cleanup_port_forwarding(self):
497        try:
498            self.adb.remove_tcp_forward(self.grpc_port)
499        except AdbError as error:
500            logging.error("Error during port forwarding cleanup: " + str(error))
501
502        try:
503            self.adb.remove_tcp_forward(self.grpc_root_server_port)
504        except AdbError as error:
505            logging.error("Error during port forwarding cleanup: " + str(error))
506
507        try:
508            self.adb.reverse("--remove tcp:%d" % self.signal_port)
509        except AdbError as error:
510            logging.error("Error during port forwarding cleanup: " + str(error))
511
512    @staticmethod
513    def ensure_no_output(result):
514        """
515        Ensure a command has not output
516        """
517        asserts.assert_true(
518            result is None or len(result) == 0, msg="command returned something when it shouldn't: %s" % result)
519
520    def sync_device_time(self):
521        self.adb.shell("settings put global auto_time 0")
522        self.adb.shell("settings put global auto_time_zone 0")
523        device_tz = self.adb.shell("date +%z")
524        asserts.assert_true(device_tz, "date +%z must return device timezone, "
525                            "but returned {} instead".format(device_tz))
526        host_tz = time.strftime("%z")
527        if device_tz != host_tz:
528            target_timezone = utils.get_timezone_olson_id()
529            logging.debug("Device timezone %s does not match host timezone %s, "
530                          "syncing them by setting timezone to %s" % (device_tz, host_tz, target_timezone))
531            self.adb.shell("setprop persist.sys.timezone %s" % target_timezone)
532            self.reboot()
533            device_tz = self.adb.shell("date +%z")
534            asserts.assert_equal(
535                host_tz, device_tz, "Device timezone %s still does not match host "
536                "timezone %s after reset" % (device_tz, host_tz))
537        self.adb.shell("date %s" % time.strftime("%m%d%H%M%Y.%S"))
538        datetime_format = "%Y-%m-%dT%H:%M:%S%z"
539        try:
540            device_time = datetime.strptime(self.adb.shell("date +'%s'" % datetime_format), datetime_format)
541        except ValueError:
542            asserts.fail("Failed to get time after sync")
543            return
544        # Include ADB delay that might be longer in SSH environment
545        max_delta_seconds = 3
546        host_time = datetime.now(tz=device_time.tzinfo)
547        asserts.assert_almost_equal(
548            (device_time - host_time).total_seconds(),
549            0,
550            msg="Device time %s and host time %s off by >%dms after sync" %
551            (device_time.isoformat(), host_time.isoformat(), int(max_delta_seconds * 1000)),
552            delta=max_delta_seconds)
553
554    def push_or_die(self, src_file_path, dst_file_path, push_timeout=300):
555        """Pushes a file to the Android device
556
557        Args:
558            src_file_path: The path to the file to install.
559            dst_file_path: The destination of the file.
560            push_timeout: How long to wait for the push to finish in seconds
561        """
562        out = self.adb.push('%s %s' % (src_file_path, dst_file_path), timeout=push_timeout)
563        if 'error' in out:
564            asserts.fail('Unable to push file %s to %s due to %s' % (src_file_path, dst_file_path, out))
565
566    def tcp_forward_or_die(self, host_port, device_port, num_retry=1):
567        """
568        Forward a TCP port from host to device or fail
569        :param host_port: host port, int, 0 for adb to assign one
570        :param device_port: device port, int
571        :param num_retry: number of times to reboot and retry this before dying
572        :return: host port int
573        """
574        error_or_port = self.adb.tcp_forward(host_port, device_port)
575        if not error_or_port:
576            logging.debug("host port %d was already forwarded" % host_port)
577            return host_port
578        if not isinstance(error_or_port, int):
579            if num_retry > 0:
580                # If requested, reboot an retry
581                num_retry -= 1
582                logging.warning(
583                    "[%s] Failed to TCP forward host port %d to "
584                    "device port %d, num_retries left is %d" % (self.label, host_port, device_port, num_retry))
585                self.reboot()
586                return self.tcp_forward_or_die(host_port, device_port, num_retry=num_retry)
587            asserts.fail(
588                'Unable to forward host port %d to device port %d, error %s' % (host_port, device_port, error_or_port))
589        return error_or_port
590
591    def tcp_reverse_or_die(self, device_port, host_port, num_retry=1):
592        """
593        Forward a TCP port from device to host or fail
594        :param device_port: device port, int, 0 for adb to assign one
595        :param host_port: host port, int
596        :param num_retry: number of times to reboot and retry this before dying
597        :return: device port int
598        """
599        error_or_port = self.adb.reverse("tcp:%d tcp:%d" % (device_port, host_port))
600        if not error_or_port:
601            logging.debug("device port %d was already reversed" % device_port)
602            return device_port
603        try:
604            error_or_port = int(error_or_port)
605        except ValueError:
606            if num_retry > 0:
607                # If requested, reboot an retry
608                num_retry -= 1
609                logging.warning(
610                    "[%s] Failed to TCP reverse device port %d to "
611                    "host port %d, num_retries left is %d" % (self.label, device_port, host_port, num_retry))
612                self.reboot()
613                return self.tcp_reverse_or_die(device_port, host_port, num_retry=num_retry)
614            asserts.fail(
615                'Unable to reverse device port %d to host port %d, error %s' % (device_port, host_port, error_or_port))
616        return error_or_port
617
618    def ensure_verity_disabled(self):
619        """Ensures that verity is enabled.
620
621        If verity is not enabled, this call will reboot the phone. Note that
622        this only works on debuggable builds.
623        """
624        logging.debug("Disabling verity and remount for %s", self.serial_number)
625        # The below properties will only exist if verity has been enabled.
626        system_verity = self.adb.getprop('partition.system.verified')
627        vendor_verity = self.adb.getprop('partition.vendor.verified')
628        if system_verity or vendor_verity:
629            self.adb.disable_verity()
630            self.reboot()
631        self.adb.remount()
632        self.adb.wait_for_device(timeout=self.WAIT_FOR_DEVICE_TIMEOUT_SECONDS)
633
634    def reboot(self, timeout_minutes=15.0):
635        """Reboots the device.
636
637        Reboot the device, wait for device to complete booting.
638        """
639        logging.debug("Rebooting %s", self.serial_number)
640        self.adb.reboot()
641
642        timeout_start = time.time()
643        timeout = timeout_minutes * 60
644        # Android sometimes return early after `adb reboot` is called. This
645        # means subsequent calls may make it to the device before the reboot
646        # goes through, return false positives for getprops such as
647        # sys.boot_completed.
648        while time.time() < timeout_start + timeout:
649            try:
650                self.adb.get_state()
651                time.sleep(.1)
652            except AdbError:
653                # get_state will raise an error if the device is not found. We
654                # want the device to be missing to prove the device has kicked
655                # off the reboot.
656                break
657        minutes_left = timeout_minutes - (time.time() - timeout_start) / 60.0
658        self.wait_for_boot_completion(timeout_minutes=minutes_left)
659        asserts.assert_true(self.adb.ensure_root(), "device %s cannot run as root after reboot", self.serial_number)
660
661    def wait_for_boot_completion(self, timeout_minutes=15.0):
662        """
663        Waits for Android framework to broadcast ACTION_BOOT_COMPLETED.
664        :param timeout_minutes: number of minutes to wait
665        """
666        timeout_start = time.time()
667        timeout = timeout_minutes * 60
668
669        self.adb.wait_for_device(timeout=self.WAIT_FOR_DEVICE_TIMEOUT_SECONDS)
670        while time.time() < timeout_start + timeout:
671            try:
672                completed = self.adb.getprop("sys.boot_completed")
673                if completed == '1':
674                    return
675            except AdbError:
676                # adb shell calls may fail during certain period of booting
677                # process, which is normal. Ignoring these errors.
678                pass
679            time.sleep(5)
680        asserts.fail(msg='Device %s booting process timed out.' % self.serial_number)
681