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 VtsProfilingMessage_pb2 as VtsProfilingMsg 21from vts.proto import VtsReportMessage_pb2 as ReportMsg 22from vts.runners.host import asserts 23from vts.runners.host import const 24from vts.runners.host import keys 25from vts.utils.python.common import cmd_utils 26from vts.utils.python.os import path_utils 27from vts.utils.python.web import feature_utils 28 29LOCAL_PROFILING_TRACE_PATH = "/tmp/vts-test-trace" 30TARGET_PROFILING_TRACE_PATH = "/data/local/tmp/" 31HAL_INSTRUMENTATION_LIB_PATH_32 = "/data/local/tmp/32/" 32HAL_INSTRUMENTATION_LIB_PATH_64 = "/data/local/tmp/64/" 33 34_PROFILING_DATA = "profiling_data" 35_HOST_PROFILING_DATA = "host_profiling_data" 36 37 38class VTSProfilingData(object): 39 """Class to store the VTS profiling data. 40 41 Attributes: 42 values: A dict that stores the profiling data. e.g. latencies of each api. 43 options: A set of strings where each string specifies an associated 44 option (which is the form of 'key=value'). 45 """ 46 47 def __init__(self): 48 self.values = {} 49 self.options = set() 50 51 52EVENT_TYPE_DICT = { 53 0: "SERVER_API_ENTRY", 54 1: "SERVER_API_EXIT", 55 2: "CLIENT_API_ENTRY", 56 3: "CLIENT_API_EXIT", 57 4: "SYNC_CALLBACK_ENTRY", 58 5: "SYNC_CALLBACK_EXIT", 59 6: "ASYNC_CALLBACK_ENTRY", 60 7: "ASYNC_CALLBACK_EXIT", 61 8: "PASSTHROUGH_ENTRY", 62 9: "PASSTHROUGH_EXIT", 63} 64 65 66class ProfilingFeature(feature_utils.Feature): 67 """Feature object for profiling functionality. 68 69 Attributes: 70 enabled: boolean, True if profiling is enabled, False otherwise 71 web: (optional) WebFeature, object storing web feature util for test run 72 """ 73 74 _TOGGLE_PARAM = keys.ConfigKeys.IKEY_ENABLE_PROFILING 75 _REQUIRED_PARAMS = [keys.ConfigKeys.IKEY_DATA_FILE_PATH] 76 _OPTIONAL_PARAMS = [ 77 keys.ConfigKeys.IKEY_PROFILING_TRACING_PATH, 78 keys.ConfigKeys.IKEY_TRACE_FILE_TOOL_NAME, 79 keys.ConfigKeys.IKEY_SAVE_TRACE_FILE_REMOTE, 80 keys.ConfigKeys.IKEY_ABI_BITNESS, 81 ] 82 83 def __init__(self, user_params, web=None): 84 """Initializes the profiling feature. 85 86 Args: 87 user_params: A dictionary from parameter name (String) to parameter value. 88 web: (optional) WebFeature, object storing web feature util for test run 89 """ 90 self.ParseParameters(self._TOGGLE_PARAM, self._REQUIRED_PARAMS, 91 self._OPTIONAL_PARAMS, user_params) 92 self.web = web 93 logging.info("Profiling enabled: %s", self.enabled) 94 95 def _IsEventFromBinderizedHal(self, event_type): 96 """Returns True if the event type is from a binderized HAL.""" 97 if event_type in [8, 9]: 98 return False 99 return True 100 101 def GetTraceFiles(self, 102 dut, 103 host_profiling_trace_path=None, 104 trace_file_tool=None): 105 """Pulls the trace file and save it under the profiling trace path. 106 107 Args: 108 dut: the testing device. 109 host_profiling_trace_path: directory that stores trace files on host. 110 trace_file_tool: tools that used to store the trace file. 111 112 Returns: 113 Name list of trace files that stored on host. 114 """ 115 if not os.path.exists(LOCAL_PROFILING_TRACE_PATH): 116 os.makedirs(LOCAL_PROFILING_TRACE_PATH) 117 118 if not host_profiling_trace_path: 119 host_profiling_trace_path = LOCAL_PROFILING_TRACE_PATH 120 121 dut.shell.InvokeTerminal("profiling_shell") 122 target_trace_file = path_utils.JoinTargetPath( 123 TARGET_PROFILING_TRACE_PATH, "*.vts.trace") 124 results = dut.shell.profiling_shell.Execute("ls " + target_trace_file) 125 asserts.assertTrue(results, "failed to find trace file") 126 stdout_lines = results[const.STDOUT][0].split("\n") 127 logging.info("stdout: %s", stdout_lines) 128 trace_files = [] 129 for line in stdout_lines: 130 if line: 131 temp_file_name = os.path.join(LOCAL_PROFILING_TRACE_PATH, 132 os.path.basename(line.strip())) 133 dut.adb.pull("%s %s" % (line, temp_file_name)) 134 trace_file_name = os.path.join(host_profiling_trace_path, 135 os.path.basename(line.strip())) 136 logging.info("Saving profiling traces: %s" % trace_file_name) 137 if temp_file_name != trace_file_name: 138 file_cmd = "" 139 if trace_file_tool: 140 file_cmd += trace_file_tool 141 file_cmd += " cp " + temp_file_name + " " + trace_file_name 142 results = cmd_utils.ExecuteShellCommand(file_cmd) 143 if results[const.EXIT_CODE][0] != 0: 144 logging.error(results[const.STDERR][0]) 145 logging.error("Fail to execute command: %s" % file_cmd) 146 trace_files.append(temp_file_name) 147 return trace_files 148 149 def EnableVTSProfiling(self, shell, hal_instrumentation_lib_path=None): 150 """ Enable profiling by setting the system property. 151 152 Args: 153 shell: shell to control the testing device. 154 hal_instrumentation_lib_path: directory that stores profiling libraries. 155 """ 156 if not hal_instrumentation_lib_path: 157 bitness = getattr(self, keys.ConfigKeys.IKEY_ABI_BITNESS, None) 158 if bitness == '64': 159 hal_instrumentation_lib_path = HAL_INSTRUMENTATION_LIB_PATH_64 160 elif bitness == '32': 161 hal_instrumentation_lib_path = HAL_INSTRUMENTATION_LIB_PATH_32 162 else: 163 logging.error('Unknown abi bitness "%s". Using 64bit hal ' 164 'instrumentation lib path.', bitness) 165 hal_instrumentation_lib_path = HAL_INSTRUMENTATION_LIB_PATH_64 166 167 # cleanup any existing traces. 168 shell.Execute("rm " + os.path.join(TARGET_PROFILING_TRACE_PATH, 169 "*.vts.trace")) 170 logging.info("enable VTS profiling.") 171 172 # give permission to write the trace file. 173 shell.Execute("chmod 777 " + TARGET_PROFILING_TRACE_PATH) 174 175 shell.Execute("setprop hal.instrumentation.lib.path " + 176 hal_instrumentation_lib_path) 177 shell.Execute("setprop hal.instrumentation.enable true") 178 179 def DisableVTSProfiling(self, shell): 180 """ Disable profiling by resetting the system property. 181 182 Args: 183 shell: shell to control the testing device. 184 """ 185 shell.Execute("setprop hal.instrumentation.lib.path \"\"") 186 shell.Execute("setprop hal.instrumentation.enable false") 187 188 def _ParseTraceData(self, trace_file): 189 """Parses the data stored in trace_file, calculates the avg/max/min 190 latency for each API. 191 192 Args: 193 trace_file: file that stores the trace data. 194 195 Returns: 196 VTSProfilingData which contain the list of API names and the avg/max/min 197 latency for each API. 198 """ 199 profiling_data = VTSProfilingData() 200 api_timestamps = {} 201 api_latencies = {} 202 203 data_file_path = getattr(self, keys.ConfigKeys.IKEY_DATA_FILE_PATH) 204 trace_processor_binary = os.path.join(data_file_path, "host", "bin", 205 "trace_processor") 206 trace_processor_lib = os.path.join(data_file_path, "host", "lib64") 207 trace_processor_cmd = [ 208 "chmod a+x %s" % trace_processor_binary, 209 "LD_LIBRARY_PATH=%s %s --profiling %s" % 210 (trace_processor_lib, trace_processor_binary, trace_file) 211 ] 212 213 results = cmd_utils.ExecuteShellCommand(trace_processor_cmd) 214 if any(results[cmd_utils.EXIT_CODE]): 215 logging.error("Fail to execute command: %s" % trace_processor_cmd) 216 return profiling_data 217 218 stdout_lines = results[const.STDOUT][1].split("\n") 219 first_line = True 220 for line in stdout_lines: 221 if not line: 222 continue 223 if first_line: 224 _, mode = line.split(":") 225 profiling_data.options.add("hidl_hal_mode=%s" % mode) 226 first_line = False 227 else: 228 api, latency = line.split(":") 229 if profiling_data.values.get(api): 230 profiling_data.values[api].append(long(latency)) 231 else: 232 profiling_data.values[api] = [long(latency)] 233 234 return profiling_data 235 236 def StartHostProfiling(self, name): 237 """Starts a profiling operation. 238 239 Args: 240 name: string, the name of a profiling point 241 242 Returns: 243 True if successful, False otherwise 244 """ 245 if not self.enabled: 246 return False 247 248 if not hasattr(self, _HOST_PROFILING_DATA): 249 setattr(self, _HOST_PROFILING_DATA, {}) 250 251 host_profiling_data = getattr(self, _HOST_PROFILING_DATA) 252 253 if name in host_profiling_data: 254 logging.error("profiling point %s is already active.", name) 255 return False 256 host_profiling_data[name] = feature_utils.GetTimestamp() 257 return True 258 259 def StopHostProfiling(self, name): 260 """Stops a profiling operation. 261 262 Args: 263 name: string, the name of a profiling point 264 """ 265 if not self.enabled: 266 return 267 268 if not hasattr(self, _HOST_PROFILING_DATA): 269 setattr(self, _HOST_PROFILING_DATA, {}) 270 271 host_profiling_data = getattr(self, _HOST_PROFILING_DATA) 272 273 if name not in host_profiling_data: 274 logging.error("profiling point %s is not active.", name) 275 return False 276 277 start_timestamp = host_profiling_data[name] 278 end_timestamp = feature_utils.GetTimestamp() 279 if self.web and self.web.enabled: 280 self.web.AddProfilingDataTimestamp(name, start_timestamp, 281 end_timestamp) 282 return True 283 284 def ProcessTraceDataForTestCase(self, dut): 285 """Pulls the generated trace file to the host, parses the trace file to 286 get the profiling data (e.g. latency of each API call) and stores these 287 data in _profiling_data. 288 289 Requires the feature to be enabled; no-op otherwise. 290 291 Args: 292 dut: the registered device. 293 """ 294 if not self.enabled: 295 return 296 297 if not hasattr(self, _PROFILING_DATA): 298 setattr(self, _PROFILING_DATA, []) 299 300 profiling_data = getattr(self, _PROFILING_DATA) 301 302 trace_files = [] 303 save_trace_remote = getattr( 304 self, keys.ConfigKeys.IKEY_SAVE_TRACE_FILE_REMOTE, False) 305 if save_trace_remote: 306 trace_files = self.GetTraceFiles( 307 dut, 308 getattr(self, keys.ConfigKeys.IKEY_PROFILING_TRACING_PATH, 309 None), 310 getattr(self, keys.ConfigKeys.IKEY_TRACE_FILE_TOOL_NAME, None)) 311 else: 312 trace_files = self.GetTraceFiles(dut) 313 314 for file in trace_files: 315 logging.info("parsing trace file: %s.", file) 316 data = self._ParseTraceData(file) 317 if data: 318 profiling_data.append(data) 319 320 def ProcessAndUploadTraceData(self): 321 """Process and upload profiling trace data. 322 323 Requires the feature to be enabled; no-op otherwise. 324 325 Merges the profiling data generated by each test case, calculates the 326 aggregated max/min/avg latency for each API and uploads these latency 327 metrics to webdb. 328 """ 329 if not self.enabled: 330 return 331 332 merged_profiling_data = VTSProfilingData() 333 for data in getattr(self, _PROFILING_DATA, []): 334 for item in data.options: 335 merged_profiling_data.options.add(item) 336 for api, latences in data.values.items(): 337 if merged_profiling_data.values.get(api): 338 merged_profiling_data.values[api].extend(latences) 339 else: 340 merged_profiling_data.values[api] = latences 341 for api, latencies in merged_profiling_data.values.items(): 342 if not self.web or not self.web.enabled: 343 continue 344 345 self.web.AddProfilingDataUnlabeledVector( 346 api, 347 latencies, 348 merged_profiling_data.options, 349 x_axis_label="API processing latency (nano secs)", 350 y_axis_label="Frequency") 351