Send timings of the first frame without batching (#9424)

For https://github.com/flutter/flutter/issues/34867

Test added:
* ReportTimingsIsCalledImmediatelyAfterTheFirstFrame

lib/ui/window.dart

@@ -19,7 +19,8 @@ typedef FrameCallback = void Function(Duration duration);
 /// 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.
+/// even if there are no later frames to batch. The timing of the first frame
+/// will be sent immediately without batching.
 /// {@endtemplate}
 typedef TimingsCallback = void Function(List<FrameTiming> timings);
 

shell/common/shell.cc

@@ -938,7 +938,8 @@ void Shell::OnFrameRasterized(const FrameTiming& timing) {
   // 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) {
+  if (!first_frame_rasterized_ || UnreportedFramesCount() >= 100) {
+    first_frame_rasterized_ = true;
     ReportTimings();
   } else if (!frame_timings_report_scheduled_) {
 #if FLUTTER_RUNTIME_MODE == FLUTTER_RUNTIME_MODE_RELEASE

shell/common/shell.h

@@ -110,6 +110,8 @@ class Shell final : public PlatformView::Delegate,
   bool is_setup_ = false;
   uint64_t next_pointer_flow_id_ = 0;
 
+  bool first_frame_rasterized_ = false;
+
   // Written in the UI thread and read from the GPU thread. Hence make it
   // atomic.
   std::atomic<bool> needs_report_timings_{false};

shell/common/shell_unittests.cc

@@ -156,7 +156,7 @@ TEST_F(ShellTest, InitializeWithGPUAndPlatformThreadsTheSame) {
 TEST_F(ShellTest, FixturesAreFunctional) {
   ASSERT_FALSE(DartVMRef::IsInstanceRunning());
   auto settings = CreateSettingsForFixture();
-  auto shell = CreateShell(std::move(settings));
+  auto shell = CreateShell(settings);
   ASSERT_TRUE(ValidateShell(shell.get()));
 
   auto configuration = RunConfiguration::InferFromSettings(settings);
@@ -178,7 +178,7 @@ TEST_F(ShellTest, FixturesAreFunctional) {
 TEST_F(ShellTest, SecondaryIsolateBindingsAreSetupViaShellSettings) {
   ASSERT_FALSE(DartVMRef::IsInstanceRunning());
   auto settings = CreateSettingsForFixture();
-  auto shell = CreateShell(std::move(settings));
+  auto shell = CreateShell(settings);
   ASSERT_TRUE(ValidateShell(shell.get()));
 
   auto configuration = RunConfiguration::InferFromSettings(settings);
@@ -251,7 +251,7 @@ TEST_F(ShellTest, WhitelistedDartVMFlag) {
 
 TEST_F(ShellTest, NoNeedToReportTimingsByDefault) {
   auto settings = CreateSettingsForFixture();
-  std::unique_ptr<Shell> shell = CreateShell(std::move(settings));
+  std::unique_ptr<Shell> shell = CreateShell(settings);
 
   // Create the surface needed by rasterizer
   PlatformViewNotifyCreated(shell.get());
@@ -278,7 +278,7 @@ TEST_F(ShellTest, NoNeedToReportTimingsByDefault) {
 
 TEST_F(ShellTest, NeedsReportTimingsIsSetWithCallback) {
   auto settings = CreateSettingsForFixture();
-  std::unique_ptr<Shell> shell = CreateShell(std::move(settings));
+  std::unique_ptr<Shell> shell = CreateShell(settings);
 
   // Create the surface needed by rasterizer
   PlatformViewNotifyCreated(shell.get());
@@ -315,7 +315,7 @@ static void CheckFrameTimings(const std::vector<FrameTiming>& timings,
 TEST_F(ShellTest, ReportTimingsIsCalled) {
   fml::TimePoint start = fml::TimePoint::Now();
   auto settings = CreateSettingsForFixture();
-  std::unique_ptr<Shell> shell = CreateShell(std::move(settings));
+  std::unique_ptr<Shell> shell = CreateShell(settings);
 
   // Create the surface needed by rasterizer
   PlatformViewNotifyCreated(shell.get());
@@ -381,7 +381,7 @@ TEST_F(ShellTest, FrameRasterizedCallbackIsCalled) {
     timingLatch.Signal();
   };
 
-  std::unique_ptr<Shell> shell = CreateShell(std::move(settings));
+  std::unique_ptr<Shell> shell = CreateShell(settings);
 
   // Create the surface needed by rasterizer
   PlatformViewNotifyCreated(shell.get());
@@ -433,13 +433,59 @@ TEST(SettingsTest, FrameTimingSetsAndGetsProperly) {
 }
 
 #if FLUTTER_RUNTIME_MODE == FLUTTER_RUNTIME_MODE_RELEASE
-TEST_F(ShellTest, ReportTimingsIsCalledSoonerInNonReleaseMode) {
-#else
 TEST_F(ShellTest, ReportTimingsIsCalledLaterInReleaseMode) {
+#else
+TEST_F(ShellTest, ReportTimingsIsCalledSoonerInNonReleaseMode) {
 #endif
   fml::TimePoint start = fml::TimePoint::Now();
   auto settings = CreateSettingsForFixture();
-  std::unique_ptr<Shell> shell = CreateShell(std::move(settings));
+  std::unique_ptr<Shell> shell = CreateShell(settings);
+
+  // Create the surface needed by rasterizer
+  PlatformViewNotifyCreated(shell.get());
+
+  auto configuration = RunConfiguration::InferFromSettings(settings);
+  ASSERT_TRUE(configuration.IsValid());
+  configuration.SetEntrypoint("reportTimingsMain");
+
+  // Wait for 2 reports: the first one is the immediate callback of the first
+  // frame; the second one will exercise the batching logic.
+  fml::CountDownLatch reportLatch(2);
+  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.CountDown();
+  };
+  AddNativeCallback("NativeReportTimingsCallback",
+                    CREATE_NATIVE_ENTRY(nativeTimingCallback));
+  RunEngine(shell.get(), std::move(configuration));
+
+  PumpOneFrame(shell.get());
+  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
+}
+
+TEST_F(ShellTest, ReportTimingsIsCalledImmediatelyAfterTheFirstFrame) {
+  auto settings = CreateSettingsForFixture();
+  std::unique_ptr<Shell> shell = CreateShell(settings);
 
   // Create the surface needed by rasterizer
   PlatformViewNotifyCreated(shell.get());
@@ -460,23 +506,16 @@ TEST_F(ShellTest, ReportTimingsIsCalledLaterInReleaseMode) {
                     CREATE_NATIVE_ENTRY(nativeTimingCallback));
   RunEngine(shell.get(), std::move(configuration));
 
-  PumpOneFrame(shell.get());
+  for (int i = 0; i < 10; i += 1) {
+    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
+  // Check for the immediate callback of the first frame that doesn't wait for
+  // the other 9 frames to be rasterized.
+  ASSERT_EQ(timestamps.size(), FrameTiming::kCount);
 }
 
 }  // namespace testing