From fe0db192d98063be5636a2e9dd2078f819ba2e4c Mon Sep 17 00:00:00 2001
From: liyuqian <liyuqian@google.com>
Date: Tue, 11 Jun 2019 16:51:20 -0700
Subject: [PATCH] Report timings faster (100ms) in profile/debug
 (flutter/engine#9287)

This should satisfy the low-latency need of DevTools.

Test added:
* ReportTimingsIsCalledSoonerInNonReleaseMode
* ReportTimingsIsCalledLaterInReleaseMode
---
 engine/src/flutter/lib/ui/window.dart         | 13 ++---
 engine/src/flutter/shell/common/shell.cc      | 13 ++++-
 .../flutter/shell/common/shell_unittests.cc   | 47 +++++++++++++++++++
 3 files changed, 66 insertions(+), 7 deletions(-)

diff --git a/engine/src/flutter/lib/ui/window.dart b/engine/src/flutter/lib/ui/window.dart
index 447100769b..3b87d9a371 100644
--- a/engine/src/flutter/lib/ui/window.dart
+++ b/engine/src/flutter/lib/ui/window.dart
@@ -13,12 +13,13 @@ typedef FrameCallback = void Function(Duration duration);
 /// Signature for [Window.onReportTimings].
 ///
 /// {@template dart.ui.TimingsCallback.list}
-/// The callback takes a list of [FrameTiming] because it may not be immediately
-/// triggered after each frame. Instead, Flutter tries to batch frames together
-/// and send all their timings at once to decrease the overhead (as this is
-/// available in the release mode). The list is sorted in ascending order of
-/// time (earliest frame first). The timing of any frame will be sent within
-/// about 1 second even if there are no later frames to batch.
+/// The callback takes a list of [FrameTiming] because it may not be
+/// immediately triggered after each frame. Instead, Flutter tries to batch
+/// frames together and send all their timings at once to decrease the
+/// overhead (as this is available in the release mode). The list is sorted in
+/// ascending order of time (earliest frame first). The timing of any frame
+/// will be sent within about 1 second (100ms if in the profile/debug mode)
+/// even if there are no later frames to batch.
 /// {@endtemplate}
 typedef TimingsCallback = void Function(List<FrameTiming> timings);
 
diff --git a/engine/src/flutter/shell/common/shell.cc b/engine/src/flutter/shell/common/shell.cc
index 09405f6cd3..41eae0c373 100644
--- a/engine/src/flutter/shell/common/shell.cc
+++ b/engine/src/flutter/shell/common/shell.cc
@@ -934,9 +934,20 @@ void Shell::OnFrameRasterized(const FrameTiming& timing) {
   // threshold here is mainly for unit tests (so we don't have to write a
   // 1-second unit test), and make sure that our vector won't grow too big with
   // future 120fps, 240fps, or 1000fps displays.
+  //
+  // In the profile/debug mode, the timings are used by development tools which
+  // require a latency of no more than 100ms. Hence we lower that 1-second
+  // threshold to 100ms because performance overhead isn't that critical in
+  // those cases.
   if (UnreportedFramesCount() >= 100) {
     ReportTimings();
   } else if (!frame_timings_report_scheduled_) {
+#if FLUTTER_RUNTIME_MODE == FLUTTER_RUNTIME_MODE_RELEASE
+    constexpr int kBatchTimeInMilliseconds = 1000;
+#else
+    constexpr int kBatchTimeInMilliseconds = 100;
+#endif
+
     // Also make sure that frame times get reported with a max latency of 1
     // second. Otherwise, the timings of last few frames of an animation may
     // never be reported until the next animation starts.
@@ -951,7 +962,7 @@ void Shell::OnFrameRasterized(const FrameTiming& timing) {
             self->ReportTimings();
           }
         },
-        fml::TimeDelta::FromSeconds(1));
+        fml::TimeDelta::FromMilliseconds(kBatchTimeInMilliseconds));
   }
 }
 
diff --git a/engine/src/flutter/shell/common/shell_unittests.cc b/engine/src/flutter/shell/common/shell_unittests.cc
index 812abd7504..dcc3c7a8e7 100644
--- a/engine/src/flutter/shell/common/shell_unittests.cc
+++ b/engine/src/flutter/shell/common/shell_unittests.cc
@@ -434,5 +434,52 @@ TEST(SettingsTest, FrameTimingSetsAndGetsProperly) {
   }
 }
 
+#if FLUTTER_RUNTIME_MODE == FLUTTER_RUNTIME_MODE_RELEASE
+TEST_F(ShellTest, ReportTimingsIsCalledSoonerInNonReleaseMode) {
+#else
+TEST_F(ShellTest, ReportTimingsIsCalledLaterInNonReleaseMode) {
+#endif
+  fml::TimePoint start = fml::TimePoint::Now();
+  auto settings = CreateSettingsForFixture();
+  std::unique_ptr<Shell> shell = CreateShell(std::move(settings));
+
+  // Create the surface needed by rasterizer
+  PlatformViewNotifyCreated(shell.get());
+
+  auto configuration = RunConfiguration::InferFromSettings(settings);
+  ASSERT_TRUE(configuration.IsValid());
+  configuration.SetEntrypoint("reportTimingsMain");
+  fml::AutoResetWaitableEvent reportLatch;
+  std::vector<int64_t> timestamps;
+  auto nativeTimingCallback = [&reportLatch,
+                               &timestamps](Dart_NativeArguments args) {
+    Dart_Handle exception = nullptr;
+    timestamps = tonic::DartConverter<std::vector<int64_t>>::FromArguments(
+        args, 0, exception);
+    reportLatch.Signal();
+  };
+  AddNativeCallback("NativeReportTimingsCallback",
+                    CREATE_NATIVE_ENTRY(nativeTimingCallback));
+  RunEngine(shell.get(), std::move(configuration));
+
+  PumpOneFrame(shell.get());
+
+  reportLatch.Wait();
+  shell.reset();
+
+  fml::TimePoint finish = fml::TimePoint::Now();
+  fml::TimeDelta ellapsed = finish - start;
+
+#if FLUTTER_RUNTIME_MODE == FLUTTER_RUNTIME_MODE_RELEASE
+  // Our batch time is 1000ms. Hopefully the 800ms limit is relaxed enough to
+  // make it not too flaky.
+  ASSERT_TRUE(ellapsed >= fml::TimeDelta::FromMilliseconds(800));
+#else
+  // Our batch time is 100ms. Hopefully the 500ms limit is relaxed enough to
+  // make it not too flaky.
+  ASSERT_TRUE(ellapsed <= fml::TimeDelta::FromMilliseconds(500));
+#endif
+}
+
 }  // namespace testing
 }  // namespace flutter