[LCP] Check tracing enabled before tracing

Currently TextPaintTimingDetector and ImagePaintTimingDetector dumps a
trace event whenever it finds a new candidate. However, the event won't
not be generated when the "loading" category is disabled. When we have
any preparation cost for the trace event, the cost would be wasted in
this case.

For this reason, we add a check in this change. We check whether the
event category is enabled before preparing the trace value.

In addition, we whitelist trace_event_analyzer.cc for blink tests
so that we can test the code path of enabling/disabling the trace
category.

Bug:976894,978475

Change-Id: Ibca63be435f7f96b2bad64fa3aaffe2df8ba232e
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1676230Reviewed-by: Liquan (Max) Gu <maxlg@chromium.org>
Reviewed-by: Jeremy Roman <jbroman@chromium.org>
Reviewed-by: Xianzhu Wang <wangxianzhu@chromium.org>
Commit-Queue: Liquan (Max) Gu <maxlg@chromium.org>
Cr-Commit-Position: refs/heads/master@{#672258}

third_party/blink/renderer/core/paint/DEPS

@@ -10,5 +10,8 @@ specific_include_rules = {
   "(theme_painter|fallback_theme)\.cc": [
     "+ui/native_theme/native_theme.h",
     "+ui/native_theme/native_theme_base.h",
+  ],
+  ".*test\.cc": [
+    "+base/test/trace_event_analyzer.h",
   ]
 }

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

@@ -91,6 +91,8 @@ void ImagePaintTimingDetector::PopulateTraceValue(
 
 void ImagePaintTimingDetector::ReportCandidateToTrace(
     ImageRecord& largest_image_record) {
+  if (!PaintTimingDetector::IsTracing())
+    return;
   DCHECK(!largest_image_record.paint_time.is_null());
   auto value = std::make_unique<TracedValue>();
   PopulateTraceValue(*value, largest_image_record);
@@ -101,6 +103,8 @@ void ImagePaintTimingDetector::ReportCandidateToTrace(
 }
 
 void ImagePaintTimingDetector::ReportNoCandidateToTrace() {
+  if (!PaintTimingDetector::IsTracing())
+    return;
   auto value = std::make_unique<TracedValue>();
   value->SetInteger("candidateIndex", ++count_candidates_);
   value->SetBoolean("isMainFrame", frame_view_->GetFrame().IsMainFrame());
@@ -123,7 +127,7 @@ void ImagePaintTimingDetector::UpdateCandidate() {
   bool changed = detector.NotifyIfChangedLargestImagePaint(time, size);
   if (!changed)
     return;
-  if (largest_image_record && !largest_image_record->paint_time.is_null()) {
+  if (!time.is_null()) {
     if (auto* lcp_calculator = detector.GetLargestContentfulPaintCalculator())
       lcp_calculator->OnLargestImageUpdated(largest_image_record);
     // If an image has paint time, it must have been loaded.

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

@@ -6,6 +6,7 @@
 
 #include "base/bind.h"
 #include "base/test/test_mock_time_task_runner.h"
+#include "base/test/trace_event_analyzer.h"
 #include "build/build_config.h"
 #include "third_party/blink/public/platform/web_url_loader_mock_factory.h"
 #include "third_party/blink/public/web/web_performance.h"
@@ -231,6 +232,97 @@ TEST_F(ImagePaintTimingDetectorTest, LargestImagePaint_OneImage) {
   EXPECT_TRUE(record->loaded);
 }
 
+TEST_F(ImagePaintTimingDetectorTest, LargestImagePaint_TraceEvent_Candidate) {
+  using trace_analyzer::Query;
+  trace_analyzer::Start("loading");
+  {
+    SetBodyInnerHTML(R"HTML(
+      <img id="target"></img>
+    )HTML");
+    SetImageAndPaint("target", 5, 5);
+    UpdateAllLifecyclePhasesAndInvokeCallbackIfAny();
+  }
+  auto analyzer = trace_analyzer::Stop();
+  trace_analyzer::TraceEventVector events;
+  Query q = Query::EventNameIs("LargestImagePaint::Candidate");
+  analyzer->FindEvents(q, &events);
+  EXPECT_EQ(1u, events.size());
+  EXPECT_EQ("loading", events[0]->category);
+
+  EXPECT_TRUE(events[0]->HasArg("frame"));
+
+  EXPECT_TRUE(events[0]->HasArg("data"));
+  std::unique_ptr<base::Value> arg;
+  EXPECT_TRUE(events[0]->GetArgAsValue("data", &arg));
+  base::DictionaryValue* arg_dict;
+  EXPECT_TRUE(arg->GetAsDictionary(&arg_dict));
+  DOMNodeId node_id;
+  EXPECT_TRUE(arg_dict->GetInteger("DOMNodeId", &node_id));
+  EXPECT_GT(node_id, 0);
+  int size;
+  EXPECT_TRUE(arg_dict->GetInteger("size", &size));
+  EXPECT_GT(size, 0);
+  DOMNodeId candidate_index;
+  EXPECT_TRUE(arg_dict->GetInteger("candidateIndex", &candidate_index));
+  EXPECT_EQ(candidate_index, 2);
+  bool isMainFrame;
+  EXPECT_TRUE(arg_dict->GetBoolean("isMainFrame", &isMainFrame));
+  EXPECT_EQ(true, isMainFrame);
+  bool isOOPIF;
+  EXPECT_TRUE(arg_dict->GetBoolean("isOOPIF", &isOOPIF));
+  EXPECT_EQ(false, isOOPIF);
+}
+
+TEST_F(ImagePaintTimingDetectorTest, LargestImagePaint_TraceEvent_NoCandidate) {
+  using trace_analyzer::Query;
+  trace_analyzer::Start("*");
+  {
+    SetBodyInnerHTML(R"HTML(
+      <img id="target"></img>
+    )HTML");
+    SetImageAndPaint("target", 5, 5);
+    UpdateAllLifecyclePhasesAndInvokeCallbackIfAny();
+    GetDocument().getElementById("target")->remove();
+    UpdateAllLifecyclePhasesForTest();
+  }
+  auto analyzer = trace_analyzer::Stop();
+  trace_analyzer::TraceEventVector events;
+  Query q = Query::EventNameIs("LargestImagePaint::NoCandidate");
+  analyzer->FindEvents(q, &events);
+  EXPECT_EQ(2u, events.size());
+
+  {
+    EXPECT_EQ("loading", events[0]->category);
+    EXPECT_TRUE(events[0]->HasArg("frame"));
+    EXPECT_TRUE(events[0]->HasArg("data"));
+    std::unique_ptr<base::Value> arg;
+    EXPECT_TRUE(events[0]->GetArgAsValue("data", &arg));
+    base::DictionaryValue* arg_dict;
+    EXPECT_TRUE(arg->GetAsDictionary(&arg_dict));
+    DOMNodeId candidate_index;
+    EXPECT_TRUE(arg_dict->GetInteger("candidateIndex", &candidate_index));
+    EXPECT_EQ(candidate_index, 1);
+    bool is_main_frame;
+    EXPECT_TRUE(arg_dict->GetBoolean("isMainFrame", &is_main_frame));
+    EXPECT_EQ(true, is_main_frame);
+    bool is_oopif;
+    EXPECT_TRUE(arg_dict->GetBoolean("isOOPIF", &is_oopif));
+    EXPECT_EQ(false, is_oopif);
+  }
+
+  // Use block to reuse the temp variable names.
+  {
+    EXPECT_TRUE(events[1]->HasArg("data"));
+    std::unique_ptr<base::Value> arg;
+    EXPECT_TRUE(events[1]->GetArgAsValue("data", &arg));
+    base::DictionaryValue* arg_dict;
+    EXPECT_TRUE(arg->GetAsDictionary(&arg_dict));
+    DOMNodeId candidate_index;
+    EXPECT_TRUE(arg_dict->GetInteger("candidateIndex", &candidate_index));
+    EXPECT_EQ(candidate_index, 3);
+  }
+}
+
 TEST_F(ImagePaintTimingDetectorTest, UpdatePerformanceTiming) {
   const PerformanceTiming& performance_timing = GetPerformanceTiming();
   EXPECT_EQ(performance_timing.LargestImagePaintSize(), 0u);

third_party/blink/renderer/core/paint/paint_timing_detector.h

@@ -62,6 +62,12 @@ class CORE_EXPORT PaintTimingDetector
 
   void DidChangePerformanceTiming();
 
+  inline static bool IsTracing() {
+    bool tracing_enabled;
+    TRACE_EVENT_CATEGORY_GROUP_ENABLED("loading", &tracing_enabled);
+    return tracing_enabled;
+  }
+
   FloatRect CalculateVisualRect(const IntRect& visual_rect,
                                 const PropertyTreeState&) const;
 

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

@@ -62,10 +62,10 @@ void LargestTextPaintManager::PopulateTraceValue(
 
 void LargestTextPaintManager::ReportCandidateToTrace(
     const TextRecord& largest_text_record) {
+  if (!PaintTimingDetector::IsTracing())
+    return;
   auto value = std::make_unique<TracedValue>();
   PopulateTraceValue(*value, largest_text_record);
-  // TODO(crbug.com/976894): Check if the event is needed before preparing the
-  // trace value.
   TRACE_EVENT_MARK_WITH_TIMESTAMP2("loading", "LargestTextPaint::Candidate",
                                    largest_text_record.paint_time, "data",
                                    std::move(value), "frame",
@@ -73,6 +73,8 @@ void LargestTextPaintManager::ReportCandidateToTrace(
 }
 
 void LargestTextPaintManager::ReportNoCandidateToTrace() {
+  if (!PaintTimingDetector::IsTracing())
+    return;
   auto value = std::make_unique<TracedValue>();
   value->SetInteger("candidateIndex", ++count_candidates_);
   value->SetBoolean("isMainFrame", frame_view_->GetFrame().IsMainFrame());
@@ -95,7 +97,7 @@ void LargestTextPaintManager::UpdateCandidate() {
   if (!changed)
     return;
 
-  if (largest_text_record && !largest_text_record->paint_time.is_null()) {
+  if (!time.is_null()) {
     if (auto* lcp_calculator =
             paint_timing_detector_->GetLargestContentfulPaintCalculator())
       lcp_calculator->OnLargestTextUpdated(largest_text_record);

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

@@ -5,6 +5,7 @@
 #include "third_party/blink/renderer/core/paint/text_paint_timing_detector.h"
 
 #include "base/test/test_mock_time_task_runner.h"
+#include "base/test/trace_event_analyzer.h"
 #include "third_party/blink/renderer/core/paint/paint_timing_detector.h"
 #include "third_party/blink/renderer/core/svg/svg_text_content_element.h"
 #include "third_party/blink/renderer/core/testing/core_unit_test_helper.h"
@@ -172,6 +173,82 @@ TEST_F(TextPaintTimingDetectorTest, LargestTextPaint_OneText) {
             DOMNodeIds::ExistingIdForNode(only_text));
 }
 
+TEST_F(TextPaintTimingDetectorTest, LargestTextPaint_TraceEvent_Candidate) {
+  using trace_analyzer::Query;
+  trace_analyzer::Start("*");
+  {
+    SetBodyInnerHTML(R"HTML(
+      )HTML");
+    AppendDivElementToBody("The only text");
+    UpdateAllLifecyclePhasesAndSimulateSwapTime();
+  }
+  auto analyzer = trace_analyzer::Stop();
+  trace_analyzer::TraceEventVector events;
+  Query q = Query::EventNameIs("LargestTextPaint::Candidate");
+  analyzer->FindEvents(q, &events);
+  EXPECT_EQ(1u, events.size());
+  EXPECT_EQ("loading", events[0]->category);
+
+  EXPECT_TRUE(events[0]->HasArg("frame"));
+
+  EXPECT_TRUE(events[0]->HasArg("data"));
+  std::unique_ptr<base::Value> arg;
+  EXPECT_TRUE(events[0]->GetArgAsValue("data", &arg));
+  base::DictionaryValue* arg_dict;
+  EXPECT_TRUE(arg->GetAsDictionary(&arg_dict));
+  DOMNodeId node_id;
+  EXPECT_TRUE(arg_dict->GetInteger("DOMNodeId", &node_id));
+  EXPECT_GT(node_id, 0);
+  int size;
+  EXPECT_TRUE(arg_dict->GetInteger("size", &size));
+  EXPECT_GT(size, 0);
+  DOMNodeId candidate_index;
+  EXPECT_TRUE(arg_dict->GetInteger("candidateIndex", &candidate_index));
+  EXPECT_EQ(candidate_index, 1);
+  bool is_main_frame;
+  EXPECT_TRUE(arg_dict->GetBoolean("isMainFrame", &is_main_frame));
+  EXPECT_EQ(true, is_main_frame);
+  bool is_oopif;
+  EXPECT_TRUE(arg_dict->GetBoolean("isOOPIF", &is_oopif));
+  EXPECT_EQ(false, is_oopif);
+}
+
+TEST_F(TextPaintTimingDetectorTest, LargestTextPaint_TraceEvent_NoCandidate) {
+  using trace_analyzer::Query;
+  trace_analyzer::Start("*");
+  {
+    SetBodyInnerHTML(R"HTML(
+      )HTML");
+    Element* element = AppendDivElementToBody("text");
+    UpdateAllLifecyclePhasesAndSimulateSwapTime();
+    RemoveElement(element);
+    UpdateAllLifecyclePhasesForTest();
+  }
+  auto analyzer = trace_analyzer::Stop();
+  trace_analyzer::TraceEventVector events;
+  Query q = Query::EventNameIs("LargestTextPaint::NoCandidate");
+  analyzer->FindEvents(q, &events);
+  EXPECT_EQ(1u, events.size());
+  EXPECT_EQ("loading", events[0]->category);
+
+  EXPECT_TRUE(events[0]->HasArg("frame"));
+
+  EXPECT_TRUE(events[0]->HasArg("data"));
+  std::unique_ptr<base::Value> arg;
+  EXPECT_TRUE(events[0]->GetArgAsValue("data", &arg));
+  base::DictionaryValue* arg_dict;
+  EXPECT_TRUE(arg->GetAsDictionary(&arg_dict));
+  DOMNodeId candidate_index;
+  EXPECT_TRUE(arg_dict->GetInteger("candidateIndex", &candidate_index));
+  EXPECT_EQ(candidate_index, 2);
+  bool is_main_frame;
+  EXPECT_TRUE(arg_dict->GetBoolean("isMainFrame", &is_main_frame));
+  EXPECT_EQ(true, is_main_frame);
+  bool is_oopif;
+  EXPECT_TRUE(arg_dict->GetBoolean("isOOPIF", &is_oopif));
+  EXPECT_EQ(false, is_oopif);
+}
+
 TEST_F(TextPaintTimingDetectorTest, AggregationBySelfPaintingInlineElement) {
   SetBodyInnerHTML(R"HTML(
     <div style="background: yellow">