[LCP] Browser: dump trace event once LCP changed

Currently, we dump the trace event on browser shutdown. This posed a
challenge for Telemetry because Telemetry cannot retrieve the event
after the tracing connection is shutdown.

As a replacement, we dump the trace event whenever LCP-handler get
updated. This way, Telemetry will see all the history candidates
and the invalidation of them. Specifically, we use two events:
1. "NavStartToLargestContentfulPaint::Candidate::AllFrames::UKM"
2. "NavStartToLargestContentfulPaint::Invalidate::AllFrames::UKM"
Telemetry needs to sort these events by the trace timestamp. And use
the last one as the final result. Note that the LCP firing time is
different from the trace timestamp. We store it in:
event.args.data.durationInMilliseconds for the candidate event (1).

This CL also adds the frame-type to the trace event. The frame-type
indicates whether the content is from mainframe or subframe.

Bug:967788

Change-Id: If9a75f6ce1f1c93af139557fdb199b096580a774
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1671027Reviewed-by: Liquan (Max) Gu <maxlg@chromium.org>
Reviewed-by: Bryan McQuade <bmcquade@chromium.org>
Commit-Queue: Liquan (Max) Gu <maxlg@chromium.org>
Cr-Commit-Position: refs/heads/master@{#671936}

chrome/browser/page_load_metrics/observers/largest_contentful_paint_handler.cc

@@ -45,7 +45,8 @@ void MergeForSubframesWithAdjustedTime(
     const uint64_t& candidate_new_size) {
   DCHECK(inout_timing);
   const ContentfulPaintTimingInfo new_candidate(
-      candidate_new_time, candidate_new_size, inout_timing->Type());
+      candidate_new_time, candidate_new_size, inout_timing->Type(),
+      inout_timing->InMainFrame());
   const ContentfulPaintTimingInfo& merged_candidate =
       MergeTimingsBySizeAndTime(new_candidate, *inout_timing);
   inout_timing->Reset(merged_candidate.Time(), merged_candidate.Size());
@@ -70,13 +71,18 @@ bool IsSubframe(content::RenderFrameHost* subframe_rfh) {
 }  // namespace
 
 ContentfulPaintTimingInfo::ContentfulPaintTimingInfo(
-    PageLoadMetricsObserver::LargestContentType type)
-    : time_(base::Optional<base::TimeDelta>()), size_(0), type_(type) {}
+    PageLoadMetricsObserver::LargestContentType type,
+    bool in_main_frame)
+    : time_(base::Optional<base::TimeDelta>()),
+      size_(0),
+      type_(type),
+      in_main_frame_(in_main_frame) {}
 ContentfulPaintTimingInfo::ContentfulPaintTimingInfo(
     const base::Optional<base::TimeDelta>& time,
     const uint64_t& size,
-    const page_load_metrics::PageLoadMetricsObserver::LargestContentType type)
-    : time_(time), size_(size), type_(type) {}
+    const page_load_metrics::PageLoadMetricsObserver::LargestContentType type,
+    bool in_main_frame)
+    : time_(time), size_(size), type_(type), in_main_frame_(in_main_frame) {}
 
 ContentfulPaintTimingInfo::ContentfulPaintTimingInfo(
     const ContentfulPaintTimingInfo& other) = default;
@@ -88,6 +94,7 @@ ContentfulPaintTimingInfo::DataAsTraceValue() const {
   data->SetInteger("durationInMilliseconds", time_.value().InMilliseconds());
   data->SetInteger("size", size_);
   data->SetString("type", TypeInString());
+  data->SetBoolean("inMainFrame", InMainFrame());
   return data;
 }
 
@@ -115,15 +122,19 @@ void ContentfulPaintTimingInfo::Reset(
   time_ = time;
 }
 
