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
17import importlib
18import logging
19import os
20import traceback
21import signal
22import subprocess
23
24from blueberry.facade import rootservice_pb2 as facade_rootservice
25from functools import wraps
26from grpc import RpcError
27
28from blueberry.tests.gd.cert.async_subprocess_logger import AsyncSubprocessLogger
29from blueberry.tests.gd.cert.context import append_test_context, get_current_context, pop_test_context, ContextLevel
30from blueberry.tests.gd.cert.gd_device import MOBLY_CONTROLLER_CONFIG_NAME as CONTROLLER_CONFIG_NAME
31from blueberry.tests.gd.cert.os_utils import get_gd_root
32from blueberry.tests.gd.cert.os_utils import read_crash_snippet_and_log_tail
33from blueberry.tests.gd.cert.os_utils import is_subprocess_alive
34from blueberry.tests.gd.cert.os_utils import make_ports_available
35from blueberry.tests.gd.cert.os_utils import TerminalColor
36from blueberry.tests.gd.cert.tracelogger import TraceLogger
37
38from mobly import asserts, signals
39from mobly import base_test
40
41
42class Timeout:
43
44    def __init__(self, seconds=1, error_message='Timeout'):
45        self.seconds = seconds
46        self.error_message = error_message
47
48    def handle_timeout(self, signum, frame):
49        raise TimeoutError(self.error_message)
50
51    def __enter__(self):
52        signal.signal(signal.SIGALRM, self.handle_timeout)
53        signal.alarm(self.seconds)
54
55    def __exit__(self, type, value, traceback):
56        signal.alarm(0)
57
58
59class GdBaseTestClass(base_test.BaseTestClass):
60
61    FUNCTION_CALL_TIMEOUT_SECONDS = 5
62    SUBPROCESS_WAIT_TIMEOUT_SECONDS = 10
63
64    def setup_class(self, dut_module, cert_module):
65        self.dut_module = dut_module
66        self.cert_module = cert_module
67        self.log = TraceLogger(logging.getLogger())
68        self.dut_coverage_info = None
69        self.cert_coverage_info = None
70
71    def teardown_class(self):
72        # assume each test runs the same binary for dut and cert
73        # generate coverage report after running all tests in a class
74        if self.dut_coverage_info:
75            self.dut.generate_coverage_report_for_host(self.dut_coverage_info)
76            self.dut_coverage_info = None
77        if self.cert_coverage_info:
78            self.cert.generate_coverage_report_for_host(self.cert_coverage_info)
79            self.cert_coverage_info = None
80
81    def set_controller_properties_path(self, path):
82        GD_DIR = os.path.join(os.getcwd(), os.pardir)
83        self.controller_properties_file = os.path.join(GD_DIR, path)
84
85    def setup_test(self):
86        append_test_context(test_class_name=self.TAG, test_name=self.current_test_info.name)
87        self.log_path_base = get_current_context().get_full_output_path()
88        self.verbose_mode = bool(self.user_params.get('verbose_mode', False))
89        for config in self.controller_configs[CONTROLLER_CONFIG_NAME]:
90            config['verbose_mode'] = self.verbose_mode
91
92        try:
93            controller_properties_file = self.controller_properties_file
94        except AttributeError:
95            controller_properties_file = ''
96
97        self.setup_rootcanal(controller_properties_file)
98
99        # Parse and construct GD device objects
100        self.register_controller(importlib.import_module('blueberry.tests.gd.cert.gd_device'), builtin=True)
101        self.dut = self.gd_device[1]
102        self.cert = self.gd_device[0]
103        if self.dut.host_only_device:
104            new_dut_coverage_info = self.dut.get_coverage_info()
105            if self.dut_coverage_info:
106                asserts.assert_true(self.dut_coverage_info == new_dut_coverage_info,
107                                    msg="DUT coverage info must be the same for each test run, old: {}, new: {}".format(
108                                        self.dut_coverage_info, new_dut_coverage_info))
109            self.dut_coverage_info = new_dut_coverage_info
110        if self.cert.host_only_device:
111            new_cert_coverage_info = self.cert.get_coverage_info()
112            if self.cert_coverage_info:
113                asserts.assert_true(
114                    self.cert_coverage_info == new_cert_coverage_info,
115                    msg="CERT coverage info must be the same for each test run, old: {}, new: {}".format(
116                        self.cert_coverage_info, new_cert_coverage_info))
117            self.cert_coverage_info = new_cert_coverage_info
118
119        try:
120            self.dut.rootservice.StartStack(
121                facade_rootservice.StartStackRequest(
122                    module_under_test=facade_rootservice.BluetoothModule.Value(self.dut_module)))
123        except RpcError as rpc_error:
124            asserts.fail("Failed to start DUT stack, RpcError={!r}".format(rpc_error))
125        try:
126            self.cert.rootservice.StartStack(
127                facade_rootservice.StartStackRequest(
128                    module_under_test=facade_rootservice.BluetoothModule.Value(self.cert_module)))
129        except RpcError as rpc_error:
130            asserts.fail("Failed to start CERT stack, RpcError={!r}".format(rpc_error))
131        self.dut.wait_channel_ready()
132        self.cert.wait_channel_ready()
133
134    def teardown_test(self):
135        stack = ""
136        try:
137            with Timeout(seconds=self.FUNCTION_CALL_TIMEOUT_SECONDS):
138                stack = "CERT"
139                self.cert.rootservice.StopStack(facade_rootservice.StopStackRequest())
140                stack = "DUT"
141                self.dut.rootservice.StopStack(facade_rootservice.StopStackRequest())
142        except RpcError as rpc_error:
143            asserts.fail("Failed to stop {} stack, RpcError={!r}".format(stack, rpc_error))
144        except TimeoutError:
145            logging.error("Failed to stop {} stack in {} s".format(stack, self.FUNCTION_CALL_TIMEOUT_SECONDS))
146        finally:
147            # Destroy GD device objects
148            self._controller_manager.unregister_controllers()
149            self.teardown_rootcanal()
150            pop_test_context()
151
152    def setup_rootcanal(self, controller_properties_file=''):
153        # Start root-canal if needed
154        self.rootcanal_running = False
155        self.rootcanal_logpath = None
156        self.rootcanal_process = None
157        self.rootcanal_logger = None
158        if 'rootcanal' in self.controller_configs:
159            self.rootcanal_running = True
160            # Get root canal binary
161            rootcanal = os.path.join(get_gd_root(), "root-canal")
162            asserts.assert_true(os.path.isfile(rootcanal), "Root canal does not exist at %s" % rootcanal)
163
164            # Get root canal log
165            self.rootcanal_logpath = os.path.join(self.log_path_base, 'rootcanal_logs.txt')
166            # Make sure ports are available
167            rootcanal_config = self.controller_configs['rootcanal']
168            rootcanal_test_port = int(rootcanal_config.get("test_port", "6401"))
169            rootcanal_hci_port = int(rootcanal_config.get("hci_port", "6402"))
170            rootcanal_link_layer_port = int(rootcanal_config.get("link_layer_port", "6403"))
171            asserts.assert_true(
172                make_ports_available((rootcanal_test_port, rootcanal_hci_port, rootcanal_link_layer_port)),
173                "Failed to free ports rootcanal_test_port={}, rootcanal_hci_port={}, rootcanal_link_layer_port={}".
174                format(rootcanal_test_port, rootcanal_hci_port, rootcanal_link_layer_port))
175
176            # Start root canal process
177            rootcanal_cmd = [
178                rootcanal, '-test_port',
179                str(rootcanal_test_port), '-hci_port',
180                str(rootcanal_hci_port), '-link_port',
181                str(rootcanal_link_layer_port), '-controller_properties_file=' + controller_properties_file
182            ]
183            self.log.debug("Running %s" % " ".join(rootcanal_cmd))
184            self.rootcanal_process = subprocess.Popen(rootcanal_cmd,
185                                                      cwd=get_gd_root(),
186                                                      env=os.environ.copy(),
187                                                      stdout=subprocess.PIPE,
188                                                      stderr=subprocess.STDOUT,
189                                                      universal_newlines=True)
190
191            asserts.assert_true(self.rootcanal_process, msg="Cannot start root-canal at " + str(rootcanal))
192            asserts.assert_true(is_subprocess_alive(self.rootcanal_process),
193                                msg="root-canal stopped immediately after running")
194
195            self.rootcanal_logger = AsyncSubprocessLogger(self.rootcanal_process, [self.rootcanal_logpath],
196                                                          log_to_stdout=self.verbose_mode,
197                                                          tag="rootcanal",
198                                                          color=TerminalColor.MAGENTA)
199
200            # Modify the device config to include the correct root-canal port
201            for gd_device_config in self.controller_configs.get("GdDevice"):
202                gd_device_config["rootcanal_port"] = str(rootcanal_hci_port)
203
204    def teardown_rootcanal(self):
205        if self.rootcanal_running:
206            stop_signal = signal.SIGINT
207            self.rootcanal_process.send_signal(stop_signal)
208            try:
209                return_code = self.rootcanal_process.wait(timeout=self.SUBPROCESS_WAIT_TIMEOUT_SECONDS)
210            except subprocess.TimeoutExpired:
211                logging.error("Failed to interrupt root canal via SIGINT, sending SIGKILL")
212                stop_signal = signal.SIGKILL
213                self.rootcanal_process.kill()
214                try:
215                    return_code = self.rootcanal_process.wait(timeout=self.SUBPROCESS_WAIT_TIMEOUT_SECONDS)
216                except subprocess.TimeoutExpired:
217                    logging.error("Failed to kill root canal")
218                    return_code = -65536
219            if return_code != 0 and return_code != -stop_signal:
220                logging.error("rootcanal stopped with code: %d" % return_code)
221            self.rootcanal_logger.stop()
222
223    @staticmethod
224    def get_module_reference_name(a_module):
225        """Returns the module's module's submodule name as reference name.
226
227        Args:
228            a_module: Any module. Ideally, a controller module.
229        Returns:
230            A string corresponding to the module's name.
231        """
232        return a_module.__name__.split('.')[-1]
233
234    def register_controller(self, controller_module, required=True, builtin=False):
235        """Registers an controller module for a test class. Invokes Mobly's
236        implementation of register_controller.
237        """
238        module_ref_name = self.get_module_reference_name(controller_module)
239        module_config_name = controller_module.MOBLY_CONTROLLER_CONFIG_NAME
240
241        # Get controller objects from Mobly's register_controller
242        controllers = self._controller_manager.register_controller(controller_module, required=required)
243        if not controllers:
244            return None
245
246        # Log controller information
247        # Implementation of "get_info" is optional for a controller module.
248        if hasattr(controller_module, "get_info"):
249            controller_info = controller_module.get_info(controllers)
250            self.log.info("Controller %s: %s", module_config_name, controller_info)
251
252        if builtin:
253            setattr(self, module_ref_name, controllers)
254        return controllers
255
256    def __getattribute__(self, name):
257        attr = super().__getattribute__(name)
258        if not callable(attr) or not GdBaseTestClass.__is_entry_function(name):
259            return attr
260
261        @wraps(attr)
262        def __wrapped(*args, **kwargs):
263            try:
264                return attr(*args, **kwargs)
265            except RpcError as e:
266                exception_info = "".join(traceback.format_exception(e.__class__, e, e.__traceback__))
267                raise signals.TestFailure("RpcError during test\n\nRpcError:\n\n%s\n%s" %
268                                          (exception_info, self.__dump_crashes()))
269
270        return __wrapped
271
272    __ENTRY_METHODS = {"setup_class", "teardown_class", "setup_test", "teardown_test"}
273
274    @staticmethod
275    def __is_entry_function(name):
276        return name.startswith("test_") or name in GdBaseTestClass.__ENTRY_METHODS
277
278    def __dump_crashes(self):
279        """
280        return: formatted stack traces if found, or last few lines of log
281        """
282        dut_crash, dut_log_tail = self.dut.get_crash_snippet_and_log_tail()
283        cert_crash, cert_log_tail = self.cert.get_crash_snippet_and_log_tail()
284        rootcanal_crash = None
285        rootcanal_log_tail = None
286        if self.rootcanal_running and not is_subprocess_alive(self.rootcanal_process):
287            rootcanal_crash, roocanal_log_tail = read_crash_snippet_and_log_tail(self.rootcanal_logpath)
288
289        crash_detail = ""
290        if dut_crash or cert_crash or rootcanal_crash:
291            if rootcanal_crash:
292                crash_detail += "rootcanal crashed:\n\n%s\n\n" % rootcanal_crash
293            if dut_crash:
294                crash_detail += "dut stack crashed:\n\n%s\n\n" % dut_crash
295            if cert_crash:
296                crash_detail += "cert stack crashed:\n\n%s\n\n" % cert_crash
297        else:
298            if rootcanal_log_tail:
299                crash_detail += "rootcanal log tail:\n\n%s\n\n" % rootcanal_log_tail
300            if dut_log_tail:
301                crash_detail += "dut log tail:\n\n%s\n\n" % dut_log_tail
302            if cert_log_tail:
303                crash_detail += "cert log tail:\n\n%s\n\n" % cert_log_tail
304
305        return crash_detail
306