web: implement frame timings (#21552)

* web: implement frame timings

lib/web_ui/lib/src/engine.dart

@@ -164,8 +164,6 @@ void registerHotRestartListener(ui.VoidCallback listener) {
 ///
 /// This is only available on the Web, as native Flutter configures the
 /// environment in the native embedder.
-// TODO(yjbanov): we should refactor the code such that the framework does not
-//                call this method directly.
 void initializeEngine() {
   if (_engineInitialized) {
     return;
@@ -205,6 +203,8 @@ void initializeEngine() {
     if (!waitingForAnimation) {
       waitingForAnimation = true;
       html.window.requestAnimationFrame((num highResTime) {
+        _frameTimingsOnVsync();
+
         // Reset immediately, because `frameHandler` can schedule more frames.
         waitingForAnimation = false;
 
@@ -215,6 +215,13 @@ void initializeEngine() {
         // microsecond precision, and only then convert to `int`.
         final int highResTimeMicroseconds = (1000 * highResTime).toInt();
 
+        // In Flutter terminology "building a frame" consists of "beginning
+        // frame" and "drawing frame".
+        //
+        // We do not call `_frameTimingsOnBuildFinish` from here because
+        // part of the rasterization process, particularly in the HTML
+        // renderer, takes place in the `SceneBuilder.build()`.
+        _frameTimingsOnBuildStart();
         if (window._onBeginFrame != null) {
           window.invokeOnBeginFrame(
               Duration(microseconds: highResTimeMicroseconds));

lib/web_ui/lib/src/engine/html/scene_builder.dart

@@ -528,6 +528,15 @@ class SurfaceSceneBuilder implements ui.SceneBuilder {
   /// cannot be used further.
   @override
   SurfaceScene build() {
+    // "Build finish" and "raster start" happen back-to-back because we
+    // render on the same thread, so there's no overhead from hopping to
+    // another thread.
+    //
+    // In the HTML renderer we time the beginning of the rasterization phase
+    // (counter-intuitively) in SceneBuilder.build because DOM updates happen
+    // here. This is different from CanvasKit.
+    _frameTimingsOnBuildFinish();
+    _frameTimingsOnRasterStart();
     timeAction<void>(kProfilePrerollFrame, () {
       while (_surfaceStack.length > 1) {
         // Auto-pop layers that were pushed without a corresponding pop.

lib/web_ui/lib/src/engine/profiler.dart

@@ -107,3 +107,114 @@ class Profiler {
     }
   }
 }
+
+/// Whether we are collecting [ui.FrameTiming]s.
+bool get _frameTimingsEnabled {
+  return window._onReportTimings != null;
+}
+
+/// Collects frame timings from frames.
+///
+/// This list is periodically reported to the framework (see
+/// [_kFrameTimingsSubmitInterval]).
+List<ui.FrameTiming> _frameTimings = <ui.FrameTiming>[];
+
+/// The amount of time in microseconds we wait between submitting
+/// frame timings.
+const int _kFrameTimingsSubmitInterval = 100000; // 100 milliseconds
+
+/// The last time (in microseconds) we submitted frame timings.
+int _frameTimingsLastSubmitTime = _nowMicros();
+
+// These variables store individual [ui.FrameTiming] properties.
+int _vsyncStartMicros = -1;
+int _buildStartMicros = -1;
+int _buildFinishMicros = -1;
+int _rasterStartMicros = -1;
+int _rasterFinishMicros = -1;
+
+/// Records the vsync timestamp for this frame.
+void _frameTimingsOnVsync() {
+  if (!_frameTimingsEnabled) {
+    return;
+  }
+  _vsyncStartMicros = _nowMicros();
+}
+
+/// Records the time when the framework started building the frame.
+void _frameTimingsOnBuildStart() {
+  if (!_frameTimingsEnabled) {
+    return;
+  }
+  _buildStartMicros = _nowMicros();
+}
+
+/// Records the time when the framework finished building the frame.
+void _frameTimingsOnBuildFinish() {
+  if (!_frameTimingsEnabled) {
+    return;
+  }
+  _buildFinishMicros = _nowMicros();
+}
+
+/// Records the time when the framework started rasterizing the frame.
+///
+/// On the web, this value is almost always the same as [_buildFinishMicros]
+/// because it's single-threaded so there's no delay between building
+/// and rasterization.
+///
+/// This also means different things between HTML and CanvasKit renderers.
+///
+/// In HTML "rasterization" only captures DOM updates, but not the work that
+/// the browser performs after the DOM updates are committed. The browser
+/// does not report that information.
+///
+/// CanvasKit captures everything because we control the rasterization
+/// process, so we know exactly when rasterization starts and ends.
+void _frameTimingsOnRasterStart() {
+  if (!_frameTimingsEnabled) {
+    return;
+  }
+  _rasterStartMicros = _nowMicros();
+}
+
+/// Records the time when the framework started rasterizing the frame.
+///
+/// See [_frameTimingsOnRasterStart] for more details on what rasterization
+/// timings mean on the web.
+void _frameTimingsOnRasterFinish() {
+  if (!_frameTimingsEnabled) {
+    return;
+  }
+  final int now = _nowMicros();
+  _rasterFinishMicros = now;
+  _frameTimings.add(ui.FrameTiming(
+    vsyncStart: _vsyncStartMicros,
+    buildStart: _buildStartMicros,
+    buildFinish: _buildFinishMicros,
+    rasterStart: _rasterStartMicros,
+    rasterFinish: _rasterFinishMicros,
+  ));
+  _vsyncStartMicros = -1;
+  _buildStartMicros = -1;
+  _buildFinishMicros = -1;
+  _rasterStartMicros = -1;
+  _rasterFinishMicros = -1;
+  if (now - _frameTimingsLastSubmitTime > _kFrameTimingsSubmitInterval) {
+    _frameTimingsLastSubmitTime = now;
+    window.invokeOnReportTimings(_frameTimings);
+    _frameTimings = <ui.FrameTiming>[];
+  }
+}
+
+/// Current timestamp in microseconds taken from the high-precision
+/// monotonically increasing timer.
+///
+/// See also:
+///
+/// * https://developer.mozilla.org/en-US/docs/Web/API/Performance/now,
+///   particularly notes about Firefox rounding to 1ms for security reasons,
+///   which can be bypassed in tests by setting certain browser options.
+int _nowMicros() {
+  return (html.window.performance.now() * 1000).toInt();
+}

lib/web_ui/lib/src/engine/window.dart

@@ -765,12 +765,23 @@ class EngineWindow extends ui.Window {
   @override
   void render(ui.Scene scene) {
     if (experimentalUseSkia) {
+      // "Build finish" and "raster start" happen back-to-back because we
+      // render on the same thread, so there's no overhead from hopping to
+      // another thread.
+      //
+      // CanvasKit works differently from the HTML renderer in that in HTML
+      // we update the DOM in SceneBuilder.build, which is these function calls
+      // here are CanvasKit-only.
+      _frameTimingsOnBuildFinish();
+      _frameTimingsOnRasterStart();
+
       final LayerScene layerScene = scene as LayerScene;
       rasterizer!.draw(layerScene.layerTree);
     } else {
       final SurfaceScene surfaceScene = scene as SurfaceScene;
       domRenderer.renderScene(surfaceScene.webOnlyRootElement);
     }
+    _frameTimingsOnRasterFinish();
   }
 
   @visibleForTesting

lib/web_ui/test/canvaskit/frame_timings_test.dart

+// Copyright 2013 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.
+
+// @dart = 2.6
+import 'package:test/bootstrap/browser.dart';
+import 'package:test/test.dart';
+import 'package:ui/src/engine.dart';
+import 'package:ui/ui.dart' as ui;
+
+import 'common.dart';
+import '../frame_timings_common.dart';
+
+void main() {
+  internalBootstrapBrowserTest(() => testMain);
+}
+
+void testMain() {
+  group('frame timings', () {
+    setUpAll(() async {
+      await ui.webOnlyInitializePlatform();
+    });
+
+    test('Using CanvasKit', () {
+      expect(experimentalUseSkia, true);
+    });
+
+    test('collects frame timings', () async {
+      await runFrameTimingsTest();
+    });
+  }, skip: isIosSafari); // TODO: https://github.com/flutter/flutter/issues/60040
+}

lib/web_ui/test/engine/surface/frame_timings_test.dart

+// Copyright 2013 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.
+
+// @dart = 2.6
+import 'package:test/bootstrap/browser.dart';
+import 'package:test/test.dart';
+import 'package:ui/src/engine.dart';
+
+import '../../frame_timings_common.dart';
+
+void main() {
+  internalBootstrapBrowserTest(() => testMain);
+}
+
+void testMain() {
+  setUp(() async {
+    await initializeEngine();
+  });
+
+  test('collects frame timings', () async {
+    await runFrameTimingsTest();
+  });
+}

lib/web_ui/test/frame_timings_common.dart

+// Copyright 2013 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.
+
+// @dart = 2.6
+import 'dart:async';
+
+import 'package:test/test.dart';
+import 'package:ui/ui.dart' as ui;
+
+/// Tests frame timings in a renderer-agnostic way.
+///
+/// See CanvasKit-specific and HTML-specific test files `frame_timings_test.dart`.
+Future<void> runFrameTimingsTest() async {
+  List<ui.FrameTiming> timings;
+  ui.window.onReportTimings = (List<ui.FrameTiming> data) {
+    timings = data;
+  };
+  Completer<void> frameDone = Completer<void>();
+  ui.window.onDrawFrame = () {
+    final ui.SceneBuilder sceneBuilder = ui.SceneBuilder();
+    sceneBuilder
+      ..pushOffset(0, 0)
+      ..pop();
+    ui.window.render(sceneBuilder.build());
+    frameDone.complete();
+  };
+
+  // Frame 1.
+  ui.window.scheduleFrame();
+  await frameDone.future;
+  expect(timings, isNull, reason: '100 ms hasn\'t passed yet');
+  await Future<void>.delayed(const Duration(milliseconds: 150));
+
+  // Frame 2.
+  frameDone = Completer<void>();
+  ui.window.scheduleFrame();
+  await frameDone.future;
+  expect(timings, hasLength(2), reason: '100 ms passed. 2 frames pumped.');
+  for (final ui.FrameTiming timing in timings) {
+    expect(timing.vsyncOverhead, greaterThanOrEqualTo(Duration.zero));
+    expect(timing.buildDuration, greaterThanOrEqualTo(Duration.zero));
+    expect(timing.rasterDuration, greaterThanOrEqualTo(Duration.zero));
+    expect(timing.totalSpan, greaterThanOrEqualTo(Duration.zero));
+  }
+}