1# Copyright 2013 The Chromium Authors. All rights reserved. 2# Use of this source code is governed by a BSD-style license that can be 3# found in the LICENSE file. 4 5import json 6import logging 7import socket 8import time 9import traceback 10 11from telemetry import decorators 12from telemetry.internal.backends.chrome_inspector import inspector_websocket 13from telemetry.internal.backends.chrome_inspector import websocket 14from tracing.trace_data import trace_data as trace_data_module 15 16 17class TracingUnsupportedException(Exception): 18 pass 19 20 21class TracingTimeoutException(Exception): 22 pass 23 24 25class TracingUnrecoverableException(Exception): 26 pass 27 28 29class TracingHasNotRunException(Exception): 30 pass 31 32 33class TracingUnexpectedResponseException(Exception): 34 pass 35 36 37class ClockSyncResponseException(Exception): 38 pass 39 40 41class _DevToolsStreamReader(object): 42 def __init__(self, inspector_socket, stream_handle): 43 self._inspector_websocket = inspector_socket 44 self._handle = stream_handle 45 self._trace_file_handle = None 46 self._callback = None 47 48 def Read(self, callback): 49 # Do not allow the instance of this class to be reused, as 50 # we only read data sequentially at the moment, so a stream 51 # can only be read once. 52 assert not self._callback 53 self._trace_file_handle = trace_data_module.TraceFileHandle() 54 self._trace_file_handle.Open() 55 self._callback = callback 56 self._ReadChunkFromStream() 57 # The below is not a typo -- queue one extra read ahead to avoid latency. 58 self._ReadChunkFromStream() 59 60 def _ReadChunkFromStream(self): 61 # Limit max block size to avoid fragmenting memory in sock.recv(), 62 # (see https://github.com/liris/websocket-client/issues/163 for details) 63 req = {'method': 'IO.read', 'params': { 64 'handle': self._handle, 'size': 32768}} 65 self._inspector_websocket.AsyncRequest(req, self._GotChunkFromStream) 66 67 def _GotChunkFromStream(self, response): 68 # Quietly discard responses from reads queued ahead after EOF. 69 if self._trace_file_handle is None: 70 return 71 if 'error' in response: 72 raise TracingUnrecoverableException( 73 'Reading trace failed: %s' % response['error']['message']) 74 result = response['result'] 75 # Convert the trace data that's receive as UTF32 to its native encoding of 76 # UTF8 in order to reduce its size. 77 self._trace_file_handle.AppendTraceData(result['data'].encode('utf8')) 78 if not result.get('eof', False): 79 self._ReadChunkFromStream() 80 return 81 req = {'method': 'IO.close', 'params': {'handle': self._handle}} 82 self._inspector_websocket.SendAndIgnoreResponse(req) 83 self._trace_file_handle.Close() 84 self._callback(self._trace_file_handle) 85 self._trace_file_handle = None 86 87 88class TracingBackend(object): 89 90 _TRACING_DOMAIN = 'Tracing' 91 92 def __init__(self, inspector_socket, is_tracing_running=False, 93 support_modern_devtools_tracing_start_api=False): 94 self._inspector_websocket = inspector_socket 95 self._inspector_websocket.RegisterDomain( 96 self._TRACING_DOMAIN, self._NotificationHandler) 97 self._is_tracing_running = is_tracing_running 98 self._start_issued = False 99 self._can_collect_data = False 100 self._has_received_all_tracing_data = False 101 self._support_modern_devtools_tracing_start_api = ( 102 support_modern_devtools_tracing_start_api) 103 self._trace_data_builder = None 104 105 @property 106 def is_tracing_running(self): 107 return self._is_tracing_running 108 109 def StartTracing(self, chrome_trace_config, timeout=10): 110 """When first called, starts tracing, and returns True. 111 112 If called during tracing, tracing is unchanged, and it returns False. 113 """ 114 if self.is_tracing_running: 115 return False 116 assert not self._can_collect_data, 'Data not collected from last trace.' 117 # Reset collected tracing data from previous tracing calls. 118 119 if not self.IsTracingSupported(): 120 raise TracingUnsupportedException( 121 'Chrome tracing not supported for this app.') 122 123 params = {'transferMode': 'ReturnAsStream'} 124 if self._support_modern_devtools_tracing_start_api: 125 params['traceConfig'] = ( 126 chrome_trace_config.GetChromeTraceConfigForDevTools()) 127 else: 128 if chrome_trace_config.requires_modern_devtools_tracing_start_api: 129 raise TracingUnsupportedException( 130 'Trace options require modern Tracing.start DevTools API, ' 131 'which is NOT supported by the browser') 132 params['categories'], params['options'] = ( 133 chrome_trace_config.GetChromeTraceCategoriesAndOptionsForDevTools()) 134 135 req = {'method': 'Tracing.start', 'params': params} 136 logging.info('Start Tracing Request: %r', req) 137 response = self._inspector_websocket.SyncRequest(req, timeout) 138 139 if 'error' in response: 140 raise TracingUnexpectedResponseException( 141 'Inspector returned unexpected response for ' 142 'Tracing.start:\n' + json.dumps(response, indent=2)) 143 144 self._is_tracing_running = True 145 self._start_issued = True 146 return True 147 148 def RecordClockSyncMarker(self, sync_id): 149 assert self.is_tracing_running, 'Tracing must be running to clock sync.' 150 req = { 151 'method': 'Tracing.recordClockSyncMarker', 152 'params': { 153 'syncId': sync_id 154 } 155 } 156 rc = self._inspector_websocket.SyncRequest(req, timeout=2) 157 if 'error' in rc: 158 raise ClockSyncResponseException(rc['error']['message']) 159 160 def StopTracing(self): 161 """Stops tracing and pushes results to the supplied TraceDataBuilder. 162 163 If this is called after tracing has been stopped, trace data from the last 164 tracing run is pushed. 165 """ 166 if not self.is_tracing_running: 167 raise TracingHasNotRunException() 168 else: 169 if not self._start_issued: 170 # Tracing is running but start was not issued so, startup tracing must 171 # be in effect. Issue another Tracing.start to update the transfer mode. 172 # TODO(caseq): get rid of it when streaming is the default. 173 params = { 174 'transferMode': 'ReturnAsStream', 175 'traceConfig': {} 176 } 177 req = {'method': 'Tracing.start', 'params': params} 178 self._inspector_websocket.SendAndIgnoreResponse(req) 179 180 req = {'method': 'Tracing.end'} 181 self._inspector_websocket.SendAndIgnoreResponse(req) 182 183 self._is_tracing_running = False 184 self._start_issued = False 185 self._can_collect_data = True 186 187 def DumpMemory(self, timeout=30): 188 """Dumps memory. 189 190 Returns: 191 GUID of the generated dump if successful, None otherwise. 192 193 Raises: 194 TracingTimeoutException: If more than |timeout| seconds has passed 195 since the last time any data is received. 196 TracingUnrecoverableException: If there is a websocket error. 197 TracingUnexpectedResponseException: If the response contains an error 198 or does not contain the expected result. 199 """ 200 request = { 201 'method': 'Tracing.requestMemoryDump' 202 } 203 try: 204 response = self._inspector_websocket.SyncRequest(request, timeout) 205 except websocket.WebSocketTimeoutException: 206 raise TracingTimeoutException( 207 'Exception raised while sending a Tracing.requestMemoryDump ' 208 'request:\n' + traceback.format_exc()) 209 except (socket.error, websocket.WebSocketException, 210 inspector_websocket.WebSocketDisconnected): 211 raise TracingUnrecoverableException( 212 'Exception raised while sending a Tracing.requestMemoryDump ' 213 'request:\n' + traceback.format_exc()) 214 215 216 if ('error' in response or 217 'result' not in response or 218 'success' not in response['result'] or 219 'dumpGuid' not in response['result']): 220 raise TracingUnexpectedResponseException( 221 'Inspector returned unexpected response for ' 222 'Tracing.requestMemoryDump:\n' + json.dumps(response, indent=2)) 223 224 result = response['result'] 225 return result['dumpGuid'] if result['success'] else None 226 227 def CollectTraceData(self, trace_data_builder, timeout=60): 228 if not self._can_collect_data: 229 raise Exception('Cannot collect before tracing is finished.') 230 self._CollectTracingData(trace_data_builder, timeout) 231 self._can_collect_data = False 232 233 def _CollectTracingData(self, trace_data_builder, timeout): 234 """Collects tracing data. Assumes that Tracing.end has already been sent. 235 236 Args: 237 trace_data_builder: An instance of TraceDataBuilder to put results into. 238 timeout: The timeout in seconds. 239 240 Raises: 241 TracingTimeoutException: If more than |timeout| seconds has passed 242 since the last time any data is received. 243 TracingUnrecoverableException: If there is a websocket error. 244 """ 245 self._has_received_all_tracing_data = False 246 start_time = time.time() 247 self._trace_data_builder = trace_data_builder 248 try: 249 while True: 250 try: 251 self._inspector_websocket.DispatchNotifications(timeout) 252 start_time = time.time() 253 except websocket.WebSocketTimeoutException: 254 pass 255 except (socket.error, websocket.WebSocketException): 256 raise TracingUnrecoverableException( 257 'Exception raised while collecting tracing data:\n' + 258 traceback.format_exc()) 259 260 if self._has_received_all_tracing_data: 261 break 262 263 elapsed_time = time.time() - start_time 264 if elapsed_time > timeout: 265 raise TracingTimeoutException( 266 'Only received partial trace data due to timeout after %s ' 267 'seconds. If the trace data is big, you may want to increase ' 268 'the timeout amount.' % elapsed_time) 269 finally: 270 self._trace_data_builder = None 271 272 def _NotificationHandler(self, res): 273 if 'Tracing.dataCollected' == res.get('method'): 274 value = res.get('params', {}).get('value') 275 self._trace_data_builder.AddTraceFor( 276 trace_data_module.CHROME_TRACE_PART, value) 277 elif 'Tracing.tracingComplete' == res.get('method'): 278 stream_handle = res.get('params', {}).get('stream') 279 if not stream_handle: 280 self._has_received_all_tracing_data = True 281 return 282 reader = _DevToolsStreamReader(self._inspector_websocket, stream_handle) 283 reader.Read(self._ReceivedAllTraceDataFromStream) 284 285 def _ReceivedAllTraceDataFromStream(self, trace_handle): 286 self._trace_data_builder.AddTraceFor( 287 trace_data_module.CHROME_TRACE_PART, trace_handle) 288 self._has_received_all_tracing_data = True 289 290 def Close(self): 291 self._inspector_websocket.UnregisterDomain(self._TRACING_DOMAIN) 292 self._inspector_websocket = None 293 294 @decorators.Cache 295 def IsTracingSupported(self): 296 req = {'method': 'Tracing.hasCompleted'} 297 res = self._inspector_websocket.SyncRequest(req, timeout=10) 298 return not res.get('response') 299