From 3d58400e76845dc6b95d97d75e6ebdc1d9edf9bc Mon Sep 17 00:00:00 2001 From: Dan Field Date: Sat, 15 Jun 2019 00:01:35 -0700 Subject: [PATCH] Revert "Revert "redux of a change to use new engine APIs for Flutter.Frame events (#34365)" (#34514)" (#34530) This reverts commit 8f75d53735bcfc2b988e84f50e3b4e43dbbd1c7f. --- .../bin/tasks/service_extensions_test.dart | 28 +++++++++---- .../flutter/lib/src/scheduler/binding.dart | 42 ++++++++++--------- .../test/scheduler/scheduler_test.dart | 36 +++++++++++++++- 3 files changed, 77 insertions(+), 29 deletions(-) diff --git a/dev/devicelab/bin/tasks/service_extensions_test.dart b/dev/devicelab/bin/tasks/service_extensions_test.dart index ad44964fb2..bd8262f05c 100644 --- a/dev/devicelab/bin/tasks/service_extensions_test.dart +++ b/dev/devicelab/bin/tasks/service_extensions_test.dart @@ -6,12 +6,11 @@ import 'dart:async'; import 'dart:convert'; import 'dart:io'; -import 'package:path/path.dart' as path; -import 'package:vm_service_client/vm_service_client.dart'; - import 'package:flutter_devicelab/framework/adb.dart'; import 'package:flutter_devicelab/framework/framework.dart'; import 'package:flutter_devicelab/framework/utils.dart'; +import 'package:path/path.dart' as path; +import 'package:vm_service_client/vm_service_client.dart'; void main() { task(() async { @@ -57,10 +56,19 @@ void main() { final VMServiceClient client = VMServiceClient.connect('ws://localhost:$vmServicePort/ws'); final VM vm = await client.getVM(); final VMIsolateRef isolate = vm.isolates.first; - final Stream frameEvents = isolate.onExtensionEvent.where( - (VMExtensionEvent e) => e.kind == 'Flutter.Frame'); - final Stream navigationEvents = isolate.onExtensionEvent.where( - (VMExtensionEvent e) => e.kind == 'Flutter.Navigation'); + + final StreamController frameEventsController = StreamController(); + final StreamController navigationEventsController = StreamController(); + isolate.onExtensionEvent.listen((VMExtensionEvent event) { + if (event.kind == 'Flutter.Frame') { + frameEventsController.add(event); + } else if (event.kind == 'Flutter.Navigation') { + navigationEventsController.add(event); + } + }); + + final Stream frameEvents = frameEventsController.stream; + final Stream navigationEvents = navigationEventsController.stream; print('reassembling app...'); final Future frameFuture = frameEvents.first; @@ -71,13 +79,17 @@ void main() { print('${event.kind}: ${event.data}'); // validate the fields - // {number: 8, startTime: 0, elapsed: 1437} + // {number: 8, startTime: 0, elapsed: 1437, build: 600, raster: 800} expect(event.data['number'] is int); expect(event.data['number'] >= 0); expect(event.data['startTime'] is int); expect(event.data['startTime'] >= 0); expect(event.data['elapsed'] is int); expect(event.data['elapsed'] >= 0); + expect(event.data['build'] is int); + expect(event.data['build'] >= 0); + expect(event.data['raster'] is int); + expect(event.data['raster'] >= 0); final Future navigationFuture = navigationEvents.first; // This tap triggers a navigation event. diff --git a/packages/flutter/lib/src/scheduler/binding.dart b/packages/flutter/lib/src/scheduler/binding.dart index a5793a7cd5..50cd635f90 100644 --- a/packages/flutter/lib/src/scheduler/binding.dart +++ b/packages/flutter/lib/src/scheduler/binding.dart @@ -4,8 +4,8 @@ import 'dart:async'; import 'dart:collection'; -import 'dart:developer'; -import 'dart:ui' show AppLifecycleState; +import 'dart:developer' show Flow, Timeline; +import 'dart:ui' show AppLifecycleState, FramePhase, FrameTiming; import 'package:collection/collection.dart' show PriorityQueue, HeapPriorityQueue; import 'package:flutter/foundation.dart'; @@ -198,6 +198,17 @@ mixin SchedulerBinding on BindingBase, ServicesBinding { window.onDrawFrame = _handleDrawFrame; SystemChannels.lifecycle.setMessageHandler(_handleLifecycleMessage); readInitialLifecycleStateFromNativeWindow(); + + if (!kReleaseMode) { + int frameNumber = 0; + + window.onReportTimings = (List timings) { + for (FrameTiming frameTiming in timings) { + frameNumber += 1; + _profileFramePostEvent(frameNumber, frameTiming); + } + }; + } } /// The current [SchedulerBinding], if one has been created. @@ -842,8 +853,7 @@ mixin SchedulerBinding on BindingBase, ServicesBinding { } Duration _currentFrameTimeStamp; - int _profileFrameNumber = 0; - final Stopwatch _profileFrameStopwatch = Stopwatch(); + int _debugFrameNumber = 0; String _debugBanner; bool _ignoreNextEngineDrawFrame = false; @@ -894,13 +904,9 @@ mixin SchedulerBinding on BindingBase, ServicesBinding { if (rawTimeStamp != null) _lastRawTimeStamp = rawTimeStamp; - if (!kReleaseMode) { - _profileFrameNumber += 1; - _profileFrameStopwatch.reset(); - _profileFrameStopwatch.start(); - } - assert(() { + _debugFrameNumber += 1; + if (debugPrintBeginFrameBanner || debugPrintEndFrameBanner) { final StringBuffer frameTimeStampDescription = StringBuffer(); if (rawTimeStamp != null) { @@ -908,7 +914,7 @@ mixin SchedulerBinding on BindingBase, ServicesBinding { } else { frameTimeStampDescription.write('(warm-up frame)'); } - _debugBanner = '▄▄▄▄▄▄▄▄ Frame ${_profileFrameNumber.toString().padRight(7)} ${frameTimeStampDescription.toString().padLeft(18)} ▄▄▄▄▄▄▄▄'; + _debugBanner = '▄▄▄▄▄▄▄▄ Frame ${_debugFrameNumber.toString().padRight(7)} ${frameTimeStampDescription.toString().padLeft(18)} ▄▄▄▄▄▄▄▄'; if (debugPrintBeginFrameBanner) debugPrint(_debugBanner); } @@ -961,10 +967,6 @@ mixin SchedulerBinding on BindingBase, ServicesBinding { } finally { _schedulerPhase = SchedulerPhase.idle; Timeline.finishSync(); // end the Frame - if (!kReleaseMode) { - _profileFrameStopwatch.stop(); - _profileFramePostEvent(); - } assert(() { if (debugPrintEndFrameBanner) debugPrint('▀' * _debugBanner.length); @@ -975,11 +977,13 @@ mixin SchedulerBinding on BindingBase, ServicesBinding { } } - void _profileFramePostEvent() { + void _profileFramePostEvent(int frameNumber, FrameTiming frameTiming) { postEvent('Flutter.Frame', { - 'number': _profileFrameNumber, - 'startTime': _currentFrameTimeStamp.inMicroseconds, - 'elapsed': _profileFrameStopwatch.elapsedMicroseconds, + 'number': frameNumber, + 'startTime': frameTiming.timestampInMicroseconds(FramePhase.buildStart), + 'elapsed': frameTiming.totalSpan.inMicroseconds, + 'build': frameTiming.buildDuration.inMicroseconds, + 'raster': frameTiming.rasterDuration.inMicroseconds, }); } diff --git a/packages/flutter/test/scheduler/scheduler_test.dart b/packages/flutter/test/scheduler/scheduler_test.dart index debeaf2021..5eaa0fc6eb 100644 --- a/packages/flutter/test/scheduler/scheduler_test.dart +++ b/packages/flutter/test/scheduler/scheduler_test.dart @@ -3,6 +3,7 @@ // found in the LICENSE file. import 'dart:async'; +import 'dart:ui' show window, FrameTiming; import 'package:flutter/foundation.dart'; import 'package:flutter/scheduler.dart'; @@ -10,7 +11,18 @@ import 'package:flutter/services.dart'; import '../flutter_test_alternative.dart'; -class TestSchedulerBinding extends BindingBase with ServicesBinding, SchedulerBinding { } +class TestSchedulerBinding extends BindingBase with ServicesBinding, SchedulerBinding { + final Map>> eventsDispatched = >>{}; + + @override + void postEvent(String eventKind, Map eventData) { + getEventsDispatched(eventKind).add(eventData); + } + + List> getEventsDispatched(String eventKind) { + return eventsDispatched.putIfAbsent(eventKind, () => >[]); + } +} class TestStrategy { int allowedPriority = 10000; @@ -21,7 +33,8 @@ class TestStrategy { } void main() { - SchedulerBinding scheduler; + TestSchedulerBinding scheduler; + setUpAll(() { scheduler = TestSchedulerBinding(); }); @@ -116,4 +129,23 @@ void main() { expect(timerQueueTasks.length, 2); expect(taskExecuted, false); }); + + test('Flutter.Frame event fired', () async { + window.onReportTimings([FrameTiming([ + // build start, build finish + 10000, 15000, + // raster start, raster finish + 16000, 20000, + ])]); + + final List> events = scheduler.getEventsDispatched('Flutter.Frame'); + expect(events, hasLength(1)); + + final Map event = events.first; + expect(event['number'], isNonNegative); + expect(event['startTime'], 10000); + expect(event['elapsed'], 10000); + expect(event['build'], 5000); + expect(event['raster'], 4000); + }); }