[framework,web] add FlutterTimeline and semantics benchmarks that use it (#128366)

## FlutterTimeline

Add a new class `FlutterTimeline` that's a drop-in replacement for `Timeline` from `dart:developer`. In addition to forwarding invocations of `startSync`, `finishSync`, `timeSync`, and `instantSync` to `dart:developer`, provides the following extra methods that make is easy to collect timings for code blocks on a frame-by-frame basis:

* `debugCollect()` - aggregates timings since the last reset, or since the app launched.
* `debugReset()` - forgets all data collected since the previous reset, or since the app launched. This allows clearing data from previous frames so timings can be attributed to the current frame.
* `now` - this was enhanced so that it works on the web by calling `window.performance.now` (in `Timeline` this is a noop in Dart web compilers).
* `collectionEnabled` - a field that controls whether `FlutterTimeline` stores timings in memory. By default this is disabled to avoid unexpected overhead (although the class is designed for minimal and predictable overhead). Specific benchmarks can enable collection to report to Skia Perf.

## Semantics benchmarks

Add `BenchMaterial3Semantics` that benchmarks the cost of semantics when constructing a screen full of Material 3 widgets from nothing. It is expected that semantics will have non-trivial cost in this case, but we should strive to keep it much lower than the rendering cost. This is the case already. This benchmark shows that the cost of semantics is <10%.

Add `BenchMaterial3ScrollSemantics` that benchmarks the cost of scrolling a previously constructed screen full of Material 3 widgets. The expectation should be that semantics will have trivial cost, since we're just shifting some widgets around. As of today, the numbers are not great, with semantics taking >50% of frame time, which is what prompted this PR in the first place. As we optimize this, we want to see this number improve.
This commit is contained in:
Yegor 2023-06-21 14:37:02 -07:00 committed by GitHub
parent 220057794b
commit 07772a3d23
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
19 changed files with 3229 additions and 2377 deletions

View File

@ -0,0 +1,147 @@
// 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 'package:flutter/foundation.dart';
import 'package:flutter/material.dart';
import 'package:flutter/scheduler.dart';
import 'package:flutter/semantics.dart';
import 'material3.dart';
import 'recorder.dart';
/// Measures the cost of semantics when constructing screens containing
/// Material 3 widgets.
class BenchMaterial3Semantics extends WidgetBuildRecorder {
BenchMaterial3Semantics() : super(name: benchmarkName);
static const String benchmarkName = 'bench_material3_semantics';
@override
Future<void> setUpAll() async {
FlutterTimeline.debugCollectionEnabled = true;
super.setUpAll();
SemanticsBinding.instance.ensureSemantics();
}
@override
Future<void> tearDownAll() async {
FlutterTimeline.debugReset();
}
@override
void frameDidDraw() {
// Only record frames that show the widget. Frames that remove the widget
// are not interesting.
if (showWidget) {
final AggregatedTimings timings = FlutterTimeline.debugCollect();
final AggregatedTimedBlock semanticsBlock = timings.getAggregated('SEMANTICS');
final AggregatedTimedBlock getFragmentBlock = timings.getAggregated('Semantics.GetFragment');
final AggregatedTimedBlock compileChildrenBlock = timings.getAggregated('Semantics.compileChildren');
profile!.addTimedBlock(semanticsBlock, reported: true);
profile!.addTimedBlock(getFragmentBlock, reported: true);
profile!.addTimedBlock(compileChildrenBlock, reported: true);
}
super.frameDidDraw();
FlutterTimeline.debugReset();
}
@override
Widget createWidget() {
return const SingleColumnMaterial3Components();
}
}
/// Measures the cost of semantics when scrolling screens containing Material 3
/// widgets.
///
/// The implementation uses a ListView that jumps the scroll position between
/// 0 and 1 every frame. Such a small delta is not enough for lazy rendering to
/// add/remove widgets, but its enough to trigger the framework to recompute
/// some of the semantics.
///
/// The expected output numbers of this benchmarks should be very small as
/// scrolling a list view should be a matter of shifting some widgets and
/// updating the projected clip imposed by the viewport. As of June 2023, the
/// numbers are not great. Semantics consumes >50% of frame time.
class BenchMaterial3ScrollSemantics extends WidgetRecorder {
BenchMaterial3ScrollSemantics() : super(name: benchmarkName);
static const String benchmarkName = 'bench_material3_scroll_semantics';
@override
Future<void> setUpAll() async {
FlutterTimeline.debugCollectionEnabled = true;
super.setUpAll();
SemanticsBinding.instance.ensureSemantics();
}
@override
Future<void> tearDownAll() async {
FlutterTimeline.debugReset();
}
@override
void frameDidDraw() {
final AggregatedTimings timings = FlutterTimeline.debugCollect();
final AggregatedTimedBlock semanticsBlock = timings.getAggregated('SEMANTICS');
final AggregatedTimedBlock getFragmentBlock = timings.getAggregated('Semantics.GetFragment');
final AggregatedTimedBlock compileChildrenBlock = timings.getAggregated('Semantics.compileChildren');
profile!.addTimedBlock(semanticsBlock, reported: true);
profile!.addTimedBlock(getFragmentBlock, reported: true);
profile!.addTimedBlock(compileChildrenBlock, reported: true);
super.frameDidDraw();
FlutterTimeline.debugReset();
}
@override
Widget createWidget() => _ScrollTest();
}
class _ScrollTest extends StatefulWidget {
@override
State<_ScrollTest> createState() => _ScrollTestState();
}
class _ScrollTestState extends State<_ScrollTest> with SingleTickerProviderStateMixin {
late final Ticker ticker;
late final ScrollController scrollController;
@override
void initState() {
super.initState();
scrollController = ScrollController();
bool forward = true;
// A one-off timer is necessary to allow the framework to measure the
// available scroll extents before the scroll controller can be exercised
// to change the scroll position.
Timer.run(() {
ticker = createTicker((_) {
scrollController.jumpTo(forward ? 1 : 0);
forward = !forward;
});
ticker.start();
});
}
@override
void dispose() {
ticker.dispose();
scrollController.dispose();
super.dispose();
}
@override
Widget build(BuildContext context) {
return SingleColumnMaterial3Components(
scrollController: scrollController,
);
}
}

View File

@ -203,6 +203,7 @@ class BenchBuildColorsGrid extends WidgetBuildRecorder {
@override
Future<void> setUpAll() async {
super.setUpAll();
registerEngineBenchmarkValueListener('text_layout', (num value) {
_textLayoutMicros += value;
});

File diff suppressed because it is too large Load Diff

View File

@ -426,12 +426,18 @@ abstract class WidgetRecorder extends Recorder implements FrameRecorder {
_runCompleter!.completeError(error, stackTrace);
}
late final _RecordingWidgetsBinding _binding;
@override
@mustCallSuper
Future<void> setUpAll() async {
_binding = _RecordingWidgetsBinding.ensureInitialized();
}
@override
Future<Profile> run() async {
_runCompleter = Completer<void>();
final Profile localProfile = profile = Profile(name: name, useCustomWarmUp: useCustomWarmUp);
final _RecordingWidgetsBinding binding =
_RecordingWidgetsBinding.ensureInitialized();
final Widget widget = createWidget();
registerEngineBenchmarkValueListener(kProfilePrerollFrame, (num value) {
@ -449,7 +455,7 @@ abstract class WidgetRecorder extends Recorder implements FrameRecorder {
);
});
binding._beginRecording(this, widget);
_binding._beginRecording(this, widget);
try {
await _runCompleter!.future;
@ -508,6 +514,14 @@ abstract class WidgetBuildRecorder extends Recorder implements FrameRecorder {
}
}
late final _RecordingWidgetsBinding _binding;
@override
@mustCallSuper
Future<void> setUpAll() async {
_binding = _RecordingWidgetsBinding.ensureInitialized();
}
@override
@mustCallSuper
void frameWillDraw() {
@ -546,9 +560,7 @@ abstract class WidgetBuildRecorder extends Recorder implements FrameRecorder {
Future<Profile> run() async {
_runCompleter = Completer<void>();
final Profile localProfile = profile = Profile(name: name);
final _RecordingWidgetsBinding binding =
_RecordingWidgetsBinding.ensureInitialized();
binding._beginRecording(this, _WidgetBuildRecorderHost(this));
_binding._beginRecording(this, _WidgetBuildRecorderHost(this));
try {
await _runCompleter!.future;
@ -948,6 +960,15 @@ class Profile {
}
}
/// A convenience wrapper over [addDataPoint] for adding [AggregatedTimedBlock]
/// to the profile.
///
/// Uses [AggregatedTimedBlock.name] as the name of the data point, and
/// [AggregatedTimedBlock.duration] as the duration.
void addTimedBlock(AggregatedTimedBlock timedBlock, { required bool reported }) {
addDataPoint(timedBlock.name, Duration(microseconds: timedBlock.duration.toInt()), reported: reported);
}
/// Checks the samples collected so far and sets the appropriate benchmark phase.
///
/// If enough warm-up samples have been collected, stops the warm-up phase and

View File

@ -19,6 +19,7 @@ import 'src/web/bench_draw_rect.dart';
import 'src/web/bench_dynamic_clip_on_static_picture.dart';
import 'src/web/bench_image_decoding.dart';
import 'src/web/bench_material_3.dart';
import 'src/web/bench_material_3_semantics.dart';
import 'src/web/bench_mouse_region_grid_hover.dart';
import 'src/web/bench_mouse_region_grid_scroll.dart';
import 'src/web/bench_mouse_region_mixed_grid_hover.dart';
@ -64,6 +65,8 @@ final Map<String, RecorderFactory> benchmarks = <String, RecorderFactory>{
BenchPlatformViewInfiniteScroll.benchmarkName: () => BenchPlatformViewInfiniteScroll.forward(),
BenchPlatformViewInfiniteScroll.benchmarkNameBackward: () => BenchPlatformViewInfiniteScroll.backward(),
BenchMaterial3Components.benchmarkName: () => BenchMaterial3Components(),
BenchMaterial3Semantics.benchmarkName: () => BenchMaterial3Semantics(),
BenchMaterial3ScrollSemantics.benchmarkName: () => BenchMaterial3ScrollSemantics(),
// CanvasKit-only benchmarks
if (isCanvasKit) ...<String, RecorderFactory>{

View File

@ -2,7 +2,7 @@
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
import 'dart:developer';
import 'package:flutter/foundation.dart';
import '../common.dart';
@ -16,8 +16,8 @@ void main() {
final Stopwatch watch = Stopwatch();
watch.start();
for (int i = 0; i < _kNumIterations; i += 1) {
Timeline.startSync('foo');
Timeline.finishSync();
FlutterTimeline.startSync('foo');
FlutterTimeline.finishSync();
}
watch.stop();
@ -31,14 +31,14 @@ void main() {
watch.reset();
watch.start();
for (int i = 0; i < _kNumIterations; i += 1) {
Timeline.startSync('foo', arguments: <String, dynamic>{
FlutterTimeline.startSync('foo', arguments: <String, dynamic>{
'int': 1234,
'double': 0.3,
'list': <int>[1, 2, 3, 4],
'map': <String, dynamic>{'map': true},
'bool': false,
});
Timeline.finishSync();
FlutterTimeline.finishSync();
}
watch.stop();

View File

@ -1375,6 +1375,14 @@ Future<void> _runWebTreeshakeTest() async {
pos = javaScript.indexOf(word, pos);
}
// The following are classes from `timeline.dart` that should be treeshaken
// off unless the app (typically a benchmark) uses methods that need them.
expect(javaScript.contains('AggregatedTimedBlock'), false);
expect(javaScript.contains('AggregatedTimings'), false);
expect(javaScript.contains('_BlockBuffer'), false);
expect(javaScript.contains('_StringListChain'), false);
expect(javaScript.contains('_Float64ListChain'), false);
const int kMaxExpectedDebugFillProperties = 11;
if (count > kMaxExpectedDebugFillProperties) {
throw Exception(

View File

@ -46,4 +46,5 @@ export 'src/foundation/serialization.dart';
export 'src/foundation/service_extensions.dart';
export 'src/foundation/stack_frame.dart';
export 'src/foundation/synchronous_future.dart';
export 'src/foundation/timeline.dart';
export 'src/foundation/unicode.dart';

View File

@ -0,0 +1,11 @@
// 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:developer';
/// Returns the current timestamp in microseconds from a monotonically
/// increasing clock.
///
/// This is the Dart VM implementation.
double get performanceTimestamp => Timeline.now.toDouble();

View File

@ -0,0 +1,27 @@
// 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:js_interop';
/// Returns the current timestamp in microseconds from a monotonically
/// increasing clock.
///
/// This is the web implementation, which uses `window.performance.now` as the
/// source of the timestamp.
///
/// See:
/// * https://developer.mozilla.org/en-US/docs/Web/API/Performance/now
double get performanceTimestamp => 1000 * _performance.now();
@JS()
@staticInterop
class _DomPerformance {}
@JS('performance')
external _DomPerformance get _performance;
extension _DomPerformanceExtension on _DomPerformance {
@JS()
external double now();
}

View File

@ -20,6 +20,7 @@ import 'object.dart';
import 'platform.dart';
import 'print.dart';
import 'service_extensions.dart';
import 'timeline.dart';
export 'dart:ui' show PlatformDispatcher, SingletonFlutterWindow; // ignore: deprecated_member_use
@ -141,7 +142,9 @@ abstract class BindingBase {
/// [initServiceExtensions] to have bindings initialize their
/// VM service extensions, if any.
BindingBase() {
developer.Timeline.startSync('Framework initialization');
if (!kReleaseMode) {
FlutterTimeline.startSync('Framework initialization');
}
assert(() {
_debugConstructed = true;
return true;
@ -157,7 +160,9 @@ abstract class BindingBase {
developer.postEvent('Flutter.FrameworkInitialization', <String, String>{});
developer.Timeline.finishSync();
if (!kReleaseMode) {
FlutterTimeline.finishSync();
}
}
bool _debugConstructed = false;

View File

@ -0,0 +1,432 @@
// 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:developer';
import 'dart:typed_data';
import 'package:meta/meta.dart';
import '_timeline_io.dart'
if (dart.library.js_util) '_timeline_web.dart' as impl;
import 'constants.dart';
/// Measures how long blocks of code take to run.
///
/// This class can be used as a drop-in replacement for [Timeline] as it
/// provides methods compatible with [Timeline] signature-wise, and it has
/// minimal overhead.
///
/// Provides [debugReset] and [debugCollect] methods that make it convenient to use in
/// frame-oriented environment where collected metrics can be attributed to a
/// frame, then aggregated into frame statistics, e.g. frame averages.
///
/// Forwards measurements to [Timeline] so they appear in Flutter DevTools.
abstract final class FlutterTimeline {
static _BlockBuffer _buffer = _BlockBuffer();
/// Whether block timings are collected and can be retrieved using the
/// [debugCollect] method.
///
/// This is always false in release mode.
static bool get debugCollectionEnabled => _collectionEnabled;
/// Enables metric collection.
///
/// Metric collection can only be enabled in non-release modes. It is most
/// useful in profile mode where application performance is representative
/// of a deployed application.
///
/// When disabled, resets collected data by calling [debugReset].
///
/// Throws a [StateError] if invoked in release mode.
static set debugCollectionEnabled(bool value) {
if (kReleaseMode) {
throw _createReleaseModeNotSupportedError();
}
if (value == _collectionEnabled) {
return;
}
_collectionEnabled = value;
debugReset();
}
static StateError _createReleaseModeNotSupportedError() {
return StateError('FlutterTimeline metric collection not supported in release mode.');
}
static bool _collectionEnabled = false;
/// Start a synchronous operation labeled `name`.
///
/// Optionally takes a map of `arguments`. This slice may also optionally be
/// associated with a [Flow] event. This operation must be finished by calling
/// [finishSync] before returning to the event queue.
///
/// This is a drop-in replacement for [Timeline.startSync].
static void startSync(String name, { Map<String, Object?>? arguments, Flow? flow }) {
Timeline.startSync(name, arguments: arguments, flow: flow);
if (!kReleaseMode && _collectionEnabled) {
_buffer.startSync(name, arguments: arguments, flow: flow);
}
}
/// Finish the last synchronous operation that was started.
///
/// This is a drop-in replacement for [Timeline.finishSync].
static void finishSync() {
Timeline.finishSync();
if (!kReleaseMode && _collectionEnabled) {
_buffer.finishSync();
}
}
/// Emit an instant event.
///
/// This is a drop-in replacement for [Timeline.instantSync].
static void instantSync(String name, { Map<String, Object?>? arguments }) {
Timeline.instantSync(name, arguments: arguments);
}
/// A utility method to time a synchronous `function`. Internally calls
/// `function` bracketed by calls to [startSync] and [finishSync].
///
/// This is a drop-in replacement for [Timeline.timeSync].
static T timeSync<T>(String name, TimelineSyncFunction<T> function,
{ Map<String, Object?>? arguments, Flow? flow }) {
startSync(name, arguments: arguments, flow: flow);
try {
return function();
} finally {
finishSync();
}
}
/// The current time stamp from the clock used by the timeline in
/// microseconds.
///
/// When run on the Dart VM, uses the same monotonic clock as the embedding
/// API's `Dart_TimelineGetMicros`.
///
/// When run on the web, uses `window.performance.now`.
///
/// This is a drop-in replacement for [Timeline.now].
static int get now => impl.performanceTimestamp.toInt();
/// Returns timings collected since [debugCollectionEnabled] was set to true,
/// since the previous [debugCollect], or since the previous [debugReset],
/// whichever was last.
///
/// Resets the collected timings.
///
/// This is only meant to be used in non-release modes, typically in profile
/// mode that provides timings close to release mode timings.
static AggregatedTimings debugCollect() {
if (kReleaseMode) {
throw _createReleaseModeNotSupportedError();
}
if (!_collectionEnabled) {
throw StateError('Timeline metric collection not enabled.');
}
final AggregatedTimings result = AggregatedTimings(_buffer.computeTimings());
debugReset();
return result;
}
/// Forgets all previously collected timing data.
///
/// Use this method to scope metrics to a frame, a pointer event, or any
/// other event. To do that, call [debugReset] at the start of the event, then
/// call [debugCollect] at the end of the event.
///
/// This is only meant to be used in non-release modes.
static void debugReset() {
if (kReleaseMode) {
throw _createReleaseModeNotSupportedError();
}
_buffer = _BlockBuffer();
}
}
/// Provides [start], [end], and [duration] of a named block of code, timed by
/// [FlutterTimeline].
@immutable
final class TimedBlock {
/// Creates a timed block of code from a [name], [start], and [end].
///
/// The [name] should be sufficiently unique and descriptive for someone to
/// easily tell which part of code was measured.
const TimedBlock({
required this.name,
required this.start,
required this.end,
}) : assert(end >= start, 'The start timestamp must not be greater than the end timestamp.');
/// A readable label for a block of code that was measured.
///
/// This field should be sufficiently unique and descriptive for someone to
/// easily tell which part of code was measured.
final String name;
/// The timestamp in microseconds that marks the beginning of the measured
/// block of code.
final double start;
/// The timestamp in microseconds that marks the end of the measured block of
/// code.
final double end;
/// How long the measured block of code took to execute in microseconds.
double get duration => end - start;
@override
String toString() {
return 'TimedBlock($name, $start, $end, $duration)';
}
}
/// Provides aggregated results for timings collected by [FlutterTimeline].
@immutable
final class AggregatedTimings {
/// Creates aggregated timings for the provided timed blocks.
AggregatedTimings(this.timedBlocks);
/// All timed blocks collected between the last reset and [FlutterTimeline.debugCollect].
final List<TimedBlock> timedBlocks;
/// Aggregated timed blocks collected between the last reset and [FlutterTimeline.debugCollect].
///
/// Does not guarantee that all code blocks will be reported. Only those that
/// executed since the last reset are listed here. Use [getAggregated] for
/// graceful handling of missing code blocks.
late final List<AggregatedTimedBlock> aggregatedBlocks = _computeAggregatedBlocks();
List<AggregatedTimedBlock> _computeAggregatedBlocks() {
final Map<String, (double, int)> aggregate = <String, (double, int)>{};
for (final TimedBlock block in timedBlocks) {
final (double, int) previousValue = aggregate.putIfAbsent(block.name, () => (0, 0));
aggregate[block.name] = (previousValue.$1 + block.duration, previousValue.$2 + 1);
}
return aggregate.entries.map<AggregatedTimedBlock>(
(MapEntry<String, (double, int)> entry) {
return AggregatedTimedBlock(name: entry.key, duration: entry.value.$1, count: entry.value.$2);
}
).toList();
}
/// Returns aggregated numbers for a named block of code.
///
/// If the block in question never executed since the last reset, returns an
/// aggregation with zero duration and count.
AggregatedTimedBlock getAggregated(String name) {
return aggregatedBlocks.singleWhere(
(AggregatedTimedBlock block) => block.name == name,
// Handle the case where there are no recorded blocks of the specified
// type. In this case, the aggregated duration is simply zero, and so is
// the number of occurrences (i.e. count).
orElse: () => AggregatedTimedBlock(name: name, duration: 0, count: 0),
);
}
}
/// Aggregates multiple [TimedBlock] objects that share a [name].
///
/// It is common for the same block of code to be executed multiple times within
/// a frame. It is useful to combine multiple executions and report the total
/// amount of time attributed to that block of code.
@immutable
final class AggregatedTimedBlock {
/// Creates a timed block of code from a [name] and [duration].
///
/// The [name] should be sufficiently unique and descriptive for someone to
/// easily tell which part of code was measured.
const AggregatedTimedBlock({
required this.name,
required this.duration,
required this.count,
}) : assert(duration >= 0);
/// A readable label for a block of code that was measured.
///
/// This field should be sufficiently unique and descriptive for someone to
/// easily tell which part of code was measured.
final String name;
/// The sum of [TimedBlock.duration] values of aggretaged blocks.
final double duration;
/// The number of [TimedBlock] objects aggregated.
final int count;
@override
String toString() {
return 'AggregatedTimedBlock($name, $duration, $count)';
}
}
const int _kSliceSize = 500;
/// A growable list of float64 values with predictable [add] performance.
///
/// The list is organized into a "chain" of [Float64List]s. The object starts
/// with a `Float64List` "slice". When [add] is called, the value is added to
/// the slice. Once the slice is full, it is moved into the chain, and a new
/// slice is allocated. Slice size is static and therefore its allocation has
/// predictable cost. This is unlike the default [List] implementation, which,
/// when full, doubles its buffer size and copies all old elements into the new
/// buffer, leading to unpredictable performance. This makes it a poor choice
/// for recording performance because buffer reallocation would affect the
/// runtime.
///
/// The trade-off is that reading values back from the chain is more expensive
/// compared to [List] because it requires iterating over multiple slices. This
/// is a reasonable trade-off for performance metrics, because it is more
/// important to minimize the overhead while recording metrics, than it is when
/// reading them.
final class _Float64ListChain {
_Float64ListChain();
final List<Float64List> _chain = <Float64List>[];
Float64List _slice = Float64List(_kSliceSize);
int _pointer = 0;
int get length => _length;
int _length = 0;
/// Adds and [element] to this chain.
void add(double element) {
_slice[_pointer] = element;
_pointer += 1;
_length += 1;
if (_pointer >= _kSliceSize) {
_chain.add(_slice);
_slice = Float64List(_kSliceSize);
_pointer = 0;
}
}
/// Returns all elements added to this chain.
///
/// This getter is not optimized to be fast. It is assumed that when metrics
/// are read back, they do not affect the timings of the work being
/// benchmarked.
List<double> extractElements() {
final List<double> result = <double>[];
_chain.forEach(result.addAll);
for (int i = 0; i < _pointer; i++) {
result.add(_slice[i]);
}
return result;
}
}
/// Same as [_Float64ListChain] but for recording string values.
final class _StringListChain {
_StringListChain();
final List<List<String?>> _chain = <List<String?>>[];
List<String?> _slice = List<String?>.filled(_kSliceSize, null);
int _pointer = 0;
int get length => _length;
int _length = 0;
/// Adds and [element] to this chain.
void add(String element) {
_slice[_pointer] = element;
_pointer += 1;
_length += 1;
if (_pointer >= _kSliceSize) {
_chain.add(_slice);
_slice = List<String?>.filled(_kSliceSize, null);
_pointer = 0;
}
}
/// Returns all elements added to this chain.
///
/// This getter is not optimized to be fast. It is assumed that when metrics
/// are read back, they do not affect the timings of the work being
/// benchmarked.
List<String> extractElements() {
final List<String> result = <String>[];
for (final List<String?> slice in _chain) {
for (final String? element in slice) {
result.add(element!);
}
}
for (int i = 0; i < _pointer; i++) {
result.add(_slice[i]!);
}
return result;
}
}
/// A buffer that records starts and ends of code blocks, and their names.
final class _BlockBuffer {
// Start-finish blocks can be nested. Track this nestedness by stacking the
// start timestamps. Finish timestamps will pop timings from the stack and
// add the (start, finish) tuple to the _block.
static const int _stackDepth = 1000;
static final Float64List _startStack = Float64List(_stackDepth);
static final List<String?> _nameStack = List<String?>.filled(_stackDepth, null);
static int _stackPointer = 0;
final _Float64ListChain _starts = _Float64ListChain();
final _Float64ListChain _finishes = _Float64ListChain();
final _StringListChain _names = _StringListChain();
List<TimedBlock> computeTimings() {
assert(
_stackPointer == 0,
'Invalid sequence of `startSync` and `finishSync`.\n'
'The operation stack was not empty. The following operations are still '
'waiting to be finished via the `finishSync` method:\n'
'${List<String>.generate(_stackPointer, (int i) => _nameStack[i]!).join(', ')}'
);
final List<TimedBlock> result = <TimedBlock>[];
final int length = _finishes.length;
final List<double> starts = _starts.extractElements();
final List<double> finishes = _finishes.extractElements();
final List<String> names = _names.extractElements();
assert(starts.length == length);
assert(finishes.length == length);
assert(names.length == length);
for (int i = 0; i < length; i++) {
result.add(TimedBlock(
start: starts[i],
end: finishes[i],
name: names[i],
));
}
return result;
}
void startSync(String name, { Map<String, Object?>? arguments, Flow? flow }) {
_startStack[_stackPointer] = impl.performanceTimestamp;
_nameStack[_stackPointer] = name;
_stackPointer += 1;
}
void finishSync() {
assert(
_stackPointer > 0,
'Invalid sequence of `startSync` and `finishSync`.\n'
'Attempted to finish timing a block of code, but there are no pending '
'`startSync` calls.'
);
final double finishTime = impl.performanceTimestamp;
final double startTime = _startStack[_stackPointer - 1];
final String name = _nameStack[_stackPointer - 1]!;
_stackPointer -= 1;
_starts.add(startTime);
_finishes.add(finishTime);
_names.add(name);
}
}

View File

@ -2,7 +2,6 @@
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
import 'dart:developer';
import 'dart:ui' as ui show SemanticsUpdate;
import 'package:flutter/foundation.dart';
@ -507,13 +506,13 @@ mixin RendererBinding on BindingBase, ServicesBinding, SchedulerBinding, Gesture
await super.performReassemble();
if (BindingBase.debugReassembleConfig?.widgetName == null) {
if (!kReleaseMode) {
Timeline.startSync('Preparing Hot Reload (layout)');
FlutterTimeline.startSync('Preparing Hot Reload (layout)');
}
try {
renderView.reassemble();
} finally {
if (!kReleaseMode) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
}
}

View File

@ -2,7 +2,6 @@
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
import 'dart:developer' show Timeline;
import 'dart:math' as math;
import 'dart:ui' as ui show lerpDouble;
@ -1396,7 +1395,7 @@ abstract class RenderBox extends RenderObject {
}());
if (!kReleaseMode) {
if (debugProfileLayoutsEnabled || _debugIntrinsicsDepth == 0) {
Timeline.startSync(
FlutterTimeline.startSync(
'$runtimeType intrinsics',
arguments: debugTimelineArguments,
);
@ -1411,7 +1410,7 @@ abstract class RenderBox extends RenderObject {
if (!kReleaseMode) {
_debugIntrinsicsDepth -= 1;
if (debugProfileLayoutsEnabled || _debugIntrinsicsDepth == 0) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
}
return result;
@ -1832,7 +1831,7 @@ abstract class RenderBox extends RenderObject {
}());
if (!kReleaseMode) {
if (debugProfileLayoutsEnabled || _debugIntrinsicsDepth == 0) {
Timeline.startSync(
FlutterTimeline.startSync(
'$runtimeType.getDryLayout',
arguments: debugTimelineArguments,
);
@ -1844,7 +1843,7 @@ abstract class RenderBox extends RenderObject {
if (!kReleaseMode) {
_debugIntrinsicsDepth -= 1;
if (debugProfileLayoutsEnabled || _debugIntrinsicsDepth == 0) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
}
return result;

View File

@ -2,7 +2,6 @@
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
import 'dart:developer';
import 'dart:ui' as ui show PictureRecorder;
import 'dart:ui';
@ -986,7 +985,7 @@ class PipelineOwner {
}
return true;
}());
Timeline.startSync(
FlutterTimeline.startSync(
'LAYOUT',
arguments: debugTimelineArguments,
);
@ -1035,7 +1034,7 @@ class PipelineOwner {
return true;
}());
if (!kReleaseMode) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
}
}
@ -1074,7 +1073,7 @@ class PipelineOwner {
/// [flushPaint].
void flushCompositingBits() {
if (!kReleaseMode) {
Timeline.startSync('UPDATING COMPOSITING BITS');
FlutterTimeline.startSync('UPDATING COMPOSITING BITS');
}
_nodesNeedingCompositingBitsUpdate.sort((RenderObject a, RenderObject b) => a.depth - b.depth);
for (final RenderObject node in _nodesNeedingCompositingBitsUpdate) {
@ -1088,7 +1087,7 @@ class PipelineOwner {
}
assert(_nodesNeedingCompositingBitsUpdate.isEmpty, 'Child PipelineOwners must not dirty nodes in their parent.');
if (!kReleaseMode) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
}
@ -1122,7 +1121,7 @@ class PipelineOwner {
}
return true;
}());
Timeline.startSync(
FlutterTimeline.startSync(
'PAINT',
arguments: debugTimelineArguments,
);
@ -1161,7 +1160,7 @@ class PipelineOwner {
return true;
}());
if (!kReleaseMode) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
}
}
@ -1250,7 +1249,7 @@ class PipelineOwner {
return;
}
if (!kReleaseMode) {
Timeline.startSync('SEMANTICS');
FlutterTimeline.startSync('SEMANTICS');
}
assert(_semanticsOwner != null);
assert(() {
@ -1277,7 +1276,7 @@ class PipelineOwner {
return true;
}());
if (!kReleaseMode) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
}
}
@ -2379,7 +2378,7 @@ abstract class RenderObject with DiagnosticableTreeMixin implements HitTestTarge
}
return true;
}());
Timeline.startSync(
FlutterTimeline.startSync(
'$runtimeType',
arguments: debugTimelineArguments,
);
@ -2443,7 +2442,7 @@ abstract class RenderObject with DiagnosticableTreeMixin implements HitTestTarge
}
if (!kReleaseMode && debugProfileLayoutsEnabled) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
return;
}
@ -2510,7 +2509,7 @@ abstract class RenderObject with DiagnosticableTreeMixin implements HitTestTarge
markNeedsPaint();
if (!kReleaseMode && debugProfileLayoutsEnabled) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
}
@ -3082,7 +3081,7 @@ abstract class RenderObject with DiagnosticableTreeMixin implements HitTestTarge
}
return true;
}());
Timeline.startSync(
FlutterTimeline.startSync(
'$runtimeType',
arguments: debugTimelineArguments,
);
@ -3166,7 +3165,7 @@ abstract class RenderObject with DiagnosticableTreeMixin implements HitTestTarge
return true;
}());
if (!kReleaseMode && debugProfilePaintsEnabled) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
}
@ -3528,14 +3527,24 @@ abstract class RenderObject with DiagnosticableTreeMixin implements HitTestTarge
// The subtree is probably being kept alive by a viewport but not laid out.
return;
}
if (!kReleaseMode) {
FlutterTimeline.startSync('Semantics.GetFragment');
}
final _SemanticsFragment fragment = _getSemanticsForParent(
mergeIntoParent: _semantics?.parent?.isPartOfNodeMerging ?? false,
blockUserActions: _semantics?.areUserActionsBlocked ?? false,
);
if (!kReleaseMode) {
FlutterTimeline.finishSync();
}
assert(fragment is _InterestingSemanticsFragment);
final _InterestingSemanticsFragment interestingFragment = fragment as _InterestingSemanticsFragment;
final List<SemanticsNode> result = <SemanticsNode>[];
final List<SemanticsNode> siblingNodes = <SemanticsNode>[];
if (!kReleaseMode) {
FlutterTimeline.startSync('Semantics.compileChildren');
}
interestingFragment.compileChildren(
parentSemanticsClipRect: _semantics?.parentSemanticsClipRect,
parentPaintClipRect: _semantics?.parentPaintClipRect,
@ -3543,6 +3552,9 @@ abstract class RenderObject with DiagnosticableTreeMixin implements HitTestTarge
result: result,
siblingNodes: siblingNodes,
);
if (!kReleaseMode) {
FlutterTimeline.finishSync();
}
// Result may contain sibling nodes that are irrelevant for this update.
assert(interestingFragment.config == null && result.any((SemanticsNode node) => node == _semantics));
}

View File

@ -2,7 +2,6 @@
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
import 'dart:developer';
import 'dart:io' show Platform;
import 'dart:ui' as ui show FlutterView, Scene, SceneBuilder, SemanticsUpdate;
@ -229,7 +228,7 @@ class RenderView extends RenderObject with RenderObjectWithChildMixin<RenderBox>
/// Actually causes the output of the rendering pipeline to appear on screen.
void compositeFrame() {
if (!kReleaseMode) {
Timeline.startSync('COMPOSITING');
FlutterTimeline.startSync('COMPOSITING');
}
try {
final ui.SceneBuilder builder = ui.SceneBuilder();
@ -247,7 +246,7 @@ class RenderView extends RenderObject with RenderObjectWithChildMixin<RenderBox>
}());
} finally {
if (!kReleaseMode) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
}
}

View File

@ -4,7 +4,6 @@
import 'dart:async';
import 'dart:collection';
import 'dart:developer';
import 'package:flutter/foundation.dart';
import 'package:flutter/rendering.dart';
@ -2700,7 +2699,7 @@ class BuildOwner {
}
return true;
}());
Timeline.startSync(
FlutterTimeline.startSync(
'BUILD',
arguments: debugTimelineArguments
);
@ -2771,7 +2770,7 @@ class BuildOwner {
}
return true;
}());
Timeline.startSync(
FlutterTimeline.startSync(
'${element.widget.runtimeType}',
arguments: debugTimelineArguments,
);
@ -2794,7 +2793,7 @@ class BuildOwner {
);
}
if (isTimelineTracked) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
index += 1;
if (dirtyCount < _dirtyElements.length || _dirtyElementsNeedsResorting!) {
@ -2832,7 +2831,7 @@ class BuildOwner {
_scheduledFlushDirtyElements = false;
_dirtyElementsNeedsResorting = null;
if (!kReleaseMode) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
assert(_debugBuilding);
assert(() {
@ -3044,7 +3043,7 @@ class BuildOwner {
@pragma('vm:notify-debugger-on-exception')
void finalizeTree() {
if (!kReleaseMode) {
Timeline.startSync('FINALIZE TREE');
FlutterTimeline.startSync('FINALIZE TREE');
}
try {
lockState(_inactiveElements._unmountAll); // this unregisters the GlobalKeys
@ -3140,7 +3139,7 @@ class BuildOwner {
_reportException(ErrorSummary('while finalizing the widget tree'), e, stack);
} finally {
if (!kReleaseMode) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
}
}
@ -3153,7 +3152,7 @@ class BuildOwner {
/// This is expensive and should not be called except during development.
void reassemble(Element root, DebugReassembleConfig? reassembleConfig) {
if (!kReleaseMode) {
Timeline.startSync('Preparing Hot Reload (widgets)');
FlutterTimeline.startSync('Preparing Hot Reload (widgets)');
}
try {
assert(root._parent == null);
@ -3162,7 +3161,7 @@ class BuildOwner {
root.reassemble();
} finally {
if (!kReleaseMode) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
}
}
@ -3678,14 +3677,14 @@ abstract class Element extends DiagnosticableTree implements BuildContext {
}
return true;
}());
Timeline.startSync(
FlutterTimeline.startSync(
'${newWidget.runtimeType}',
arguments: debugTimelineArguments,
);
}
child.update(newWidget);
if (isTimelineTracked) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
assert(child.widget == newWidget);
assert(() {
@ -4153,7 +4152,7 @@ abstract class Element extends DiagnosticableTree implements BuildContext {
}
return true;
}());
Timeline.startSync(
FlutterTimeline.startSync(
'${newWidget.runtimeType}',
arguments: debugTimelineArguments,
);
@ -4186,7 +4185,7 @@ abstract class Element extends DiagnosticableTree implements BuildContext {
return newChild;
} finally {
if (isTimelineTracked) {
Timeline.finishSync();
FlutterTimeline.finishSync();
}
}
}

View File

@ -0,0 +1,143 @@
// 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 'package:flutter/foundation.dart';
import 'package:flutter_test/flutter_test.dart';
// IMPORTANT: keep this in sync with the same constant defined
// in foundation/timeline.dart
const int kSliceSize = 500;
void main() {
setUp(() {
FlutterTimeline.debugReset();
FlutterTimeline.debugCollectionEnabled = false;
});
test('Does not collect when collection not enabled', () {
FlutterTimeline.startSync('TEST');
FlutterTimeline.finishSync();
expect(
() => FlutterTimeline.debugCollect(),
throwsStateError,
);
});
test('Collects when collection is enabled', () {
FlutterTimeline.debugCollectionEnabled = true;
FlutterTimeline.startSync('TEST');
FlutterTimeline.finishSync();
final AggregatedTimings data = FlutterTimeline.debugCollect();
expect(data.timedBlocks, hasLength(1));
expect(data.aggregatedBlocks, hasLength(1));
final AggregatedTimedBlock block = data.getAggregated('TEST');
expect(block.name, 'TEST');
expect(block.count, 1);
// After collection the timeline is reset back to empty.
final AggregatedTimings data2 = FlutterTimeline.debugCollect();
expect(data2.timedBlocks, isEmpty);
expect(data2.aggregatedBlocks, isEmpty);
});
test('Deletes old data when reset', () {
FlutterTimeline.debugCollectionEnabled = true;
FlutterTimeline.startSync('TEST');
FlutterTimeline.finishSync();
FlutterTimeline.debugReset();
final AggregatedTimings data = FlutterTimeline.debugCollect();
expect(data.timedBlocks, isEmpty);
expect(data.aggregatedBlocks, isEmpty);
});
test('Reports zero aggregation when requested missing block', () {
FlutterTimeline.debugCollectionEnabled = true;
final AggregatedTimings data = FlutterTimeline.debugCollect();
final AggregatedTimedBlock block = data.getAggregated('MISSING');
expect(block.name, 'MISSING');
expect(block.count, 0);
expect(block.duration, 0);
});
test('Measures the runtime of a function', () {
FlutterTimeline.debugCollectionEnabled = true;
// The off-by-one values for `start` and `end` are for web's sake where
// timer values are reported as float64 and toInt/toDouble conversions
// are noops, so there's no value truncation happening, which makes it
// a bit inconsistent with Stopwatch.
final int start = FlutterTimeline.now - 1;
FlutterTimeline.timeSync('TEST', () {
final Stopwatch watch = Stopwatch()..start();
while (watch.elapsedMilliseconds < 5) {}
watch.stop();
});
final int end = FlutterTimeline.now + 1;
final AggregatedTimings data = FlutterTimeline.debugCollect();
expect(data.timedBlocks, hasLength(1));
expect(data.aggregatedBlocks, hasLength(1));
final TimedBlock block = data.timedBlocks.single;
expect(block.name, 'TEST');
expect(block.start, greaterThanOrEqualTo(start));
expect(block.end, lessThanOrEqualTo(end));
expect(block.duration, greaterThan(0));
final AggregatedTimedBlock aggregated = data.getAggregated('TEST');
expect(aggregated.name, 'TEST');
expect(aggregated.count, 1);
expect(aggregated.duration, block.duration);
});
test('FlutterTimeline.instanceSync does not collect anything', () {
FlutterTimeline.debugCollectionEnabled = true;
FlutterTimeline.instantSync('TEST');
final AggregatedTimings data = FlutterTimeline.debugCollect();
expect(data.timedBlocks, isEmpty);
expect(data.aggregatedBlocks, isEmpty);
});
test('FlutterTimeline.now returns a value', () {
FlutterTimeline.debugCollectionEnabled = true;
expect(FlutterTimeline.now, isNotNull);
});
test('Can collect more than one slice of data', () {
FlutterTimeline.debugCollectionEnabled = true;
for (int i = 0; i < 10 * kSliceSize; i++) {
FlutterTimeline.startSync('TEST');
FlutterTimeline.finishSync();
}
final AggregatedTimings data = FlutterTimeline.debugCollect();
expect(data.timedBlocks, hasLength(10 * kSliceSize));
expect(data.aggregatedBlocks, hasLength(1));
final AggregatedTimedBlock block = data.getAggregated('TEST');
expect(block.name, 'TEST');
expect(block.count, 10 * kSliceSize);
});
test('Collects blocks in a correct order', () {
FlutterTimeline.debugCollectionEnabled = true;
const int testCount = 7 * kSliceSize ~/ 2;
for (int i = 0; i < testCount; i++) {
FlutterTimeline.startSync('TEST$i');
FlutterTimeline.finishSync();
}
final AggregatedTimings data = FlutterTimeline.debugCollect();
expect(data.timedBlocks, hasLength(testCount));
expect(
data.timedBlocks.map<String>((TimedBlock block) => block.name).toList(),
List<String>.generate(testCount, (int i) => 'TEST$i'),
);
});
}