-ContentfulPaint::ContentfulPaint()
-    : text_(PageLoadMetricsObserver::LargestContentType::kText),
-      image_(PageLoadMetricsObserver::LargestContentType::kImage) {}
+ContentfulPaint::ContentfulPaint(bool in_main_frame)
+    : text_(PageLoadMetricsObserver::LargestContentType::kText, in_main_frame),
+      image_(PageLoadMetricsObserver::LargestContentType::kImage,
+             in_main_frame) {}
 
 const ContentfulPaintTimingInfo& ContentfulPaint::MergeTextAndImageTiming() {
   return MergeTimingsBySizeAndTime(text_, image_);
 }
 
-LargestContentfulPaintHandler::LargestContentfulPaintHandler() = default;
+LargestContentfulPaintHandler::LargestContentfulPaintHandler()
+    : main_frame_contentful_paint_(true /*in_main_frame*/),
+      subframe_contentful_paint_(false /*in_main_frame*/) {}
+
 LargestContentfulPaintHandler::~LargestContentfulPaintHandler() = default;
 
 void LargestContentfulPaintHandler::RecordTiming(

chrome/browser/page_load_metrics/observers/largest_contentful_paint_handler.h

@@ -16,16 +16,17 @@ namespace page_load_metrics {
 class ContentfulPaintTimingInfo {
  public:
   explicit ContentfulPaintTimingInfo(
-      page_load_metrics::PageLoadMetricsObserver::LargestContentType);
+      page_load_metrics::PageLoadMetricsObserver::LargestContentType,
+      bool in_main_frame);
   explicit ContentfulPaintTimingInfo(
       const base::Optional<base::TimeDelta>&,
       const uint64_t& size,
-      const page_load_metrics::PageLoadMetricsObserver::LargestContentType);
+      const page_load_metrics::PageLoadMetricsObserver::LargestContentType,
+      bool in_main_frame);
   explicit ContentfulPaintTimingInfo(const ContentfulPaintTimingInfo& other);
   void Reset(const base::Optional<base::TimeDelta>&, const uint64_t& size);
-  base::Optional<base::TimeDelta> Time() const {
-    return time_;
-  }
+  base::Optional<base::TimeDelta> Time() const { return time_; }
+  bool InMainFrame() const { return in_main_frame_; }
   uint64_t Size() const { return size_; }
   page_load_metrics::PageLoadMetricsObserver::LargestContentType Type() const {
     return type_;
@@ -44,11 +45,12 @@ class ContentfulPaintTimingInfo {
   base::Optional<base::TimeDelta> time_;
   uint64_t size_;
   page_load_metrics::PageLoadMetricsObserver::LargestContentType type_;
+  bool in_main_frame_;
 };
 
 class ContentfulPaint {
  public:
-  ContentfulPaint();
+  explicit ContentfulPaint(bool in_main_frame);
   ContentfulPaintTimingInfo& Text() { return text_; }
   ContentfulPaintTimingInfo& Image() { return image_; }
   const ContentfulPaintTimingInfo& MergeTextAndImageTiming();

chrome/browser/page_load_metrics/observers/ukm_page_load_metrics_observer.cc

@@ -319,9 +319,6 @@ void UkmPageLoadMetricsObserver::RecordTimingMetrics(
       largest_contentful_paint_handler_.MergeMainFrameAndSubframes();
   if (!paint.IsEmpty() &&
       WasStartedInForegroundOptionalEventInForeground(paint.Time(), info)) {
-    TRACE_EVENT_INSTANT1(
-        "loading", "NavStartToLargestContentfulPaint::AllFrames::UKM",
-        TRACE_EVENT_SCOPE_THREAD, "data", paint.DataAsTraceValue());
     builder
         .SetExperimental_PaintTiming_NavigationToLargestContentPaintAllFrames(
             paint.Time().value().InMilliseconds());
@@ -624,6 +621,23 @@ void UkmPageLoadMetricsObserver::OnTimingUpdate(
     const page_load_metrics::PageLoadExtraInfo& extra_info) {
   largest_contentful_paint_handler_.RecordTiming(timing.paint_timing,
                                                  subframe_rfh);
+  bool loading_enabled;
+  TRACE_EVENT_CATEGORY_GROUP_ENABLED("loading", &loading_enabled);
+  if (!loading_enabled)
+    return;
+  const page_load_metrics::ContentfulPaintTimingInfo& paint =
+      largest_contentful_paint_handler_.MergeMainFrameAndSubframes();
+  if (!paint.IsEmpty()) {
+    TRACE_EVENT_INSTANT1(
+        "loading",
+        "NavStartToLargestContentfulPaint::Candidate::AllFrames::UKM",
+        TRACE_EVENT_SCOPE_THREAD, "data", paint.DataAsTraceValue());
+  } else {
+    TRACE_EVENT_INSTANT0("loading",
+                         "NavStartToLargestContentfulPaint::"
+                         "Invalidate::AllFrames::UKM",
+                         TRACE_EVENT_SCOPE_THREAD);
+  }
 }
 
 void UkmPageLoadMetricsObserver::OnCpuTimingUpdate(

chrome/browser/page_load_metrics/observers/ukm_page_load_metrics_observer_unittest.cc

@@ -443,8 +443,8 @@ TEST_F(UkmPageLoadMetricsObserverTest, LargestContentPaint_Trace) {
   }
   auto analyzer = trace_analyzer::Stop();
   trace_analyzer::TraceEventVector events;
-  Query q =
-      Query::EventNameIs("NavStartToLargestContentfulPaint::AllFrames::UKM");
+  Query q = Query::EventNameIs(
+      "NavStartToLargestContentfulPaint::Candidate::AllFrames::UKM");
   analyzer->FindEvents(q, &events);
   EXPECT_EQ(1u, events.size());
   EXPECT_EQ("loading", events[0]->category);
@@ -464,6 +464,48 @@ TEST_F(UkmPageLoadMetricsObserverTest, LargestContentPaint_Trace) {
   EXPECT_EQ("text", type);
 }
 
+TEST_F(UkmPageLoadMetricsObserverTest,
+       LargestContentPaint_Trace_InvalidateCandidate) {
+  using trace_analyzer::Query;
+  trace_analyzer::Start("loading");
+  {
+    page_load_metrics::mojom::PageLoadTiming timing;
+    page_load_metrics::InitPageLoadTimingForTest(&timing);
+    timing.navigation_start = base::Time::FromDoubleT(1);
+    timing.paint_timing->largest_text_paint =
+        base::TimeDelta::FromMilliseconds(600);
+    timing.paint_timing->largest_text_paint_size = 1000;
+    PopulateRequiredTimingFields(&timing);
+
+    NavigateAndCommit(GURL(kTestUrl1));
+    SimulateTimingUpdate(timing);
+
+    timing.paint_timing->largest_text_paint = base::Optional<base::TimeDelta>();
+    timing.paint_timing->largest_text_paint_size = 0;
+    PopulateRequiredTimingFields(&timing);
+
+    SimulateTimingUpdate(timing);
+
+    // Simulate closing the tab.
+    DeleteContents();
+  }
+  auto analyzer = trace_analyzer::Stop();
+
+  trace_analyzer::TraceEventVector candidate_events;
+  Query candidate_query = Query::EventNameIs(
+      "NavStartToLargestContentfulPaint::Candidate::AllFrames::UKM");
+  analyzer->FindEvents(candidate_query, &candidate_events);
+  EXPECT_EQ(1u, candidate_events.size());
+
+  trace_analyzer::TraceEventVector invalidate_events;
+  Query invalidate_query = Query::EventNameIs(
+      "NavStartToLargestContentfulPaint::"
+      "Invalidate::AllFrames::UKM");
+  analyzer->FindEvents(invalidate_query, &invalidate_events);
+  EXPECT_EQ(1u, invalidate_events.size());
+  EXPECT_EQ("loading", invalidate_events[0]->category);
+}
+
 TEST_F(UkmPageLoadMetricsObserverTest, LargestContentPaint_OnlyText) {
   page_load_metrics::mojom::PageLoadTiming timing;
   page_load_metrics::InitPageLoadTimingForTest(&timing);