Metrics for document.write script blocking

chrome/browser/page_load_metrics/observers/document_write_page_load_metrics_observer.cc

Index: chrome/browser/page_load_metrics/observers/document_write_page_load_metrics_observer.cc
diff --git a/chrome/browser/page_load_metrics/observers/document_write_page_load_metrics_observer.cc b/chrome/browser/page_load_metrics/observers/document_write_page_load_metrics_observer.cc
index a26c8bad2a62f972d48d0c19460bb9ee02090aec..499d812a8e715fb2937e98bf3fc20110227b112b 100644
--- a/chrome/browser/page_load_metrics/observers/document_write_page_load_metrics_observer.cc
+++ b/chrome/browser/page_load_metrics/observers/document_write_page_load_metrics_observer.cc
@@ -41,6 +41,43 @@ const char kBackgroundHistogramDocWriteParseBlockedOnScriptLoadDocumentWrite[] =
     "PageLoad.Clients.DocWrite.Evaluator.Timing2."
     "ParseBlockedOnScriptLoadFromDocumentWrite.Background";
 
+// document.write blocking histograms
+const char kHistogramDocWriteBlockParseStartToFirstContentfulPaint[] =
+    "PageLoad.Clients.DocWrite.Block.Timing2.ParseStartToFirstContentfulPaint";
+const char kHistogramDocWriteBlockParseBlockedOnScript[] =
+    "PageLoad.Clients.DocWrite.Block.Timing2.ParseBlockedOnScriptLoad";
+const char kHistogramDocWriteBlockParseBlockedOnScriptLoadDocumentWrite[] =
+    "PageLoad.Clients.DocWrite.Block.Timing2."
+    "ParseBlockedOnScriptLoadFromDocumentWrite";
+const char kHistogramDocWriteBlockParseDuration[] =
+    "PageLoad.Clients.DocWrite.Block.Timing2.ParseDuration";
+const char kHistogramDocWriteBlockParseBlockedOnScriptParseComplete[] =
+    "PageLoad.Clients.DocWrite.Block.Timing2.ParseBlockedOnScriptLoad."
+    "ParseComplete";
+const char
+    kHistogramDocWriteBlockParseBlockedOnScriptLoadDocumentWriteParseComplete
+        [] = "PageLoad.Clients.DocWrite.Block.Timing2."
+             "ParseBlockedOnScriptLoadFromDocumentWrite.ParseComplete";
+const char kHistogramDocWriteBlockReloads[] =
+    "PageLoad.Clients.DocWrite.Block.Reloads";

[Bryan McQuade, 2016/04/27 14:29:24]

let's update this to ReloadCount as well

[shivanisha, 2016/04/27 15:34:38]

My bad. Sure. Updated.

+
+const char kBackgroundHistogramDocWriteBlockParseBlockedOnScript[] =
+    "PageLoad.Clients.DocWrite.Block.Timing2.ParseBlockedOnScriptLoad."
+    "Background";
+const char kBackgroundHistogramDocWriteBlockParseBlockedOnScriptComplete[] =
+    "PageLoad.Clients.DocWrite.Block.Timing2.ParseBlockedOnScriptLoad."
+    "ParseComplete.Background";
+const char
+    kBackgroundHistogramDocWriteBlockParseBlockedOnScriptLoadDocumentWrite[] =
+        "PageLoad.Clients.DocWrite.Block.Timing2."
+        "ParseBlockedOnScriptLoadFromDocumentWrite.Background";
+const char
+    kBackgroundHistogramDocWriteBlockParseBlockedOnScriptLoadDocWriteComplete
+        [] = "PageLoad.Clients.DocWrite.Block.Timing2."
+             "ParseBlockedOnScriptLoadFromDocumentWrite.ParseComplete."
+             "Background";
+const char kBackgroundHistogramDocWriteBlockParseDuration[] =
+    "PageLoad.Clients.DocWrite.Block.Timing2.ParseDuration.Background";
 }  // namespace internal
 
 DocumentWritePageLoadMetricsObserver::DocumentWritePageLoadMetricsObserver() {}
@@ -54,6 +91,15 @@ void DocumentWritePageLoadMetricsObserver::OnComplete(
       blink::WebLoadingBehaviorFlag::WebLoadingBehaviorDocumentWriteEvaluator) {
     LogDocumentWriteEvaluatorData(timing, info);
   }
