[UKM] Record FCP information in Blink.UpdateTime

Add a boolean metric to Blink.UpdateTime to record whether the event
was before or after FCP (First Contentful Paint). Also re-organise the
way we report FCP to LocalFrameView for the purposes of the new metric
and triggering commits. The latter reduces code in PaintTiming.

Bug: 1001199
Change-Id: Ibc18faae13ece92e1270c72548585e1f3c4dcc2e
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1864366Reviewed-by: Robert Kaplow <rkaplow@chromium.org>
Reviewed-by: vmpstr <vmpstr@chromium.org>
Commit-Queue: Stephen Chenney <schenney@chromium.org>
Cr-Commit-Position: refs/heads/master@{#710029}

third_party/blink/renderer/core/frame/local_frame_ukm_aggregator.cc

@@ -273,6 +273,7 @@ void LocalFrameUkmAggregator::UpdateEventTimeAndRecordEventIfNeeded() {
 void LocalFrameUkmAggregator::RecordEvent() {
   ukm::builders::Blink_UpdateTime builder(source_id_);
   builder.SetMainFrame(primary_metric_.interval_duration.InMicroseconds());
+  builder.SetMainFrameIsBeforeFCP(is_before_fcp_);
   for (unsigned i = 0; i < (unsigned)kCount; ++i) {
     MetricId id = static_cast<MetricId>(i);
     auto& absolute_record = absolute_metric_records_[(unsigned)id];

third_party/blink/renderer/core/frame/local_frame_ukm_aggregator.h

@@ -226,7 +226,7 @@ class CORE_EXPORT LocalFrameUkmAggregator
 
   // Record a main frame time metric, that also computes the ratios for the
   // sub-metrics and generates UMA samples. UKM is only reported when
-  // BeginMainFrame() returned true. All counters are cleared when this method
+  // BeginMainFrame() had been called. All counters are cleared when this method
   // is called.
   void RecordEndOfFrameMetrics(base::TimeTicks start, base::TimeTicks end);
 
@@ -240,6 +240,10 @@ class CORE_EXPORT LocalFrameUkmAggregator
   // Mark the beginning of a main frame update.
   void BeginMainFrame();
 
+  // Inform the aggregator that we have reached First Contentful Paint.
+  // The UKM event reports this.
+  void DidReachFirstContentfulPaint() { is_before_fcp_ = false; }
+
   bool InMainFrame() { return in_main_frame_update_; }
 
   // Populate a BeginMainFrameMetrics structure with the latency numbers for
@@ -315,6 +319,9 @@ class CORE_EXPORT LocalFrameUkmAggregator
   // Main frame metrics are only recorded if this is true.
   bool in_main_frame_update_ = false;
 
+  // Record whether or not it is before the First Contentful Paint.
+  bool is_before_fcp_ = true;
+
   DISALLOW_COPY_AND_ASSIGN(LocalFrameUkmAggregator);
 };
 

third_party/blink/renderer/core/frame/local_frame_ukm_aggregator_test.cc

@@ -61,7 +61,8 @@ class LocalFrameUkmAggregatorTest : public testing::Test {
   void VerifyEntries(unsigned expected_num_entries,
                      unsigned expected_primary_metric,
                      unsigned expected_sub_metric,
-                     unsigned expected_percentage) {
+                     unsigned expected_percentage,
+                     bool expected_before_fcp) {
     EXPECT_EQ(recorder().entries_count(), expected_num_entries);
     auto entries = recorder().GetEntriesByName("Blink.UpdateTime");
     EXPECT_EQ(entries.size(), expected_num_entries);
@@ -85,6 +86,10 @@ class LocalFrameUkmAggregatorTest : public testing::Test {
             entry, GetPercentageMetricName(i));
         EXPECT_NEAR(*metric_percentage, expected_percentage, 0.001);
       }
+      EXPECT_TRUE(
+          ukm::TestUkmRecorder::EntryHasMetric(entry, "MainFrameIsBeforeFCP"));
+      EXPECT_EQ(expected_before_fcp, *ukm::TestUkmRecorder::GetEntryMetric(
+                                         entry, "MainFrameIsBeforeFCP"));
     }
   }
 
@@ -138,13 +143,13 @@ TEST_F(LocalFrameUkmAggregatorTest, FirstFrameIsRecorded) {
       floor(100.0 / (float)LocalFrameUkmAggregator::kCount);
 
   VerifyEntries(1u, expected_primary_metric, expected_sub_metric,
-                expected_percentage);
+                expected_percentage, true);
 
   // Reset the aggregator. Should not record any more.
   ResetAggregator();
 
   VerifyEntries(1u, expected_primary_metric, expected_sub_metric,
-                expected_percentage);
+                expected_percentage, true);
 }
 
 TEST_F(LocalFrameUkmAggregatorTest, EventsRecordedAtIntervals) {
@@ -157,6 +162,9 @@ TEST_F(LocalFrameUkmAggregatorTest, EventsRecordedAtIntervals) {
   // The records should be recorded in the first frame after every interval,
   // and no sooner.
 
+  // If we claim we are past FCP, the event should indicate that.
+  aggregator().DidReachFirstContentfulPaint();
+
   // Set the first sample interval to 2.
   FramesToNextEventForTest(2);
   unsigned millisecond_per_step = 50 / (LocalFrameUkmAggregator::kCount + 1);
@@ -179,7 +187,7 @@ TEST_F(LocalFrameUkmAggregatorTest, EventsRecordedAtIntervals) {
   float expected_percentage =
       floor(millisecond_per_step * 100.0 / (float)millisecond_per_frame);
   VerifyEntries(1u, millisecond_per_frame, millisecond_per_step,
-                expected_percentage);
+                expected_percentage, false);
 
   // Another step does not get us past the sample interval.
   start_time = Now();
@@ -194,7 +202,7 @@ TEST_F(LocalFrameUkmAggregatorTest, EventsRecordedAtIntervals) {
   aggregator().RecordEndOfFrameMetrics(start_time, Now());
 
   VerifyEntries(1u, millisecond_per_frame, millisecond_per_step,
-                expected_percentage);
+                expected_percentage, false);
 
   // Another step should tick us past the sample interval.
   // Note that the sample is a single frame, so even if we've taken
@@ -211,7 +219,7 @@ TEST_F(LocalFrameUkmAggregatorTest, EventsRecordedAtIntervals) {
   aggregator().RecordEndOfFrameMetrics(start_time, Now());
 
   VerifyEntries(2u, millisecond_per_frame, millisecond_per_step,
-                expected_percentage);
+                expected_percentage, false);
 
   // Step one more frame so we don't sample again.
   start_time = Now();
@@ -227,7 +235,7 @@ TEST_F(LocalFrameUkmAggregatorTest, EventsRecordedAtIntervals) {
 
   // Should be no more samples.
   VerifyEntries(2u, millisecond_per_frame, millisecond_per_step,
-                expected_percentage);
+                expected_percentage, false);
 
   // And one more step to generate one more sample
   start_time = Now();
@@ -244,7 +252,7 @@ TEST_F(LocalFrameUkmAggregatorTest, EventsRecordedAtIntervals) {
   // We should have 3 more events, once for the prior interval and 2 for the
   // new interval.
   VerifyEntries(3u, millisecond_per_frame, millisecond_per_step,
-                expected_percentage);
+                expected_percentage, false);
 }
 
 TEST_F(LocalFrameUkmAggregatorTest, LatencyDataIsPopulated) {

third_party/blink/renderer/core/frame/local_frame_view.cc

@@ -4327,6 +4327,12 @@ LocalFrameUkmAggregator& LocalFrameView::EnsureUkmAggregator() {
   return *ukm_aggregator_;
 }
 
+void LocalFrameView::OnFirstContentfulPaint() {
+  GetPage()->GetChromeClient().StopDeferringCommits(
+      *frame_, cc::PaintHoldingCommitTrigger::kFirstContentfulPaint);
+  EnsureUkmAggregator().DidReachFirstContentfulPaint();
+}
+
 void LocalFrameView::RegisterForLifecycleNotifications(
     LifecycleNotificationObserver* observer) {
   lifecycle_observers_.insert(observer);

third_party/blink/renderer/core/frame/local_frame_view.h

@@ -672,6 +672,11 @@ class CORE_EXPORT LocalFrameView final
   // Return the UKM aggregator for this frame, creating it if necessary.
   LocalFrameUkmAggregator& EnsureUkmAggregator();
 
+  // Report the First Contentful Paint signal to the LocalFrameView.
+  // This causes Deferred Commits to be restarted and tells the UKM
+  // aggregator that FCP has been reached.
+  void OnFirstContentfulPaint();
+
 #if DCHECK_IS_ON()
   void SetIsUpdatingDescendantDependentFlags(bool val) {
     is_updating_descendant_dependent_flags_ = val;

third_party/blink/renderer/core/paint/paint_timing.cc

@@ -163,13 +163,13 @@ void PaintTiming::SetFirstContentfulPaint(base::TimeTicks stamp) {
   RegisterNotifySwapTime(PaintEvent::kFirstContentfulPaint);
 
   // Restart commits that may have been deferred.
-  if (!GetFrame() || !GetFrame()->IsMainFrame())
+  LocalFrame* frame = GetFrame();
+  if (!frame || !frame->IsMainFrame())
     return;
-  GetFrame()->GetPage()->GetChromeClient().StopDeferringCommits(
-      *GetFrame(), cc::PaintHoldingCommitTrigger::kFirstContentfulPaint);
+  frame->View()->OnFirstContentfulPaint();
 
-  if (GetFrame()->GetFrameScheduler())
-    GetFrame()->GetFrameScheduler()->OnFirstContentfulPaint();
+  if (frame->GetFrameScheduler())
+    frame->GetFrameScheduler()->OnFirstContentfulPaint();
 }
 
 void PaintTiming::RegisterNotifySwapTime(PaintEvent event) {

tools/metrics/ukm/ukm.xml

@@ -2043,6 +2043,12 @@ be describing additional metrics about the same event.
       results, in microseconds.
     </summary>
   </metric>
+  <metric name="MainFrameIsBeforeFCP" enum="Boolean">
+    <summary>
+      True if the lifecycle update in this event occurred before FCP (First
+      Contentful Paint) was registered.
+    </summary>
+  </metric>
   <metric name="Paint">
     <summary>
       The time taken to paint for the main frame in microseconds during the