More frame events (#11747)

* Revert "Revert "fire service protocol events for frames (#11565)" (#11727)"

This reverts commit f25e2f52.

* move the postEvent() call into a separate method

dev/devicelab/bin/tasks/commands_test.dart

@@ -13,9 +13,6 @@ import 'package:flutter_devicelab/framework/adb.dart';
 import 'package:flutter_devicelab/framework/framework.dart';
 import 'package:flutter_devicelab/framework/utils.dart';
 
-// "An Observatory debugger and profiler on iPhone SE is available at: http://127.0.0.1:8100/"
-final RegExp observatoryRegExp = new RegExp(r'An Observatory debugger .* is available at: (\S+:(\d+))');
-
 void main() {
   task(() async {
     int vmServicePort;
@@ -38,10 +35,9 @@ void main() {
         .listen((String line) {
           print('run:stdout: $line');
           stdout.add(line);
-          if (line.contains(observatoryRegExp)) {
-            final Match match = observatoryRegExp.firstMatch(line);
-            vmServicePort = int.parse(match.group(2));
-            print('service protocol connection available at ${match.group(1)}');
+          if (lineContainsServicePort(line)) {
+            vmServicePort = parseServicePort(line);
+            print('service protocol connection available at port $vmServicePort');
             print('run: ready!');
             ready.complete();
             ok ??= true;

dev/devicelab/bin/tasks/routing_test.dart

@@ -14,6 +14,8 @@ import 'package:flutter_devicelab/framework/utils.dart';
 
 void main() {
   task(() async {
+    int vmServicePort;
+
     final Device device = await devices.workingDevice;
     await device.unlock();
     final Directory appDir = dir(path.join(flutterDirectory.path, 'dev/integration_tests/ui'));
@@ -30,18 +32,18 @@ void main() {
       final Completer<Null> ready = new Completer<Null>();
       bool ok;
       print('run: starting...');
-      // TODO(devoncarew): Instead of passing in a specific port, we should let the app
-      // bind to a free port and detect which port was chosen; see commands_test.dart.
       final Process run = await startProcess(
         path.join(flutterDirectory.path, 'bin', 'flutter'),
-        <String>['run', '--verbose', '--observatory-port=8888', '-d', device.deviceId, '--route', '/smuggle-it', 'lib/route.dart'],
+        <String>['run', '--verbose', '-d', device.deviceId, '--route', '/smuggle-it', 'lib/route.dart'],
       );
       run.stdout
         .transform(UTF8.decoder)
         .transform(const LineSplitter())
         .listen((String line) {
           print('run:stdout: $line');
-          if (line.contains(new RegExp(r'^\[\s+\] For a more detailed help message, press "h"\. To quit, press "q"\.'))) {
+          if (lineContainsServicePort(line)) {
+            vmServicePort = parseServicePort(line);
+            print('service protocol connection available at port $vmServicePort');
             print('run: ready!');
             ready.complete();
             ok ??= true;
@@ -60,7 +62,7 @@ void main() {
       print('drive: starting...');
       final Process drive = await startProcess(
         path.join(flutterDirectory.path, 'bin', 'flutter'),
-        <String>['drive', '--use-existing-app', 'http://127.0.0.1:8888/', '--no-keep-app-running', 'lib/route.dart'],
+        <String>['drive', '--use-existing-app', 'http://127.0.0.1:$vmServicePort/', '--no-keep-app-running', 'lib/route.dart'],
       );
       drive.stdout
         .transform(UTF8.decoder)

dev/devicelab/bin/tasks/service_extensions_test.dart

+// Copyright (c) 2017 The Chromium 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';
+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';
+
+void main() {
+  task(() async {
+    int vmServicePort;
+
+    final Device device = await devices.workingDevice;
+    await device.unlock();
+    final Directory appDir = dir(path.join(flutterDirectory.path, 'dev/integration_tests/ui'));
+    await inDirectory(appDir, () async {
+      final Completer<Null> ready = new Completer<Null>();
+      bool ok;
+      print('run: starting...');
+      final Process run = await startProcess(
+        path.join(flutterDirectory.path, 'bin', 'flutter'),
+        <String>['run', '--verbose', '-d', device.deviceId, 'lib/main.dart'],
+      );
+      run.stdout
+          .transform(UTF8.decoder)
+          .transform(const LineSplitter())
+          .listen((String line) {
+        print('run:stdout: $line');
+        if (lineContainsServicePort(line)) {
+          vmServicePort = parseServicePort(line);
+          print('service protocol connection available at port $vmServicePort');
+          print('run: ready!');
+          ready.complete();
+          ok ??= true;
+        }
+      });
+      run.stderr
+          .transform(UTF8.decoder)
+          .transform(const LineSplitter())
+          .listen((String line) {
+        stderr.writeln('run:stderr: $line');
+      });
+      run.exitCode.then((int exitCode) { ok = false; });
+      await Future.any<dynamic>(<Future<dynamic>>[ ready.future, run.exitCode ]);
+      if (!ok)
+        throw 'Failed to run test app.';
+
+      final VMServiceClient client = new VMServiceClient.connect('ws://localhost:$vmServicePort/ws');
+      final VM vm = await client.getVM();
+      final VMIsolateRef isolate = vm.isolates.first;
+      final Stream<VMExtensionEvent> frameEvents = isolate.onExtensionEvent.where(
+              (VMExtensionEvent e) => e.kind == 'Flutter.Frame');
+
+      print('reassembling app...');
+      final Future<VMExtensionEvent> frameFuture = frameEvents.first;
+      await isolate.invokeExtension('ext.flutter.reassemble');
+
+      // ensure we get an event
+      final VMExtensionEvent event = await frameFuture;
+      print('${event.kind}: ${event.data}');
+
+      // validate the fields
+      // {number: 8, startTime: 0, elapsed: 1437}
+      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);
+
+      run.stdin.write('q');
+      final int result = await run.exitCode;
+      if (result != 0)
+        throw 'Received unexpected exit code $result from run process.';
+    });
+    return new TaskResult.success(null);
+  });
+}
+
+void expect(bool value) {
+  if (!value)
+    throw 'failed assertion in service extensions test';
+}

dev/devicelab/lib/framework/utils.dart

@@ -473,3 +473,13 @@ String extractCloudAuthTokenArg(List<String> rawArgs) {
   }
   return token;
 }
+
+// "An Observatory debugger and profiler on ... is available at: http://127.0.0.1:8100/"
+final RegExp _kObservatoryRegExp = new RegExp(r'An Observatory debugger .* is available at: (\S+:(\d+))');
+
+bool lineContainsServicePort(String line) => line.contains(_kObservatoryRegExp);
+
+int parseServicePort(String line) {
+  final Match match = _kObservatoryRegExp.firstMatch(line);
+  return match == null ? null : int.parse(match.group(2));
+}

dev/devicelab/manifest.yaml

@@ -134,6 +134,13 @@ tasks:
     required_agent_capabilities: ["has-android-device"]
     flaky: true
 
+  service_extensions_test:
+    description: >
+      Validates our service protocol extensions.
+    stage: devicelab
+    required_agent_capabilities: ["has-android-device"]
+    flaky: true
+
   android_sample_catalog_generator:
     description: >
       Builds sample catalog markdown pages and Android screenshots

packages/flutter/lib/src/scheduler/binding.dart

@@ -557,7 +557,8 @@ abstract class SchedulerBinding extends BindingBase {
   }
   Duration _currentFrameTimeStamp;
 
-  int _debugFrameNumber = 0;
+  int _profileFrameNumber = 0;
+  final Stopwatch _profileFrameStopwatch = new Stopwatch();
   String _debugBanner;
 
   /// Called by the engine to prepare the framework to produce a new frame.
@@ -590,8 +591,13 @@ abstract class SchedulerBinding extends BindingBase {
     if (rawTimeStamp != null)
       _lastRawTimeStamp = rawTimeStamp;
 
+    profile(() {
+      _profileFrameNumber += 1;
+      _profileFrameStopwatch.reset();
+      _profileFrameStopwatch.start();
+    });
+
     assert(() {
-      _debugFrameNumber += 1;
       if (debugPrintBeginFrameBanner || debugPrintEndFrameBanner) {
         final StringBuffer frameTimeStampDescription = new StringBuffer();
         if (rawTimeStamp != null) {
@@ -599,7 +605,7 @@ abstract class SchedulerBinding extends BindingBase {
         } else {
           frameTimeStampDescription.write('(warm-up frame)');
         }
-        _debugBanner = '▄▄▄▄▄▄▄▄ Frame ${_debugFrameNumber.toString().padRight(7)}   ${frameTimeStampDescription.toString().padLeft(18)} ▄▄▄▄▄▄▄▄';
+        _debugBanner = '▄▄▄▄▄▄▄▄ Frame ${_profileFrameNumber.toString().padRight(7)}   ${frameTimeStampDescription.toString().padLeft(18)} ▄▄▄▄▄▄▄▄';
         if (debugPrintBeginFrameBanner)
           debugPrint(_debugBanner);
       }
@@ -651,20 +657,32 @@ abstract class SchedulerBinding extends BindingBase {
         _invokeFrameCallback(callback, _currentFrameTimeStamp);
     } finally {
       _schedulerPhase = SchedulerPhase.idle;
-      _currentFrameTimeStamp = null;
-      Timeline.finishSync();
+      Timeline.finishSync(); // end the Frame
+      profile(() {
+        _profileFrameStopwatch.stop();
+        _profileFramePostEvent();
+      });
       assert(() {
         if (debugPrintEndFrameBanner)
           debugPrint('▀' * _debugBanner.length);
         _debugBanner = null;
         return true;
       });
+      _currentFrameTimeStamp = null;
     }
 
     // All frame-related callbacks have been executed. Run lower-priority tasks.
     _runTasks();
   }
 
+  void _profileFramePostEvent() {
+    postEvent('Flutter.Frame', <String, dynamic>{
+      'number': _profileFrameNumber,
+      'startTime': _currentFrameTimeStamp.inMicroseconds,
+      'elapsed': _profileFrameStopwatch.elapsedMicroseconds
+    });
+  }
+
   static void _debugDescribeTimeStamp(Duration timeStamp, StringBuffer buffer) {
     if (timeStamp.inDays > 0)
       buffer.write('${timeStamp.inDays}d ');