+  if (info.metadata.behavior_flags &
+      blink::WebLoadingBehaviorFlag::WebLoadingBehaviorDocumentWriteBlock) {
+    LogDocumentWriteBlockData(timing, info);
+  }
+  if (info.metadata.behavior_flags &
+      blink::WebLoadingBehaviorFlag::
+          WebLoadingBehaviorDocumentWriteBlockReload) {

[jkarlin, 2016/04/27 14:28:16]

DCHECK(!info.metadata.behavior_flags &
blink::WebLoadingBehaviorFlag::WebLoadingBehaviorDocumentWriteBlock) to verify
that on reload we don't block stuff.

[shivanisha, 2016/04/27 15:34:38]

Done.

+    UMA_HISTOGRAM_COUNTS(internal::kHistogramDocWriteBlockReloads, 1);
+  }
 }
 
 void DocumentWritePageLoadMetricsObserver::LogDocumentWriteEvaluatorData(
@@ -78,11 +124,7 @@ void DocumentWritePageLoadMetricsObserver::LogDocumentWriteEvaluatorData(
           timing.first_contentful_paint - timing.parse_start);
     }
 
-    const bool incomplete_parse_in_foreground =
-        timing.parse_stop.is_zero() && info.started_in_foreground &&
-        info.first_background_time.is_zero();
-    if (incomplete_parse_in_foreground ||
-        WasStartedInForegroundEventInForeground(timing.parse_stop, info)) {
+    if (WasParseInForeground(timing.parse_start, timing.parse_stop, info)) {
       PAGE_LOAD_HISTOGRAM(internal::kHistogramDocWriteParseBlockedOnScript,
                           timing.parse_blocked_on_script_load_duration);
       PAGE_LOAD_HISTOGRAM(
@@ -118,3 +160,62 @@ void DocumentWritePageLoadMetricsObserver::LogDocumentWriteEvaluatorData(
     }
   }
 }
+
+void DocumentWritePageLoadMetricsObserver::LogDocumentWriteBlockData(
+    const page_load_metrics::PageLoadTiming& timing,
+    const page_load_metrics::PageLoadExtraInfo& info) {
+  // Parse started.
+  if (!timing.parse_start.is_zero()) {

[jkarlin, 2016/04/27 14:28:16]

Rather than wrap the whole thing in this condition, prefer:

if (timing.parse_start.is_zero())
  return;

[shivanisha, 2016/04/27 15:34:38]

Good point. done.

+    if (WasStartedInForegroundEventInForeground(timing.first_contentful_paint,
+                                                info)) {
+      PAGE_LOAD_HISTOGRAM(
+          internal::kHistogramDocWriteBlockParseStartToFirstContentfulPaint,
+          timing.first_contentful_paint - timing.parse_start);
+    }
+
+    if (WasParseInForeground(timing.parse_start, timing.parse_stop, info)) {
+      PAGE_LOAD_HISTOGRAM(internal::kHistogramDocWriteBlockParseBlockedOnScript,
+                          timing.parse_blocked_on_script_load_duration);
+      PAGE_LOAD_HISTOGRAM(
+          internal::
+              kHistogramDocWriteBlockParseBlockedOnScriptLoadDocumentWrite,
+          timing.parse_blocked_on_script_load_from_document_write_duration);
+    } else {
+      PAGE_LOAD_HISTOGRAM(
+          internal::kBackgroundHistogramDocWriteBlockParseBlockedOnScript,
+          timing.parse_blocked_on_script_load_duration);
+      PAGE_LOAD_HISTOGRAM(
+          internal::
+              kBackgroundHistogramDocWriteBlockParseBlockedOnScriptLoadDocumentWrite,
+          timing.parse_blocked_on_script_load_from_document_write_duration);
+    }
+
+    // Parse completed.
+    if (!timing.parse_stop.is_zero()) {

[jkarlin, 2016/04/27 14:28:16]

Could early return here if parsing hasn't completed, up to you.

[shivanisha, 2016/04/27 15:34:38]

done

+      base::TimeDelta parse_duration = timing.parse_stop - timing.parse_start;
+      if (WasStartedInForegroundEventInForeground(timing.parse_stop, info)) {
+        PAGE_LOAD_HISTOGRAM(internal::kHistogramDocWriteBlockParseDuration,
+                            parse_duration);
+        PAGE_LOAD_HISTOGRAM(
+            internal::kHistogramDocWriteBlockParseBlockedOnScriptParseComplete,
+            timing.parse_blocked_on_script_load_duration);
+        PAGE_LOAD_HISTOGRAM(
+            internal::
+                kHistogramDocWriteBlockParseBlockedOnScriptLoadDocumentWriteParseComplete,
+            timing.parse_blocked_on_script_load_from_document_write_duration);
+      } else {
+        PAGE_LOAD_HISTOGRAM(
+            internal::kBackgroundHistogramDocWriteBlockParseDuration,
+            parse_duration);
+        PAGE_LOAD_HISTOGRAM(
+            internal::
+                kBackgroundHistogramDocWriteBlockParseBlockedOnScriptComplete,
+            timing.parse_blocked_on_script_load_duration);
+        PAGE_LOAD_HISTOGRAM(
+            internal::
+                kBackgroundHistogramDocWriteBlockParseBlockedOnScriptLoadDocWriteComplete,
+            timing.parse_blocked_on_script_load_from_document_write_duration);
+      }
+    }
+  }
+}