1#
2# Copyright (C) 2016 The Android Open Source Project
3#
4# Licensed under the Apache License, Version 2.0 (the "License");
5# you may not use this file except in compliance with the License.
6# You may obtain a copy of the License at
7#
8#      http://www.apache.org/licenses/LICENSE-2.0
9#
10# Unless required by applicable law or agreed to in writing, software
11# distributed under the License is distributed on an "AS IS" BASIS,
12# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13# See the License for the specific language governing permissions and
14# limitations under the License.
15
16import logging
17import os
18
19from google.protobuf import text_format
20from vts.proto import ComponentSpecificationMessage_pb2 as CompSpecMsg
21from vts.proto import VtsProfilingMessage_pb2 as VtsProfilingMsg
22from vts.proto import VtsReportMessage_pb2 as ReportMsg
23from vts.runners.host import asserts
24from vts.runners.host import const
25from vts.runners.host import keys
26from vts.utils.python.common import cmd_utils
27from vts.utils.python.os import path_utils
28from vts.utils.python.web import feature_utils
29
30LOCAL_PROFILING_TRACE_PATH = "/tmp/vts-test-trace"
31TARGET_PROFILING_TRACE_PATH = "/data/local/tmp/"
32HAL_INSTRUMENTATION_LIB_PATH_32 = "/data/local/tmp/32/"
33HAL_INSTRUMENTATION_LIB_PATH_64 = "/data/local/tmp/64/"
34DEFAULT_HAL_ROOT = "android.hardware."
35
36_PROFILING_DATA = "profiling_data"
37_HOST_PROFILING_DATA = "host_profiling_data"
38
39
40class VTSProfilingData(object):
41    """Class to store the VTS profiling data.
42
43    Attributes:
44        values: A dict that stores the profiling data. e.g. latencies of each api.
45        options: A set of strings where each string specifies an associated
46                 option (which is the form of 'key=value').
47    """
48
49    def __init__(self):
50        self.values = {}
51        self.options = set()
52
53
54EVENT_TYPE_DICT = {
55    0: "SERVER_API_ENTRY",
56    1: "SERVER_API_EXIT",
57    2: "CLIENT_API_ENTRY",
58    3: "CLIENT_API_EXIT",
59    4: "SYNC_CALLBACK_ENTRY",
60    5: "SYNC_CALLBACK_EXIT",
61    6: "ASYNC_CALLBACK_ENTRY",
62    7: "ASYNC_CALLBACK_EXIT",
63    8: "PASSTHROUGH_ENTRY",
64    9: "PASSTHROUGH_EXIT",
65}
66
67
68class VTSApiCoverageData(object):
69    """Class to store the API coverage data.
70
71    Attributes:
72        package_name: sting, HAL package name (e.g. android.hardware.foo).
73        version_major: string, HAL major version (e.g. 1).
74        version_minor: string, HAL minor version (e.g. 0).
75        interface_name: string, HAL interface name (e.g. IFoo).
76        total_apis: A set of strings, each string represents an API name defined
77                    in the given HAL.
78        covered_apis: A set of strings, each string represents an API name
79                      covered by the test.
80    """
81
82    def __init__(self, package_name, version, interface_name):
83        self.package_name = package_name
84        self.version_major, self.version_minor = version.split(".")
85        self.interface_name = interface_name
86        self.total_apis = set()
87        self.covered_apis = set()
88
89
90class ProfilingFeature(feature_utils.Feature):
91    """Feature object for profiling functionality.
92
93    Attributes:
94        enabled: boolean, True if profiling is enabled, False otherwise
95        web: (optional) WebFeature, object storing web feature util for test run.
96        data_file_path: Path to the data directory within vts package.
97        api_coverage_data: A dictionary from full HAL interface name
98        (e.g. android.hardware.foo@1.0::IFoo) to VtsApiCoverageData.
99    """
100
101    _TOGGLE_PARAM = keys.ConfigKeys.IKEY_ENABLE_PROFILING
102    _REQUIRED_PARAMS = [keys.ConfigKeys.IKEY_DATA_FILE_PATH]
103    _OPTIONAL_PARAMS = [
104        keys.ConfigKeys.IKEY_PROFILING_TRACING_PATH,
105        keys.ConfigKeys.IKEY_TRACE_FILE_TOOL_NAME,
106        keys.ConfigKeys.IKEY_SAVE_TRACE_FILE_REMOTE,
107        keys.ConfigKeys.IKEY_ABI_BITNESS,
108        keys.ConfigKeys.IKEY_PROFILING_ARG_VALUE,
109    ]
110
111    def __init__(self, user_params, web=None):
112        """Initializes the profiling feature.
113
114        Args:
115            user_params: A dictionary from parameter name (String) to parameter value.
116            web: (optional) WebFeature, object storing web feature util for test run
117        """
118        self.ParseParameters(self._TOGGLE_PARAM, self._REQUIRED_PARAMS,
119                             self._OPTIONAL_PARAMS, user_params)
120        self.web = web
121        if self.enabled:
122            logging.info("Profiling is enabled.")
123        else:
124            logging.debug("Profiling is disabled.")
125
126        self.data_file_path = getattr(self,
127                                      keys.ConfigKeys.IKEY_DATA_FILE_PATH, None)
128        self.api_coverage_data = {}
129
130    def _IsEventFromBinderizedHal(self, event_type):
131        """Returns True if the event type is from a binderized HAL."""
132        if event_type in [8, 9]:
133            return False
134        return True
135
136    def GetTraceFiles(self,
137                      dut,
138                      host_profiling_trace_path=None,
139                      trace_file_tool=None):
140        """Pulls the trace file and save it under the profiling trace path.
141
142        Args:
143            dut: the testing device.
144            host_profiling_trace_path: directory that stores trace files on host.
145            trace_file_tool: tools that used to store the trace file.
146
147        Returns:
148            Name list of trace files that stored on host.
149        """
150        if not os.path.exists(LOCAL_PROFILING_TRACE_PATH):
151            os.makedirs(LOCAL_PROFILING_TRACE_PATH)
152
153        if not host_profiling_trace_path:
154            host_profiling_trace_path = LOCAL_PROFILING_TRACE_PATH
155
156        target_trace_file = path_utils.JoinTargetPath(
157            TARGET_PROFILING_TRACE_PATH, "*.vts.trace")
158        results = dut.shell.Execute("ls " + target_trace_file)
159        asserts.assertTrue(results, "failed to find trace file")
160        stdout_lines = results[const.STDOUT][0].split("\n")
161        logging.debug("stdout: %s", stdout_lines)
162        trace_files = []
163        for line in stdout_lines:
164            if line:
165                temp_file_name = os.path.join(LOCAL_PROFILING_TRACE_PATH,
166                                              os.path.basename(line.strip()))
167                dut.adb.pull("%s %s" % (line, temp_file_name))
168                trace_file_name = os.path.join(host_profiling_trace_path,
169                                               os.path.basename(line.strip()))
170                logging.info("Saving profiling traces: %s" % trace_file_name)
171                if temp_file_name != trace_file_name:
172                    file_cmd = ""
173                    if trace_file_tool:
174                        file_cmd += trace_file_tool
175                    file_cmd += " cp " + temp_file_name + " " + trace_file_name
176                    results = cmd_utils.ExecuteShellCommand(file_cmd)
177                    if results[const.EXIT_CODE][0] != 0:
178                        logging.error(results[const.STDERR][0])
179                        logging.error("Fail to execute command: %s" % file_cmd)
180                trace_files.append(temp_file_name)
181        return trace_files
182
183    def EnableVTSProfiling(self, shell, hal_instrumentation_lib_path=None):
184        """ Enable profiling by setting the system property.
185
186        Args:
187            shell: shell to control the testing device.
188            hal_instrumentation_lib_path: string, the path of directory that stores
189                                          profiling libraries.
190        """
191        hal_instrumentation_lib_path_32 = HAL_INSTRUMENTATION_LIB_PATH_32
192        hal_instrumentation_lib_path_64 = HAL_INSTRUMENTATION_LIB_PATH_64
193        if hal_instrumentation_lib_path is not None:
194            bitness = getattr(self, keys.ConfigKeys.IKEY_ABI_BITNESS, None)
195            if bitness == '64':
196                hal_instrumentation_lib_path_64 = hal_instrumentation_lib_path
197            elif bitness == '32':
198                hal_instrumentation_lib_path_32 = hal_instrumentation_lib_path
199            else:
200                logging.error('Unknown abi bitness "%s". Using 64bit hal '
201                              'instrumentation lib path.', bitness)
202
203        # cleanup any existing traces.
204        shell.Execute(
205            "rm " + os.path.join(TARGET_PROFILING_TRACE_PATH, "*.vts.trace"))
206        logging.debug("enabling VTS profiling.")
207
208        # give permission to write the trace file.
209        shell.Execute("chmod 777 " + TARGET_PROFILING_TRACE_PATH)
210
211        shell.Execute("setprop hal.instrumentation.lib.path.32 " +
212                      hal_instrumentation_lib_path_32)
213        shell.Execute("setprop hal.instrumentation.lib.path.64 " +
214                      hal_instrumentation_lib_path_64)
215
216        if getattr(self, keys.ConfigKeys.IKEY_PROFILING_ARG_VALUE, False):
217            shell.Execute("setprop hal.instrumentation.profile.args true")
218        else:
219            shell.Execute("setprop hal.instrumentation.profile.args false")
220        shell.Execute("setprop hal.instrumentation.enable true")
221
222    def DisableVTSProfiling(self, shell):
223        """ Disable profiling by resetting the system property.
224
225        Args:
226            shell: shell to control the testing device.
227        """
228        shell.Execute("setprop hal.instrumentation.lib.path \"\"")
229        shell.Execute("setprop hal.instrumentation.profile.args \"\"")
230        shell.Execute("setprop hal.instrumentation.enable false")
231
232    def _ParseTraceData(self, trace_file, measure_api_coverage):
233        """Parses the data stored in trace_file, calculates the avg/max/min
234        latency for each API.
235
236        Args:
237            trace_file: file that stores the trace data.
238            measure_api_coverage: whether to measure the api coverage data.
239
240        Returns:
241            VTSProfilingData which contain the list of API names and the avg/max/min
242            latency for each API.
243        """
244        profiling_data = VTSProfilingData()
245        api_timestamps = {}
246        api_latencies = {}
247
248        trace_processor_binary = os.path.join(self.data_file_path, "host",
249                                              "bin", "trace_processor")
250        trace_processor_lib = os.path.join(self.data_file_path, "host",
251                                           "lib64")
252        trace_processor_cmd = [
253            "chmod a+x %s" % trace_processor_binary,
254            "LD_LIBRARY_PATH=%s %s -m profiling_trace %s" %
255            (trace_processor_lib, trace_processor_binary, trace_file)
256        ]
257
258        results = cmd_utils.ExecuteShellCommand(trace_processor_cmd)
259        if any(results[cmd_utils.EXIT_CODE]):
260            logging.error("Fail to execute command: %s" % trace_processor_cmd)
261            logging.error("stdout: %s" % results[const.STDOUT])
262            logging.error("stderr: %s" % results[const.STDERR])
263            return profiling_data
264
265        stdout_lines = results[const.STDOUT][1].split("\n")
266        first_line = True
267        for line in stdout_lines:
268            if not line:
269                continue
270            if first_line:
271                _, mode = line.split(":")
272                profiling_data.options.add("hidl_hal_mode=%s" % mode)
273                first_line = False
274            else:
275                full_api, latency = line.rsplit(":", 1)
276                full_interface, api_name = full_api.rsplit("::", 1)
277                if profiling_data.values.get(api_name):
278                    profiling_data.values[api_name].append(long(latency))
279                else:
280                    profiling_data.values[api_name] = [long(latency)]
281
282                if measure_api_coverage:
283                    package, interface_name = full_interface.split("::")
284                    package_name, version = package.split("@")
285
286                    if full_interface in self.api_coverage_data:
287                        self.api_coverage_data[
288                            full_interface].covered_apis.add(api_name)
289                    else:
290                        total_apis = self._GetTotalApis(
291                            package_name, version, interface_name)
292                        if total_apis:
293                            vts_api_coverage = VTSApiCoverageData(
294                                package_name, version, interface_name)
295                            vts_api_coverage.total_apis = total_apis
296                            if api_name in total_apis:
297                                vts_api_coverage.covered_apis.add(api_name)
298                            else:
299                                logging.warning("API %s is not supported by %s",
300                                                api_name, full_interface)
301                            self.api_coverage_data[
302                                full_interface] = vts_api_coverage
303
304        return profiling_data
305
306    def _GetTotalApis(self, package_name, version, interface_name):
307        """Parse the specified vts spec and get all APIs defined in the spec.
308
309        Args:
310            package_name: string, HAL package name.
311            version: string, HAL version.
312            interface_name: string, HAL interface name.
313
314        Returns:
315            A set of strings, each string represents an API defined in the spec.
316        """
317        total_apis = set()
318        spec_proto = CompSpecMsg.ComponentSpecificationMessage()
319        # TODO: support general package that does not start with android.hardware.
320        if not package_name.startswith(DEFAULT_HAL_ROOT):
321            logging.warning("Unsupported hal package: %s", package_name)
322            return total_apis
323
324        hal_package_path = package_name[len(DEFAULT_HAL_ROOT):].replace(
325            ".", "/")
326        vts_spec_path = os.path.join(
327            self.data_file_path, "spec/hardware/interfaces", hal_package_path,
328            version, "vts", interface_name[1:] + ".vts")
329        logging.debug("vts_spec_path: %s", vts_spec_path)
330        with open(vts_spec_path, 'r') as spec_file:
331            spec_string = spec_file.read()
332            text_format.Merge(spec_string, spec_proto)
333        for api in spec_proto.interface.api:
334            if not api.is_inherited:
335                total_apis.add(api.name)
336        return total_apis
337
338    def StartHostProfiling(self, name):
339        """Starts a profiling operation.
340
341        Args:
342            name: string, the name of a profiling point
343
344        Returns:
345            True if successful, False otherwise
346        """
347        if not self.enabled:
348            return False
349
350        if not hasattr(self, _HOST_PROFILING_DATA):
351            setattr(self, _HOST_PROFILING_DATA, {})
352
353        host_profiling_data = getattr(self, _HOST_PROFILING_DATA)
354
355        if name in host_profiling_data:
356            logging.error("profiling point %s is already active.", name)
357            return False
358        host_profiling_data[name] = feature_utils.GetTimestamp()
359        return True
360
361    def StopHostProfiling(self, name):
362        """Stops a profiling operation.
363
364        Args:
365            name: string, the name of a profiling point
366        """
367        if not self.enabled:
368            return
369
370        if not hasattr(self, _HOST_PROFILING_DATA):
371            setattr(self, _HOST_PROFILING_DATA, {})
372
373        host_profiling_data = getattr(self, _HOST_PROFILING_DATA)
374
375        if name not in host_profiling_data:
376            logging.error("profiling point %s is not active.", name)
377            return False
378
379        start_timestamp = host_profiling_data[name]
380        end_timestamp = feature_utils.GetTimestamp()
381        if self.web and self.web.enabled:
382            self.web.AddProfilingDataTimestamp(name, start_timestamp,
383                                               end_timestamp)
384        return True
385
386    def ProcessTraceDataForTestCase(self, dut, measure_api_coverage=True):
387        """Pulls the generated trace file to the host, parses the trace file to
388        get the profiling data (e.g. latency of each API call) and stores these
389        data in _profiling_data.
390
391        Requires the feature to be enabled; no-op otherwise.
392
393        Args:
394            dut: the registered device.
395        """
396        if not self.enabled:
397            return
398
399        if not hasattr(self, _PROFILING_DATA):
400            setattr(self, _PROFILING_DATA, [])
401
402        profiling_data = getattr(self, _PROFILING_DATA)
403
404        trace_files = []
405        save_trace_remote = getattr(
406            self, keys.ConfigKeys.IKEY_SAVE_TRACE_FILE_REMOTE, False)
407        if save_trace_remote:
408            trace_files = self.GetTraceFiles(
409                dut,
410                getattr(self, keys.ConfigKeys.IKEY_PROFILING_TRACING_PATH,
411                        None),
412                getattr(self, keys.ConfigKeys.IKEY_TRACE_FILE_TOOL_NAME, None))
413        else:
414            trace_files = self.GetTraceFiles(dut)
415
416        for file in trace_files:
417            logging.info("parsing trace file: %s.", file)
418            data = self._ParseTraceData(file, measure_api_coverage)
419            if data:
420                profiling_data.append(data)
421
422    def ProcessAndUploadTraceData(self, upload_api_coverage=True):
423        """Process and upload profiling trace data.
424
425        Requires the feature to be enabled; no-op otherwise.
426
427        Merges the profiling data generated by each test case, calculates the
428        aggregated max/min/avg latency for each API and uploads these latency
429        metrics to webdb.
430
431        Args:
432            upload_api_coverage: whether to upload the API coverage data.
433        """
434        if not self.enabled:
435            return
436
437        merged_profiling_data = VTSProfilingData()
438        for data in getattr(self, _PROFILING_DATA, []):
439            for item in data.options:
440                merged_profiling_data.options.add(item)
441            for api, latences in data.values.items():
442                if merged_profiling_data.values.get(api):
443                    merged_profiling_data.values[api].extend(latences)
444                else:
445                    merged_profiling_data.values[api] = latences
446        for api, latencies in merged_profiling_data.values.items():
447            if not self.web or not self.web.enabled:
448                continue
449
450            self.web.AddProfilingDataUnlabeledVector(
451                api,
452                latencies,
453                merged_profiling_data.options,
454                x_axis_label="API processing latency (nano secs)",
455                y_axis_label="Frequency")
456
457        if upload_api_coverage:
458            self.web.AddApiCoverageReport(self.api_coverage_data.values())
459