blob: b62c4d74c81377cb4be1464afb8a38375c027477 [file] [log] [blame]
// Copyright 2014 The Flutter Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
import 'dart:async';
import 'dart:convert' show json, utf8, LineSplitter, JsonEncoder;
import 'dart:io' as io;
import 'dart:math' as math;
import 'package:path/path.dart' as path;
import 'package:meta/meta.dart';
import 'package:webkit_inspection_protocol/webkit_inspection_protocol.dart';
/// The number of samples used to extract metrics, such as noise, means,
/// max/min values.
///
/// Keep this constant in sync with the same constant defined in `dev/benchmarks/macrobenchmarks/lib/src/web/recorder.dart`.
const int _kMeasuredSampleCount = 10;
/// Options passed to Chrome when launching it.
class ChromeOptions {
ChromeOptions({
this.userDataDirectory,
this.url,
this.windowWidth = 1024,
this.windowHeight = 1024,
this.headless,
this.debugPort,
});
/// If not null passed as `--user-data-dir`.
final String userDataDirectory;
/// If not null launches a Chrome tab at this URL.
final String url;
/// The width of the Chrome window.
///
/// This is important for screenshots and benchmarks.
final int windowWidth;
/// The height of the Chrome window.
///
/// This is important for screenshots and benchmarks.
final int windowHeight;
/// Launches code in "headless" mode, which allows running Chrome in
/// environments without a display, such as LUCI and Cirrus.
final bool headless;
/// The port Chrome will use for its debugging protocol.
///
/// If null, Chrome is launched without debugging. When running in headless
/// mode without a debug port, Chrome quits immediately. For most tests it is
/// typical to set [headless] to true and set a non-null debug port.
final int debugPort;
}
/// A function called when the Chrome process encounters an error.
typedef ChromeErrorCallback = void Function(String);
/// Manages a single Chrome process.
class Chrome {
Chrome._(this._chromeProcess, this._onError, this._debugConnection) {
// If the Chrome process quits before it was asked to quit, notify the
// error listener.
_chromeProcess.exitCode.then((int exitCode) {
if (!_isStopped) {
_onError('Chrome process exited prematurely with exit code $exitCode');
}
});
}
/// Launches Chrome with the give [options].
///
/// The [onError] callback is called with an error message when the Chrome
/// process encounters an error. In particular, [onError] is called when the
/// Chrome process exits prematurely, i.e. before [stop] is called.
static Future<Chrome> launch(ChromeOptions options, { String workingDirectory, @required ChromeErrorCallback onError }) async {
if (!io.Platform.isWindows) {
final io.ProcessResult versionResult = io.Process.runSync(_findSystemChromeExecutable(), const <String>['--version']);
print('Launching ${versionResult.stdout}');
} else {
print('Launching Chrome...');
}
final bool withDebugging = options.debugPort != null;
final List<String> args = <String>[
if (options.userDataDirectory != null)
'--user-data-dir=${options.userDataDirectory}',
if (options.url != null)
options.url,
if (io.Platform.environment['CHROME_NO_SANDBOX'] == 'true')
'--no-sandbox',
if (options.headless)
'--headless',
if (withDebugging)
'--remote-debugging-port=${options.debugPort}',
'--window-size=${options.windowWidth},${options.windowHeight}',
'--disable-extensions',
'--disable-popup-blocking',
// Indicates that the browser is in "browse without sign-in" (Guest session) mode.
'--bwsi',
'--no-first-run',
'--no-default-browser-check',
'--disable-default-apps',
'--disable-translate',
];
final io.Process chromeProcess = await io.Process.start(
_findSystemChromeExecutable(),
args,
workingDirectory: workingDirectory,
);
WipConnection debugConnection;
if (withDebugging) {
debugConnection = await _connectToChromeDebugPort(chromeProcess, options.debugPort);
}
return Chrome._(chromeProcess, onError, debugConnection);
}
final io.Process _chromeProcess;
final ChromeErrorCallback _onError;
final WipConnection _debugConnection;
bool _isStopped = false;
Completer<void> _tracingCompleter;
StreamSubscription<WipEvent> _tracingSubscription;
List<Map<String, dynamic>> _tracingData;
/// Starts recording a performance trace.
///
/// If there is already a tracing session in progress, throws an error. Call
/// [endRecordingPerformance] before starting a new tracing session.
///
/// The [label] is for debugging convenience.
Future<void> beginRecordingPerformance(String label) async {
if (_tracingCompleter != null) {
throw StateError(
'Cannot start a new performance trace. A tracing session labeled '
'"$label" is already in progress.'
);
}
_tracingCompleter = Completer<void>();
_tracingData = <Map<String, dynamic>>[];
// Subscribe to tracing events prior to calling "Tracing.start". Otherwise,
// we'll miss tracing data.
_tracingSubscription = _debugConnection.onNotification.listen((WipEvent event) {
// We receive data as a sequence of "Tracing.dataCollected" followed by
// "Tracing.tracingComplete" at the end. Until "Tracing.tracingComplete"
// is received, the data may be incomplete.
if (event.method == 'Tracing.tracingComplete') {
_tracingCompleter.complete();
_tracingSubscription.cancel();
_tracingSubscription = null;
} else if (event.method == 'Tracing.dataCollected') {
final dynamic value = event.params['value'];
if (value is! List) {
throw FormatException('"Tracing.dataCollected" returned malformed data. '
'Expected a List but got: ${value.runtimeType}');
}
_tracingData.addAll((event.params['value'] as List<dynamic>).cast<Map<String, dynamic>>());
}
});
await _debugConnection.sendCommand('Tracing.start', <String, dynamic>{
// The choice of categories is as follows:
//
// blink:
// provides everything on the UI thread, including scripting,
// style recalculations, layout, painting, and some compositor
// work.
// blink.user_timing:
// provides marks recorded using window.performance. We use marks
// to find frames that the benchmark cares to measure.
// gpu:
// provides tracing data from the GPU data
// disabled due to https://bugs.chromium.org/p/chromium/issues/detail?id=1068259
// TODO(yjbanov): extract useful GPU data
'categories': 'blink,blink.user_timing',
'transferMode': 'SendAsStream',
});
}
/// Stops a performance tracing session started by [beginRecordingPerformance].
///
/// Returns all the collected tracing data unfiltered.
Future<List<Map<String, dynamic>>> endRecordingPerformance() async {
await _debugConnection.sendCommand('Tracing.end');
await _tracingCompleter.future;
final List<Map<String, dynamic>> data = _tracingData;
_tracingCompleter = null;
_tracingData = null;
return data;
}
/// Stops the Chrome process.
void stop() {
_isStopped = true;
_chromeProcess.kill();
}
}
String _findSystemChromeExecutable() {
// On some environments, such as the Dart HHH tester, Chrome resides in a
// non-standard location and is provided via the following environment
// variable.
final String envExecutable = io.Platform.environment['CHROME_EXECUTABLE'];
if (envExecutable != null) {
return envExecutable;
}
if (io.Platform.isLinux) {
final io.ProcessResult which =
io.Process.runSync('which', <String>['google-chrome']);
if (which.exitCode != 0) {
throw Exception('Failed to locate system Chrome installation.');
}
return (which.stdout as String).trim();
} else if (io.Platform.isMacOS) {
return '/Applications/Google Chrome.app/Contents/MacOS/Google Chrome';
} else if (io.Platform.isWindows) {
const String kWindowsExecutable = r'Google\Chrome\Application\chrome.exe';
final List<String> kWindowsPrefixes = <String>[
io.Platform.environment['LOCALAPPDATA'],
io.Platform.environment['PROGRAMFILES'],
io.Platform.environment['PROGRAMFILES(X86)'],
];
final String windowsPrefix = kWindowsPrefixes.firstWhere((String prefix) {
if (prefix == null) {
return false;
}
final String expectedPath = path.join(prefix, kWindowsExecutable);
return io.File(expectedPath).existsSync();
}, orElse: () => '.');
return path.join(windowsPrefix, kWindowsExecutable);
} else {
throw Exception('Web benchmarks cannot run on ${io.Platform.operatingSystem}.');
}
}
/// Waits for Chrome to print DevTools URI and connects to it.
Future<WipConnection> _connectToChromeDebugPort(io.Process chromeProcess, int port) async {
chromeProcess.stdout
.transform(utf8.decoder)
.transform(const LineSplitter())
.listen((String line) {
print('[CHROME]: $line');
});
await chromeProcess.stderr
.transform(utf8.decoder)
.transform(const LineSplitter())
.map((String line) {
print('[CHROME]: $line');
return line;
})
.firstWhere((String line) => line.startsWith('DevTools listening'), orElse: () {
throw Exception('Expected Chrome to print "DevTools listening" string '
'with DevTools URL, but the string was never printed.');
});
final Uri devtoolsUri = await _getRemoteDebuggerUrl(Uri.parse('http://localhost:$port'));
print('Connecting to DevTools: $devtoolsUri');
final ChromeConnection chromeConnection = ChromeConnection('localhost', port);
final Iterable<ChromeTab> tabs = (await chromeConnection.getTabs()).where((ChromeTab tab) {
return tab.url.startsWith('http://localhost');
});
final ChromeTab tab = tabs.single;
final WipConnection debugConnection = await tab.connect();
print('Connected to Chrome tab: ${tab.title} (${tab.url})');
return debugConnection;
}
/// Gets the Chrome debugger URL for the web page being benchmarked.
Future<Uri> _getRemoteDebuggerUrl(Uri base) async {
final io.HttpClient client = io.HttpClient();
final io.HttpClientRequest request = await client.getUrl(base.resolve('/json/list'));
final io.HttpClientResponse response = await request.close();
final List<dynamic> jsonObject = await json.fuse(utf8).decoder.bind(response).single as List<dynamic>;
if (jsonObject == null || jsonObject.isEmpty) {
return base;
}
return base.resolve(jsonObject.first['webSocketDebuggerUrl'] as String);
}
/// Summarizes a Blink trace down to a few interesting values.
class BlinkTraceSummary {
BlinkTraceSummary._({
@required this.averageBeginFrameTime,
@required this.averageUpdateLifecyclePhasesTime,
}) : averageTotalUIFrameTime = averageBeginFrameTime + averageUpdateLifecyclePhasesTime;
static BlinkTraceSummary fromJson(List<Map<String, dynamic>> traceJson) {
try {
// Convert raw JSON data to BlinkTraceEvent objects sorted by timestamp.
List<BlinkTraceEvent> events = traceJson
.map<BlinkTraceEvent>(BlinkTraceEvent.fromJson)
.toList()
..sort((BlinkTraceEvent a, BlinkTraceEvent b) => a.ts - b.ts);
Exception noMeasuredFramesFound() => Exception(
'No measured frames found in benchmark tracing data. This likely '
'indicates a bug in the benchmark. For example, the benchmark failed '
'to pump enough frames. It may also indicate a change in Chrome\'s '
'tracing data format. Check if Chrome version changed recently and '
'adjust the parsing code accordingly.',
);
// Use the pid from the first "measured_frame" event since the event is
// emitted by the script running on the process we're interested in.
//
// We previously tried using the "CrRendererMain" event. However, for
// reasons unknown, Chrome in the devicelab refuses to emit this event
// sometimes, causing to flakes.
final BlinkTraceEvent firstMeasuredFrameEvent = events.firstWhere(
(BlinkTraceEvent event) => event.isBeginMeasuredFrame,
orElse: () => throw noMeasuredFramesFound(),
);
if (firstMeasuredFrameEvent == null) {
// This happens in benchmarks that do not measure frames, such as some
// of the text layout benchmarks.
return null;
}
final int tabPid = firstMeasuredFrameEvent.pid;
// Filter out data from unrelated processes
events = events.where((BlinkTraceEvent element) => element.pid == tabPid).toList();
// Extract frame data.
final List<BlinkFrame> frames = <BlinkFrame>[];
int skipCount = 0;
BlinkFrame frame = BlinkFrame();
for (final BlinkTraceEvent event in events) {
if (event.isBeginFrame) {
frame.beginFrame = event;
} else if (event.isUpdateAllLifecyclePhases) {
frame.updateAllLifecyclePhases = event;
if (frame.endMeasuredFrame != null) {
frames.add(frame);
} else {
skipCount += 1;
}
frame = BlinkFrame();
} else if (event.isBeginMeasuredFrame) {
frame.beginMeasuredFrame = event;
} else if (event.isEndMeasuredFrame) {
frame.endMeasuredFrame = event;
}
}
print('Extracted ${frames.length} measured frames.');
print('Skipped $skipCount non-measured frames.');
if (frames.isEmpty) {
throw noMeasuredFramesFound();
}
// Compute averages and summarize.
return BlinkTraceSummary._(
averageBeginFrameTime: _computeAverageDuration(frames.map((BlinkFrame frame) => frame.beginFrame).toList()),
averageUpdateLifecyclePhasesTime: _computeAverageDuration(frames.map((BlinkFrame frame) => frame.updateAllLifecyclePhases).toList()),
);
} catch (_, __) {
final io.File traceFile = io.File('./chrome-trace.json');
io.stderr.writeln('Failed to interpret the Chrome trace contents. The trace was saved in ${traceFile.path}');
traceFile.writeAsStringSync(const JsonEncoder.withIndent(' ').convert(traceJson));
rethrow;
}
}
/// The average duration of "WebViewImpl::beginFrame" events.
///
/// This event contains all of scripting time of an animation frame, plus an
/// unknown small amount of work browser does before and after scripting.
final Duration averageBeginFrameTime;
/// The average duration of "WebViewImpl::updateAllLifecyclePhases" events.
///
/// This event contains style, layout, painting, and compositor computations,
/// which are not included in the scripting time. This event does not
/// include GPU time, which happens on a separate thread.
final Duration averageUpdateLifecyclePhasesTime;
/// The average sum of [averageBeginFrameTime] and
/// [averageUpdateLifecyclePhasesTime].
///
/// This value contains the vast majority of work the UI thread performs in
/// any given animation frame.
final Duration averageTotalUIFrameTime;
@override
String toString() => '$BlinkTraceSummary('
'averageBeginFrameTime: ${averageBeginFrameTime.inMicroseconds / 1000}ms, '
'averageUpdateLifecyclePhasesTime: ${averageUpdateLifecyclePhasesTime.inMicroseconds / 1000}ms)';
}
/// Contains events pertaining to a single frame in the Blink trace data.
class BlinkFrame {
/// Corresponds to 'WebViewImpl::beginFrame' event.
BlinkTraceEvent beginFrame;
/// Corresponds to 'WebViewImpl::updateAllLifecyclePhases' event.
BlinkTraceEvent updateAllLifecyclePhases;
/// Corresponds to 'measured_frame' begin event.
BlinkTraceEvent beginMeasuredFrame;
/// Corresponds to 'measured_frame' end event.
BlinkTraceEvent endMeasuredFrame;
}
/// Takes a list of events that have non-null [BlinkTraceEvent.tdur] computes
/// their average as a [Duration] value.
Duration _computeAverageDuration(List<BlinkTraceEvent> events) {
// Compute the sum of "tdur" fields of the last _kMeasuredSampleCount events.
final double sum = events
.skip(math.max(events.length - _kMeasuredSampleCount, 0))
.fold(0.0, (double previousValue, BlinkTraceEvent event) {
if (event.tdur == null) {
throw FormatException('Trace event lacks "tdur" field: $event');
}
return previousValue + event.tdur;
});
final int sampleCount = math.min(events.length, _kMeasuredSampleCount);
return Duration(microseconds: sum ~/ sampleCount);
}
/// An event collected by the Blink tracer (in Chrome accessible using chrome://tracing).
///
/// See also:
/// * https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview
class BlinkTraceEvent {
BlinkTraceEvent._({
@required this.args,
@required this.cat,
@required this.name,
@required this.ph,
@required this.pid,
@required this.tid,
@required this.ts,
@required this.tts,
@required this.tdur,
});
/// Parses an event from its JSON representation.
///
/// Sample event encoded as JSON (the data is bogus, this just shows the format):
///
/// ```
/// {
/// "name": "myName",
/// "cat": "category,list",
/// "ph": "B",
/// "ts": 12345,
/// "pid": 123,
/// "tid": 456,
/// "args": {
/// "someArg": 1,
/// "anotherArg": {
/// "value": "my value"
/// }
/// }
/// }
/// ```
///
/// For detailed documentation of the format see:
///
/// https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview
static BlinkTraceEvent fromJson(Map<String, dynamic> json) {
return BlinkTraceEvent._(
args: json['args'] as Map<String, dynamic>,
cat: json['cat'] as String,
name: json['name'] as String,
ph: json['ph'] as String,
pid: _readInt(json, 'pid'),
tid: _readInt(json, 'tid'),
ts: _readInt(json, 'ts'),
tts: _readInt(json, 'tts'),
tdur: _readInt(json, 'tdur'),
);
}
/// Event-specific data.
final Map<String, dynamic> args;
/// Event category.
final String cat;
/// Event name.
final String name;
/// Event "phase".
final String ph;
/// Process ID of the process that emitted the event.
final int pid;
/// Thread ID of the thread that emitted the event.
final int tid;
/// Timestamp in microseconds using tracer clock.
final int ts;
/// Timestamp in microseconds using thread clock.
final int tts;
/// Event duration in microseconds.
final int tdur;
/// A "begin frame" event contains all of the scripting time of an animation
/// frame (JavaScript, WebAssembly), plus a negligible amount of internal
/// browser overhead.
///
/// This event does not include non-UI thread scripting, such as web workers,
/// service workers, and CSS Paint paintlets.
///
/// This event is a duration event that has its `tdur` populated.
bool get isBeginFrame => ph == 'X' && name == 'WebViewImpl::beginFrame';
/// An "update all lifecycle phases" event contains UI thread computations
/// related to an animation frame that's outside the scripting phase.
///
/// This event includes style recalculation, layer tree update, layout,
/// painting, and parts of compositing work.
///
/// This event is a duration event that has its `tdur` populated.
bool get isUpdateAllLifecyclePhases => ph == 'X' && name == 'WebViewImpl::updateAllLifecyclePhases';
/// Whether this is the beginning of a "measured_frame" event.
///
/// This event is a custom event emitted by our benchmark test harness.
///
/// See also:
/// * `recorder.dart`, which emits this event.
bool get isBeginMeasuredFrame => ph == 'b' && name == 'measured_frame';
/// Whether this is the end of a "measured_frame" event.
///
/// This event is a custom event emitted by our benchmark test harness.
///
/// See also:
/// * `recorder.dart`, which emits this event.
bool get isEndMeasuredFrame => ph == 'e' && name == 'measured_frame';
@override
String toString() => '$BlinkTraceEvent('
'args: ${json.encode(args)}, '
'cat: $cat, '
'name: $name, '
'ph: $ph, '
'pid: $pid, '
'tid: $tid, '
'ts: $ts, '
'tts: $tts, '
'tdur: $tdur)';
}
/// Read an integer out of [json] stored under [key].
///
/// Since JSON does not distinguish between `int` and `double`, extra
/// validation and conversion is needed.
///
/// Returns null if the value is null.
int _readInt(Map<String, dynamic> json, String key) {
final num jsonValue = json[key] as num;
if (jsonValue == null) {
return null;
}
return jsonValue.toInt();
}