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 |