| OLD | NEW |
| 1 #!/usr/bin/env python | 1 #!/usr/bin/env python |
| 2 # | 2 # |
| 3 # Copyright 2013 The Chromium Authors. All rights reserved. | 3 # Copyright 2013 The Chromium Authors. All rights reserved. |
| 4 # Use of this source code is governed by a BSD-style license that can be | 4 # Use of this source code is governed by a BSD-style license that can be |
| 5 # found in the LICENSE file. | 5 # found in the LICENSE file. |
| 6 | 6 |
| 7 import gzip | |
| 8 import json | |
| 9 import logging | |
| 10 import optparse | |
| 11 import os | |
| 12 import re | |
| 13 import select | |
| 14 import shutil | |
| 15 import sys | 7 import sys |
| 16 import threading | |
| 17 import time | |
| 18 import webbrowser | |
| 19 import zipfile | |
| 20 import zlib | |
| 21 | 8 |
| 22 from pylib import android_commands | 9 from chrome_profiler import main |
| 23 from pylib import cmd_helper | |
| 24 from pylib import constants | |
| 25 from pylib import pexpect | |
| 26 from pylib.device import device_utils | |
| 27 | |
| 28 _TRACE_VIEWER_ROOT = os.path.join(constants.DIR_SOURCE_ROOT, | |
| 29 'third_party', 'trace-viewer') | |
| 30 sys.path.append(_TRACE_VIEWER_ROOT) | |
| 31 from trace_viewer.build import trace2html # pylint: disable=F0401 | |
| 32 | |
| 33 _DEFAULT_CHROME_CATEGORIES = '_DEFAULT_CHROME_CATEGORIES' | |
| 34 | |
| 35 | |
| 36 def _GetTraceTimestamp(): | |
| 37 return time.strftime('%Y-%m-%d-%H%M%S', time.localtime()) | |
| 38 | |
| 39 | |
| 40 class ChromeTracingController(object): | |
| 41 def __init__(self, device, package_info, categories, ring_buffer): | |
| 42 self._device = device | |
| 43 self._package_info = package_info | |
| 44 self._categories = categories | |
| 45 self._ring_buffer = ring_buffer | |
| 46 self._trace_file = None | |
| 47 self._trace_interval = None | |
| 48 self._trace_start_re = \ | |
| 49 re.compile(r'Logging performance trace to file') | |
| 50 self._trace_finish_re = \ | |
| 51 re.compile(r'Profiler finished[.] Results are in (.*)[.]') | |
| 52 self._device.old_interface.StartMonitoringLogcat(clear=False) | |
| 53 | |
| 54 def __str__(self): | |
| 55 return 'chrome trace' | |
| 56 | |
| 57 @staticmethod | |
| 58 def GetCategories(device, package_info): | |
| 59 device.old_interface.BroadcastIntent( | |
| 60 package_info.package, 'GPU_PROFILER_LIST_CATEGORIES') | |
| 61 try: | |
| 62 json_category_list = device.old_interface.WaitForLogMatch( | |
| 63 re.compile(r'{"traceCategoriesList(.*)'), None, timeout=5).group(0) | |
| 64 except pexpect.TIMEOUT: | |
| 65 raise RuntimeError('Performance trace category list marker not found. ' | |
| 66 'Is the correct version of the browser running?') | |
| 67 | |
| 68 record_categories = [] | |
| 69 disabled_by_default_categories = [] | |
| 70 json_data = json.loads(json_category_list)['traceCategoriesList'] | |
| 71 for item in json_data: | |
| 72 if item.startswith('disabled-by-default'): | |
| 73 disabled_by_default_categories.append(item) | |
| 74 else: | |
| 75 record_categories.append(item) | |
| 76 | |
| 77 return record_categories, disabled_by_default_categories | |
| 78 | |
| 79 def StartTracing(self, interval): | |
| 80 self._trace_interval = interval | |
| 81 self._device.old_interface.SyncLogCat() | |
| 82 self._device.old_interface.BroadcastIntent( | |
| 83 self._package_info.package, 'GPU_PROFILER_START', | |
| 84 '-e categories "%s"' % ','.join(self._categories), | |
| 85 '-e continuous' if self._ring_buffer else '') | |
| 86 # Chrome logs two different messages related to tracing: | |
| 87 # | |
| 88 # 1. "Logging performance trace to file" | |
| 89 # 2. "Profiler finished. Results are in [...]" | |
| 90 # | |
| 91 # The first one is printed when tracing starts and the second one indicates | |
| 92 # that the trace file is ready to be pulled. | |
| 93 try: | |
| 94 self._device.old_interface.WaitForLogMatch( | |
| 95 self._trace_start_re, None, timeout=5) | |
| 96 except pexpect.TIMEOUT: | |
| 97 raise RuntimeError('Trace start marker not found. Is the correct version ' | |
| 98 'of the browser running?') | |
| 99 | |
| 100 def StopTracing(self): | |
| 101 self._device.old_interface.BroadcastIntent( | |
| 102 self._package_info.package, | |
| 103 'GPU_PROFILER_STOP') | |
| 104 self._trace_file = self._device.old_interface.WaitForLogMatch( | |
| 105 self._trace_finish_re, None, timeout=120).group(1) | |
| 106 | |
| 107 def PullTrace(self): | |
| 108 # Wait a bit for the browser to finish writing the trace file. | |
| 109 time.sleep(self._trace_interval / 4 + 1) | |
| 110 | |
| 111 trace_file = self._trace_file.replace('/storage/emulated/0/', '/sdcard/') | |
| 112 host_file = os.path.join(os.path.curdir, os.path.basename(trace_file)) | |
| 113 self._device.old_interface.PullFileFromDevice(trace_file, host_file) | |
| 114 return host_file | |
| 115 | |
| 116 | |
| 117 _SYSTRACE_OPTIONS = [ | |
| 118 # Compress the trace before sending it over USB. | |
| 119 '-z', | |
| 120 # Use a large trace buffer to increase the polling interval. | |
| 121 '-b', '16384' | |
| 122 ] | |
| 123 | |
| 124 # Interval in seconds for sampling systrace data. | |
| 125 _SYSTRACE_INTERVAL = 15 | |
| 126 | |
| 127 | |
| 128 class SystraceController(object): | |
| 129 def __init__(self, device, categories, ring_buffer): | |
| 130 self._device = device | |
| 131 self._categories = categories | |
| 132 self._ring_buffer = ring_buffer | |
| 133 self._done = threading.Event() | |
| 134 self._thread = None | |
| 135 self._trace_data = None | |
| 136 | |
| 137 def __str__(self): | |
| 138 return 'systrace' | |
| 139 | |
| 140 @staticmethod | |
| 141 def GetCategories(device): | |
| 142 return device.old_interface.RunShellCommand('atrace --list_categories') | |
| 143 | |
| 144 def StartTracing(self, _): | |
| 145 self._thread = threading.Thread(target=self._CollectData) | |
| 146 self._thread.start() | |
| 147 | |
| 148 def StopTracing(self): | |
| 149 self._done.set() | |
| 150 | |
| 151 def PullTrace(self): | |
| 152 self._thread.join() | |
| 153 self._thread = None | |
| 154 if self._trace_data: | |
| 155 output_name = 'systrace-%s' % _GetTraceTimestamp() | |
| 156 with open(output_name, 'w') as out: | |
| 157 out.write(self._trace_data) | |
| 158 return output_name | |
| 159 | |
| 160 def _RunATraceCommand(self, command): | |
| 161 # TODO(jbudorick) can this be made work with DeviceUtils? | |
| 162 # We use a separate interface to adb because the one from AndroidCommands | |
| 163 # isn't re-entrant. | |
| 164 device_param = (['-s', self._device.old_interface.GetDevice()] | |
| 165 if self._device.old_interface.GetDevice() else []) | |
| 166 cmd = ['adb'] + device_param + ['shell', 'atrace', '--%s' % command] + \ | |
| 167 _SYSTRACE_OPTIONS + self._categories | |
| 168 return cmd_helper.GetCmdOutput(cmd) | |
| 169 | |
| 170 def _CollectData(self): | |
| 171 trace_data = [] | |
| 172 self._RunATraceCommand('async_start') | |
| 173 try: | |
| 174 while not self._done.is_set(): | |
| 175 self._done.wait(_SYSTRACE_INTERVAL) | |
| 176 if not self._ring_buffer or self._done.is_set(): | |
| 177 trace_data.append( | |
| 178 self._DecodeTraceData(self._RunATraceCommand('async_dump'))) | |
| 179 finally: | |
| 180 trace_data.append( | |
| 181 self._DecodeTraceData(self._RunATraceCommand('async_stop'))) | |
| 182 self._trace_data = ''.join([zlib.decompress(d) for d in trace_data]) | |
| 183 | |
| 184 @staticmethod | |
| 185 def _DecodeTraceData(trace_data): | |
| 186 try: | |
| 187 trace_start = trace_data.index('TRACE:') | |
| 188 except ValueError: | |
| 189 raise RuntimeError('Systrace start marker not found') | |
| 190 trace_data = trace_data[trace_start + 6:] | |
| 191 | |
| 192 # Collapse CRLFs that are added by adb shell. | |
| 193 if trace_data.startswith('\r\n'): | |
| 194 trace_data = trace_data.replace('\r\n', '\n') | |
| 195 | |
| 196 # Skip the initial newline. | |
| 197 return trace_data[1:] | |
| 198 | |
| 199 | |
| 200 def _GetSupportedBrowsers(): | |
| 201 # Add aliases for backwards compatibility. | |
| 202 supported_browsers = { | |
| 203 'stable': constants.PACKAGE_INFO['chrome_stable'], | |
| 204 'beta': constants.PACKAGE_INFO['chrome_beta'], | |
| 205 'dev': constants.PACKAGE_INFO['chrome_dev'], | |
| 206 'build': constants.PACKAGE_INFO['chrome'], | |
| 207 } | |
| 208 supported_browsers.update(constants.PACKAGE_INFO) | |
| 209 unsupported_browsers = ['content_browsertests', 'gtest', 'legacy_browser'] | |
| 210 for browser in unsupported_browsers: | |
| 211 del supported_browsers[browser] | |
| 212 return supported_browsers | |
| 213 | |
| 214 | |
| 215 def _CompressFile(host_file, output): | |
| 216 with gzip.open(output, 'wb') as out: | |
| 217 with open(host_file, 'rb') as input_file: | |
| 218 out.write(input_file.read()) | |
| 219 os.unlink(host_file) | |
| 220 | |
| 221 | |
| 222 def _ArchiveFiles(host_files, output): | |
| 223 with zipfile.ZipFile(output, 'w', zipfile.ZIP_DEFLATED) as z: | |
| 224 for host_file in host_files: | |
| 225 z.write(host_file) | |
| 226 os.unlink(host_file) | |
| 227 | |
| 228 | |
| 229 def _PackageTracesAsHtml(trace_files, html_file): | |
| 230 with open(html_file, 'w') as f: | |
| 231 trace2html.WriteHTMLForTracesToFile(trace_files, f) | |
| 232 for trace_file in trace_files: | |
| 233 os.unlink(trace_file) | |
| 234 | |
| 235 | |
| 236 def _PrintMessage(heading, eol='\n'): | |
| 237 sys.stdout.write('%s%s' % (heading, eol)) | |
| 238 sys.stdout.flush() | |
| 239 | |
| 240 | |
| 241 def _WaitForEnter(timeout): | |
| 242 select.select([sys.stdin], [], [], timeout) | |
| 243 | |
| 244 | |
| 245 def _StartTracing(controllers, interval): | |
| 246 for controller in controllers: | |
| 247 controller.StartTracing(interval) | |
| 248 | |
| 249 | |
| 250 def _StopTracing(controllers): | |
| 251 for controller in controllers: | |
| 252 controller.StopTracing() | |
| 253 | |
| 254 | |
| 255 def _PullTraces(controllers, output, compress, write_json): | |
| 256 _PrintMessage('Downloading...', eol='') | |
| 257 trace_files = [] | |
| 258 for controller in controllers: | |
| 259 trace_files.append(controller.PullTrace()) | |
| 260 | |
| 261 if not write_json: | |
| 262 html_file = os.path.splitext(trace_files[0])[0] + '.html' | |
| 263 _PackageTracesAsHtml(trace_files, html_file) | |
| 264 trace_files = [html_file] | |
| 265 | |
| 266 if compress and len(trace_files) == 1: | |
| 267 result = output or trace_files[0] + '.gz' | |
| 268 _CompressFile(trace_files[0], result) | |
| 269 elif len(trace_files) > 1: | |
| 270 result = output or 'chrome-combined-trace-%s.zip' % _GetTraceTimestamp() | |
| 271 _ArchiveFiles(trace_files, result) | |
| 272 elif output: | |
| 273 result = output | |
| 274 shutil.move(trace_files[0], result) | |
| 275 else: | |
| 276 result = trace_files[0] | |
| 277 | |
| 278 _PrintMessage('done') | |
| 279 _PrintMessage('Trace written to file://%s' % os.path.abspath(result)) | |
| 280 return result | |
| 281 | |
| 282 | |
| 283 def _CaptureAndPullTrace(controllers, interval, output, compress, write_json): | |
| 284 trace_type = ' + '.join(map(str, controllers)) | |
| 285 try: | |
| 286 _StartTracing(controllers, interval) | |
| 287 if interval: | |
| 288 _PrintMessage('Capturing %d-second %s. Press Enter to stop early...' % \ | |
| 289 (interval, trace_type), eol='') | |
| 290 _WaitForEnter(interval) | |
| 291 else: | |
| 292 _PrintMessage('Capturing %s. Press Enter to stop...' % trace_type, eol='') | |
| 293 raw_input() | |
| 294 finally: | |
| 295 _StopTracing(controllers) | |
| 296 if interval: | |
| 297 _PrintMessage('done') | |
| 298 | |
| 299 return _PullTraces(controllers, output, compress, write_json) | |
| 300 | |
| 301 | |
| 302 def _ComputeChromeCategories(options): | |
| 303 categories = [] | |
| 304 if options.trace_frame_viewer: | |
| 305 categories.append('disabled-by-default-cc.debug') | |
| 306 if options.trace_ubercompositor: | |
| 307 categories.append('disabled-by-default-cc.debug*') | |
| 308 if options.trace_gpu: | |
| 309 categories.append('disabled-by-default-gpu.debug*') | |
| 310 if options.trace_flow: | |
| 311 categories.append('disabled-by-default-toplevel.flow') | |
| 312 if options.chrome_categories: | |
| 313 categories += options.chrome_categories.split(',') | |
| 314 return categories | |
| 315 | |
| 316 | |
| 317 def _ComputeSystraceCategories(options): | |
| 318 if not options.systrace_categories: | |
| 319 return [] | |
| 320 return options.systrace_categories.split(',') | |
| 321 | |
| 322 | |
| 323 def main(): | |
| 324 parser = optparse.OptionParser(description='Record about://tracing profiles ' | |
| 325 'from Android browsers. See http://dev.' | |
| 326 'chromium.org/developers/how-tos/trace-event-' | |
| 327 'profiling-tool for detailed instructions for ' | |
| 328 'profiling.') | |
| 329 | |
| 330 timed_options = optparse.OptionGroup(parser, 'Timed tracing') | |
| 331 timed_options.add_option('-t', '--time', help='Profile for N seconds and ' | |
| 332 'download the resulting trace.', metavar='N', | |
| 333 type='float') | |
| 334 parser.add_option_group(timed_options) | |
| 335 | |
| 336 cont_options = optparse.OptionGroup(parser, 'Continuous tracing') | |
| 337 cont_options.add_option('--continuous', help='Profile continuously until ' | |
| 338 'stopped.', action='store_true') | |
| 339 cont_options.add_option('--ring-buffer', help='Use the trace buffer as a ' | |
| 340 'ring buffer and save its contents when stopping ' | |
| 341 'instead of appending events into one long trace.', | |
| 342 action='store_true') | |
| 343 parser.add_option_group(cont_options) | |
| 344 | |
| 345 categories = optparse.OptionGroup(parser, 'Trace categories') | |
| 346 categories.add_option('-c', '--categories', help='Select Chrome tracing ' | |
| 347 'categories with comma-delimited wildcards, ' | |
| 348 'e.g., "*", "cat1*,-cat1a". Omit this option to trace ' | |
| 349 'Chrome\'s default categories. Chrome tracing can be ' | |
| 350 'disabled with "--categories=\'\'". Use "list" to see ' | |
| 351 'the available categories.', | |
| 352 metavar='CHROME_CATEGORIES', dest='chrome_categories', | |
| 353 default=_DEFAULT_CHROME_CATEGORIES) | |
| 354 categories.add_option('-s', '--systrace', help='Capture a systrace with the ' | |
| 355 'chosen comma-delimited systrace categories. You can ' | |
| 356 'also capture a combined Chrome + systrace by enabling ' | |
| 357 'both types of categories. Use "list" to see the ' | |
| 358 'available categories. Systrace is disabled by ' | |
| 359 'default.', metavar='SYS_CATEGORIES', | |
| 360 dest='systrace_categories', default='') | |
| 361 categories.add_option('--trace-cc', | |
| 362 help='Deprecated, use --trace-frame-viewer.', | |
| 363 action='store_true') | |
| 364 categories.add_option('--trace-frame-viewer', | |
| 365 help='Enable enough trace categories for ' | |
| 366 'compositor frame viewing.', action='store_true') | |
| 367 categories.add_option('--trace-ubercompositor', | |
| 368 help='Enable enough trace categories for ' | |
| 369 'ubercompositor frame data.', action='store_true') | |
| 370 categories.add_option('--trace-gpu', help='Enable extra trace categories for ' | |
| 371 'GPU data.', action='store_true') | |
| 372 categories.add_option('--trace-flow', help='Enable extra trace categories ' | |
| 373 'for IPC message flows.', action='store_true') | |
| 374 parser.add_option_group(categories) | |
| 375 | |
| 376 output_options = optparse.OptionGroup(parser, 'Output options') | |
| 377 output_options.add_option('-o', '--output', help='Save trace output to file.') | |
| 378 output_options.add_option('--json', help='Save trace as raw JSON instead of ' | |
| 379 'HTML.', action='store_true') | |
| 380 output_options.add_option('--view', help='Open resulting trace file in a ' | |
| 381 'browser.', action='store_true') | |
| 382 parser.add_option_group(output_options) | |
| 383 | |
| 384 browsers = sorted(_GetSupportedBrowsers().keys()) | |
| 385 parser.add_option('-b', '--browser', help='Select among installed browsers. ' | |
| 386 'One of ' + ', '.join(browsers) + ', "stable" is used by ' | |
| 387 'default.', type='choice', choices=browsers, | |
| 388 default='stable') | |
| 389 parser.add_option('-v', '--verbose', help='Verbose logging.', | |
| 390 action='store_true') | |
| 391 parser.add_option('-z', '--compress', help='Compress the resulting trace ' | |
| 392 'with gzip. ', action='store_true') | |
| 393 options, _args = parser.parse_args() | |
| 394 if options.trace_cc: | |
| 395 parser.parse_error("""--trace-cc is deprecated. | |
| 396 | |
| 397 For basic jank busting uses, use --trace-frame-viewer | |
| 398 For detailed study of ubercompositor, pass --trace-ubercompositor. | |
| 399 | |
| 400 When in doubt, just try out --trace-frame-viewer. | |
| 401 """) | |
| 402 | |
| 403 if options.verbose: | |
| 404 logging.getLogger().setLevel(logging.DEBUG) | |
| 405 | |
| 406 devices = android_commands.GetAttachedDevices() | |
| 407 if len(devices) != 1: | |
| 408 parser.error('Exactly 1 device much be attached.') | |
| 409 device = device_utils.DeviceUtils(devices[0]) | |
| 410 package_info = _GetSupportedBrowsers()[options.browser] | |
| 411 | |
| 412 if options.chrome_categories in ['list', 'help']: | |
| 413 _PrintMessage('Collecting record categories list...', eol='') | |
| 414 record_categories = [] | |
| 415 disabled_by_default_categories = [] | |
| 416 record_categories, disabled_by_default_categories = \ | |
| 417 ChromeTracingController.GetCategories(device, package_info) | |
| 418 | |
| 419 _PrintMessage('done') | |
| 420 _PrintMessage('Record Categories:') | |
| 421 _PrintMessage('\n'.join('\t%s' % item \ | |
| 422 for item in sorted(record_categories))) | |
| 423 | |
| 424 _PrintMessage('\nDisabled by Default Categories:') | |
| 425 _PrintMessage('\n'.join('\t%s' % item \ | |
| 426 for item in sorted(disabled_by_default_categories))) | |
| 427 | |
| 428 return 0 | |
| 429 | |
| 430 if options.systrace_categories in ['list', 'help']: | |
| 431 _PrintMessage('\n'.join(SystraceController.GetCategories(device))) | |
| 432 return 0 | |
| 433 | |
| 434 if not options.time and not options.continuous: | |
| 435 _PrintMessage('Time interval or continuous tracing should be specified.') | |
| 436 return 1 | |
| 437 | |
| 438 chrome_categories = _ComputeChromeCategories(options) | |
| 439 systrace_categories = _ComputeSystraceCategories(options) | |
| 440 | |
| 441 if chrome_categories and 'webview' in systrace_categories: | |
| 442 logging.warning('Using the "webview" category in systrace together with ' | |
| 443 'Chrome tracing results in duplicate trace events.') | |
| 444 | |
| 445 controllers = [] | |
| 446 if chrome_categories: | |
| 447 controllers.append(ChromeTracingController(device, | |
| 448 package_info, | |
| 449 chrome_categories, | |
| 450 options.ring_buffer)) | |
| 451 if systrace_categories: | |
| 452 controllers.append(SystraceController(device, | |
| 453 systrace_categories, | |
| 454 options.ring_buffer)) | |
| 455 | |
| 456 if not controllers: | |
| 457 _PrintMessage('No trace categories enabled.') | |
| 458 return 1 | |
| 459 | |
| 460 if options.output: | |
| 461 options.output = os.path.expanduser(options.output) | |
| 462 result = _CaptureAndPullTrace(controllers, | |
| 463 options.time if not options.continuous else 0, | |
| 464 options.output, | |
| 465 options.compress, | |
| 466 options.json) | |
| 467 if options.view: | |
| 468 if sys.platform == 'darwin': | |
| 469 os.system('/usr/bin/open %s' % os.path.abspath(result)) | |
| 470 else: | |
| 471 webbrowser.open(result) | |
| 472 | 10 |
| 473 | 11 |
| 474 if __name__ == '__main__': | 12 if __name__ == '__main__': |
| 475 sys.exit(main()) | 13 sys.exit(main.main()) |
| OLD | NEW |