From 3068fc4f7c78599ab4a09b096f0672e8510fc7e6 Mon Sep 17 00:00:00 2001 From: Jonah Williams Date: Fri, 26 Jul 2019 13:08:36 -0700 Subject: [PATCH] Revert "Fix the first frame logic in tracing and driver (#35297)" (#37027) This reverts commit 68fc7231b33dcb3f7c9e705e321135f009afda49. --- .../test_driver/scroll_perf_test.dart | 3 -- dev/devicelab/lib/tasks/perf_tests.dart | 1 - dev/devicelab/manifest.yaml | 9 ----- .../test_driver/scroll_perf_test.dart | 3 -- .../test_driver/transitions_perf_test.dart | 4 +-- packages/flutter/lib/src/widgets/binding.dart | 33 +++---------------- .../foundation/service_extensions_test.dart | 2 -- .../flutter_driver/lib/src/common/find.dart | 20 ----------- .../flutter_driver/lib/src/driver/driver.dart | 8 ----- .../lib/src/extension/extension.dart | 8 ----- packages/flutter_tools/lib/src/tracing.dart | 26 +++++---------- 11 files changed, 14 insertions(+), 103 deletions(-) diff --git a/dev/benchmarks/complex_layout/test_driver/scroll_perf_test.dart b/dev/benchmarks/complex_layout/test_driver/scroll_perf_test.dart index e26ae3476d0..c85fbd3318f 100644 --- a/dev/benchmarks/complex_layout/test_driver/scroll_perf_test.dart +++ b/dev/benchmarks/complex_layout/test_driver/scroll_perf_test.dart @@ -13,9 +13,6 @@ void main() { setUpAll(() async { driver = await FlutterDriver.connect(); - - // TODO(liyuqian): enable the following once it's proved to be non-flaky by transition_perf_test.dart. - // await driver.waitUntilFirstFrameRasterized(); }); tearDownAll(() async { diff --git a/dev/devicelab/lib/tasks/perf_tests.dart b/dev/devicelab/lib/tasks/perf_tests.dart index 41ac4278522..2dbcc2ed64b 100644 --- a/dev/devicelab/lib/tasks/perf_tests.dart +++ b/dev/devicelab/lib/tasks/perf_tests.dart @@ -159,7 +159,6 @@ class StartupTest { return TaskResult.success(data, benchmarkScoreKeys: [ 'timeToFirstFrameMicros', - 'timeToFirstFrameRasterizedMicros', ]); }); } diff --git a/dev/devicelab/manifest.yaml b/dev/devicelab/manifest.yaml index 51693d74a1e..c394cf1883f 100644 --- a/dev/devicelab/manifest.yaml +++ b/dev/devicelab/manifest.yaml @@ -251,7 +251,6 @@ tasks: description: > Measures the startup time of the Complex Layout sample app on Android. stage: devicelab - flaky: true required_agent_capabilities: ["mac/android"] hot_mode_dev_cycle__benchmark: @@ -449,14 +448,12 @@ tasks: description: > Measures the startup time of the Flutter Gallery app on iPhone 6. stage: devicelab_ios - flaky: true required_agent_capabilities: ["mac/ios"] complex_layout_ios__start_up: description: > Measures the startup time of the Complex Layout sample app on iPhone 6. stage: devicelab_ios - flaky: true required_agent_capabilities: ["mac/ios"] flutter_gallery_ios__transition_perf: @@ -464,7 +461,6 @@ tasks: Measures the performance of screen transitions in Flutter Gallery on iOS. stage: devicelab_ios - flaky: true required_agent_capabilities: ["mac/ios"] hello_world_ios__compile: @@ -569,7 +565,6 @@ tasks: description: > Measures the startup time of the Flutter Gallery app on Android. stage: devicelab - flaky: true required_agent_capabilities: ["linux/android"] flutter_gallery__transition_perf: @@ -577,7 +572,6 @@ tasks: Measures the performance of screen transitions in Flutter Gallery on Android. stage: devicelab - flaky: true required_agent_capabilities: ["linux/android"] flutter_gallery__transition_perf_with_semantics: @@ -585,7 +579,6 @@ tasks: Measures the delta in performance of screen transitions without and with semantics enabled. stage: devicelab - flaky: true required_agent_capabilities: ["linux/android"] flutter_gallery__memory_nav: @@ -624,7 +617,6 @@ tasks: description: > Measures the startup time of the Flutter Gallery app on 32-bit iOS (iPhone 4S). stage: devicelab_ios - flaky: true required_agent_capabilities: ["mac/ios32"] flutter_gallery_ios32__transition_perf: @@ -632,7 +624,6 @@ tasks: Measures the performance of screen transitions in Flutter Gallery on 32-bit iOS (iPhone 4S). stage: devicelab_ios - flaky: true required_agent_capabilities: ["mac/ios32"] run_without_leak_mac: diff --git a/examples/flutter_gallery/test_driver/scroll_perf_test.dart b/examples/flutter_gallery/test_driver/scroll_perf_test.dart index e2a43027ad1..0f1f2cb00b5 100644 --- a/examples/flutter_gallery/test_driver/scroll_perf_test.dart +++ b/examples/flutter_gallery/test_driver/scroll_perf_test.dart @@ -13,9 +13,6 @@ void main() { setUpAll(() async { driver = await FlutterDriver.connect(); - - // TODO(liyuqian): enable the following once it's proved to be non-flaky by transition_perf_test.dart. - // await driver.waitUntilFirstFrameRasterized(); }); tearDownAll(() async { diff --git a/examples/flutter_gallery/test_driver/transitions_perf_test.dart b/examples/flutter_gallery/test_driver/transitions_perf_test.dart index b67383c3ca7..c8fcd7e862f 100644 --- a/examples/flutter_gallery/test_driver/transitions_perf_test.dart +++ b/examples/flutter_gallery/test_driver/transitions_perf_test.dart @@ -183,9 +183,6 @@ void main([List args = const []]) { setUpAll(() async { driver = await FlutterDriver.connect(); - // Wait for the first frame to be rasterized. - await driver.waitUntilFirstFrameRasterized(); - if (args.contains('--with_semantics')) { print('Enabeling semantics...'); await driver.setSemantics(true); @@ -203,6 +200,7 @@ void main([List args = const []]) { }); test('all demos', () async { + // Collect timeline data for just a limited set of demos to avoid OOMs. final Timeline timeline = await driver.traceAction( () async { diff --git a/packages/flutter/lib/src/widgets/binding.dart b/packages/flutter/lib/src/widgets/binding.dart index 908e65b2c79..66d376ce446 100644 --- a/packages/flutter/lib/src/widgets/binding.dart +++ b/packages/flutter/lib/src/widgets/binding.dart @@ -4,7 +4,7 @@ import 'dart:async'; import 'dart:developer' as developer; -import 'dart:ui' show AppLifecycleState, Locale, AccessibilityFeatures, FrameTiming, TimingsCallback; +import 'dart:ui' show AppLifecycleState, Locale, AccessibilityFeatures; import 'package:flutter/foundation.dart'; import 'package:flutter/gestures.dart'; @@ -550,14 +550,6 @@ mixin WidgetsBinding on BindingBase, SchedulerBinding, GestureBinding, RendererB int _deferFirstFrameReportCount = 0; bool get _reportFirstFrame => _deferFirstFrameReportCount == 0; - - final Completer _firstFrameCompleter = Completer(); - - /// Whether the Flutter engine has rasterized the first frame. - /// - /// {@macro flutter.frame_rasterized_vs_presented} - Future get firstFrameRasterized => _firstFrameCompleter.future; - /// Whether the first frame has finished rendering. /// /// Only useful in profile and debug builds; in release builds, this always @@ -704,24 +696,6 @@ mixin WidgetsBinding on BindingBase, SchedulerBinding, GestureBinding, RendererB debugBuildingDirtyElements = true; return true; }()); - - if (_needToReportFirstFrame && _reportFirstFrame) { - assert(!_firstFrameCompleter.isCompleted); - // TODO(liyuqian): use a broadcast stream approach - final TimingsCallback oldCallback = WidgetsBinding.instance.window.onReportTimings; - WidgetsBinding.instance.window.onReportTimings = (List timings) { - if (!kReleaseMode) { - developer.Timeline.instantSync('Rasterized first useful frame'); - developer.postEvent('Flutter.FirstFrame', {}); - } - if (oldCallback != null) { - oldCallback(timings); - } - WidgetsBinding.instance.window.onReportTimings = oldCallback; - _firstFrameCompleter.complete(); - }; - } - try { if (renderViewElement != null) buildOwner.buildScope(renderViewElement); @@ -735,10 +709,11 @@ mixin WidgetsBinding on BindingBase, SchedulerBinding, GestureBinding, RendererB } if (!kReleaseMode) { if (_needToReportFirstFrame && _reportFirstFrame) { - developer.Timeline.instantSync('Widgets built first useful frame'); + developer.Timeline.instantSync('Widgets completed first useful frame'); + developer.postEvent('Flutter.FirstFrame', {}); + _needToReportFirstFrame = false; } } - _needToReportFirstFrame = false; } /// The [Element] that is at the root of the hierarchy (and which wraps the diff --git a/packages/flutter/test/foundation/service_extensions_test.dart b/packages/flutter/test/foundation/service_extensions_test.dart index 3038dc933d4..2150da2c2c8 100644 --- a/packages/flutter/test/foundation/service_extensions_test.dart +++ b/packages/flutter/test/foundation/service_extensions_test.dart @@ -79,8 +79,6 @@ class TestServiceExtensionsBinding extends BindingBase await flushMicrotasks(); if (ui.window.onDrawFrame != null) ui.window.onDrawFrame(); - if (ui.window.onReportTimings != null) - ui.window.onReportTimings([]); } @override diff --git a/packages/flutter_driver/lib/src/common/find.dart b/packages/flutter_driver/lib/src/common/find.dart index 7fd3ad97d9a..c9b40455c9b 100644 --- a/packages/flutter_driver/lib/src/common/find.dart +++ b/packages/flutter_driver/lib/src/common/find.dart @@ -132,26 +132,6 @@ class WaitUntilNoPendingFrame extends Command { String get kind => 'waitUntilNoPendingFrame'; } -/// A Flutter Driver command that waits until the Flutter engine rasterizes the -/// first frame. -/// -/// {@template flutter.frame_rasterized_vs_presented} -/// Usually, the time that a frame is rasterized is very close to the time that -/// it gets presented on the display. Specifically, rasterization is the last -/// expensive phase of a frame that's still in Flutter's control. -/// {@endtemplate} -class WaitUntilFirstFrameRasterized extends Command { - /// Creates this command. - const WaitUntilFirstFrameRasterized({ Duration timeout }) : super(timeout: timeout); - - /// Deserializes this command from the value generated by [serialize]. - WaitUntilFirstFrameRasterized.deserialize(Map json) - : super.deserialize(json); - - @override - String get kind => 'waitUntilFirstFrameRasterized'; -} - /// Base class for Flutter Driver finders, objects that describe how the driver /// should search for elements. abstract class SerializableFinder { diff --git a/packages/flutter_driver/lib/src/driver/driver.dart b/packages/flutter_driver/lib/src/driver/driver.dart index 5d7eec8dba8..01f0f8ff0a9 100644 --- a/packages/flutter_driver/lib/src/driver/driver.dart +++ b/packages/flutter_driver/lib/src/driver/driver.dart @@ -499,14 +499,6 @@ class FlutterDriver { await _sendCommand(WaitUntilNoTransientCallbacks(timeout: timeout)); } - /// Waits until the next [Window.onReportTimings] is called. - /// - /// Use this method to wait for the first frame to be rasterized during the - /// app launch. - Future waitUntilFirstFrameRasterized() async { - await _sendCommand(const WaitUntilFirstFrameRasterized()); - } - Future _getOffset(SerializableFinder finder, OffsetType type, { Duration timeout }) async { final GetOffset command = GetOffset(finder, type, timeout: timeout); final GetOffsetResult result = GetOffsetResult.fromJson(await _sendCommand(command)); diff --git a/packages/flutter_driver/lib/src/extension/extension.dart b/packages/flutter_driver/lib/src/extension/extension.dart index d46ffc5f3c4..397f9003edd 100644 --- a/packages/flutter_driver/lib/src/extension/extension.dart +++ b/packages/flutter_driver/lib/src/extension/extension.dart @@ -114,7 +114,6 @@ class FlutterDriverExtension { 'waitForAbsent': _waitForAbsent, 'waitUntilNoTransientCallbacks': _waitUntilNoTransientCallbacks, 'waitUntilNoPendingFrame': _waitUntilNoPendingFrame, - 'waitUntilFirstFrameRasterized': _waitUntilFirstFrameRasterized, 'get_semantics_id': _getSemanticsId, 'get_offset': _getOffset, 'get_diagnostics_tree': _getDiagnosticsTree, @@ -136,7 +135,6 @@ class FlutterDriverExtension { 'waitForAbsent': (Map params) => WaitForAbsent.deserialize(params), 'waitUntilNoTransientCallbacks': (Map params) => WaitUntilNoTransientCallbacks.deserialize(params), 'waitUntilNoPendingFrame': (Map params) => WaitUntilNoPendingFrame.deserialize(params), - 'waitUntilFirstFrameRasterized': (Map params) => WaitUntilFirstFrameRasterized.deserialize(params), 'get_semantics_id': (Map params) => GetSemanticsId.deserialize(params), 'get_offset': (Map params) => GetOffset.deserialize(params), 'get_diagnostics_tree': (Map params) => GetDiagnosticsTree.deserialize(params), @@ -222,12 +220,6 @@ class FlutterDriverExtension { return RenderTree(RendererBinding.instance?.renderView?.toStringDeep()); } - // This can be used to wait for the first frame being rasterized during app launch. - Future _waitUntilFirstFrameRasterized(Command command) async { - await WidgetsBinding.instance.firstFrameRasterized; - return null; - } - // Waits until at the end of a frame the provided [condition] is [true]. Future _waitUntilFrame(bool condition(), [ Completer completer ]) { completer ??= Completer(); diff --git a/packages/flutter_tools/lib/src/tracing.dart b/packages/flutter_tools/lib/src/tracing.dart index aad12e41a04..0a666d80084 100644 --- a/packages/flutter_tools/lib/src/tracing.dart +++ b/packages/flutter_tools/lib/src/tracing.dart @@ -14,13 +14,12 @@ import 'vmservice.dart'; // Names of some of the Timeline events we care about. const String _kFlutterEngineMainEnterEventName = 'FlutterEngineMainEnter'; const String _kFrameworkInitEventName = 'Framework initialization'; -const String _kFirstFrameBuiltEventName = 'Widgets built first useful frame'; -const String _kFirstFrameRasterizedEventName = 'Rasterized first useful frame'; +const String _kFirstUsefulFrameEventName = 'Widgets completed first useful frame'; class Tracing { Tracing(this.vmService); - static const String firstUsefulFrameEventName = _kFirstFrameRasterizedEventName; + static const String firstUsefulFrameEventName = _kFirstUsefulFrameEventName; static Future connect(Uri uri) async { final VMService observatory = await VMService.connect(uri); @@ -48,7 +47,7 @@ class Tracing { (await vmService.onTimelineEvent).listen((ServiceEvent timelineEvent) { final List> events = timelineEvent.timelineEvents; for (Map event in events) { - if (event['name'] == firstUsefulFrameEventName) + if (event['name'] == _kFirstUsefulFrameEventName) whenFirstFrameRendered.complete(); } }); @@ -123,23 +122,16 @@ Future downloadStartupTrace(VMService observatory, { bool awaitFirstFrame } if (awaitFirstFrame) { - final int firstFrameBuiltTimestampMicros = extractInstantEventTimestamp(_kFirstFrameBuiltEventName); - final int firstFrameRasterizedTimestampMicros = extractInstantEventTimestamp(_kFirstFrameRasterizedEventName); - if (firstFrameBuiltTimestampMicros == null || firstFrameRasterizedTimestampMicros == null) { - printTrace('First frame events are missing in the timeline: $timeline'); - throw 'First frame events are missing in the timeline. Cannot compute startup time.'; + final int firstFrameTimestampMicros = extractInstantEventTimestamp(_kFirstUsefulFrameEventName); + if (firstFrameTimestampMicros == null) { + printTrace('First frame event is missing in the timeline: $timeline'); + throw 'First frame event is missing in the timeline. Cannot compute startup time.'; } - - // To keep our old benchmarks valid, we'll preserve the - // timeToFirstFrameMicros as the firstFrameBuiltTimestampMicros. - // Additionally, we add timeToFirstFrameRasterizedMicros for a more accurate - // benchmark. - traceInfo['timeToFirstFrameRasterizedMicros'] = firstFrameRasterizedTimestampMicros - engineEnterTimestampMicros; - final int timeToFirstFrameMicros = firstFrameBuiltTimestampMicros - engineEnterTimestampMicros; + final int timeToFirstFrameMicros = firstFrameTimestampMicros - engineEnterTimestampMicros; traceInfo['timeToFirstFrameMicros'] = timeToFirstFrameMicros; message = 'Time to first frame: ${timeToFirstFrameMicros ~/ 1000}ms.'; if (frameworkInitTimestampMicros != null) - traceInfo['timeAfterFrameworkInitMicros'] = firstFrameBuiltTimestampMicros - frameworkInitTimestampMicros; + traceInfo['timeAfterFrameworkInitMicros'] = firstFrameTimestampMicros - frameworkInitTimestampMicros; } traceInfoFile.writeAsStringSync(toPrettyJson(traceInfo));