PageLoadMetricsObservers observe individual page loads

components/page_load_metrics/browser/metrics_web_contents_observer.cc

 // Copyright 2015 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "components/page_load_metrics/browser/metrics_web_contents_observer.h"
 
 #include "base/location.h"
 #include "base/logging.h"
 #include "base/metrics/histogram.h"
 #include "base/metrics/user_metrics.h"
@@ skipping 20 matching lines @@
 namespace {
 
 // The url we see from the renderer side is not always the same as what
 // we see from the browser side (e.g. chrome://newtab). We want to be
 // sure here that we aren't logging UMA for internal pages.
 bool IsRelevantNavigation(
     content::NavigationHandle* navigation_handle,
     const GURL& browser_url,
     const std::string& mime_type) {
   DCHECK(navigation_handle->HasCommitted());
   return navigation_handle->IsInMainFrame() &&

[Bryan McQuade, 2015/12/03 22:10:36]

I'm wondering if we should be including some or part of this logic in
page_load_metrics_util for the observers to use.

* the logic that decides if the browser_url is non-HTTPS? seems important for
filtering out NTP
* IsSamePage filtering seems important (do any observers want same page
navigations?)
* IsErrorPage seems like it might be important, though I guess all 3 current
observers filter on URL and thus should exclude these
* non-HTML filtering seems important

Do any of our current observers want to track stats for any of these types of
pages?

[Charlie Harrison, 2015/12/03 22:30:25]

Let's expose it when we need to, I don't think any of the current observers need
it. As is, the fact that PageLoadTiming information is / is not there is a proxy
for this. FYI I'm adding an additional check in the GoogleCaptcha observer for
same-page.

In general, I don't think any observer is going to have the same constraints, so
it's best to give them something that just works in the general case (timing
information), but has the necessary information for general purpose filters.

          !navigation_handle->IsSamePage() &&
          !navigation_handle->IsErrorPage() &&
          navigation_handle->GetURL().SchemeIsHTTPOrHTTPS() &&
          browser_url.SchemeIsHTTPOrHTTPS() &&
          (mime_type == "text/html" || mime_type == "application/xhtml+xml");
 }
 
 bool IsValidPageLoadTiming(const PageLoadTiming& timing) {
   if (timing.IsEmpty())
     return false;
@@ skipping 50 matching lines @@
   if (seconds < 32)
     return 4;
   return 5;
 }
 
 }  // namespace
 
 PageLoadTracker::PageLoadTracker(
     bool in_foreground,
     PageLoadMetricsEmbedderInterface* embedder_interface,
-    content::NavigationHandle* navigation_handle,
-    base::ObserverList<PageLoadMetricsObserver, true>* observers)
-    : has_commit_(false),
+    content::NavigationHandle* navigation_handle)
+    : renderer_tracked_(false),
+      has_commit_(false),
       navigation_start_(navigation_handle->NavigationStart()),
       started_in_foreground_(in_foreground),
-      embedder_interface_(embedder_interface),
-      observers_(observers) {}
+      embedder_interface_(embedder_interface) {
+  embedder_interface_->RegisterObservers(this);
+  for (const auto& observer : observers_) {
+    observer->OnStart(navigation_handle);
+  }
+}
 
 PageLoadTracker::~PageLoadTracker() {
   if (has_commit_) {
     RecordTimingHistograms();
     RecordRappor();
   }
+  PageLoadExtraInfo info = GetPageLoadMetricsInfo();
+  for (const auto& observer : observers_) {
+    observer->OnComplete(timing_, info);
+  }
 }
 
 void PageLoadTracker::WebContentsHidden() {
   // Only log the first time we background in a given page load.
   if (started_in_foreground_ && background_time_.is_null())
     background_time_ = base::TimeTicks::Now();
 }
 
 void PageLoadTracker::WebContentsShown() {
   // Only log the first time we foreground in a given page load.
   // Don't log foreground time if we started foregrounded.
   if (!started_in_foreground_ && foreground_time_.is_null())
     foreground_time_ = base::TimeTicks::Now();
 }
 
 void PageLoadTracker::Commit(content::NavigationHandle* navigation_handle) {
   has_commit_ = true;
   url_ = navigation_handle->GetURL();
   // We log the event that this load started. Because we don't know if a load is
   // relevant or if it will commit before now, we have to log this event at
   // commit time.
-  RecordCommittedEvent(COMMITTED_LOAD_STARTED, !started_in_foreground_);
+  if (renderer_tracked())
+    RecordCommittedEvent(RELEVANT_LOAD_STARTED, !started_in_foreground_);
 
-  FOR_EACH_OBSERVER(PageLoadMetricsObserver, *observers_,
-                    OnCommit(navigation_handle));
+  for (const auto& observer : observers_) {
+    observer->OnCommit(navigation_handle);
+  }
 }
 
 void PageLoadTracker::Redirect(content::NavigationHandle* navigation_handle) {
-  FOR_EACH_OBSERVER(PageLoadMetricsObserver, *observers_,
-                    OnRedirect(navigation_handle));
+  for (const auto& observer : observers_) {
+    observer->OnRedirect(navigation_handle);
+  }
 }
 
 bool PageLoadTracker::UpdateTiming(const PageLoadTiming& new_timing) {
   // Throw away IPCs that are not relevant to the current navigation.
   // Two timing structures cannot refer to the same navigation if they indicate
   // that a navigation started at different times, so a new timing struct with a
   // different start time from an earlier struct is considered invalid.
   bool valid_timing_descendent =
       timing_.navigation_start.is_null() ||
       timing_.navigation_start == new_timing.navigation_start;
   if (IsValidPageLoadTiming(new_timing) && valid_timing_descendent) {
     timing_ = new_timing;
     return true;
   }
   return false;
 }
 
 bool PageLoadTracker::HasBackgrounded() {
   return !started_in_foreground_ || !background_time_.is_null();
 }
 
+void PageLoadTracker::set_renderer_tracked(bool renderer_tracked) {
+  renderer_tracked_ = renderer_tracked;
+}
+
+void PageLoadTracker::AddObserver(
+    scoped_ptr<PageLoadMetricsObserver> observer) {
+  observers_.push_back(std::move(observer));
+}
+
 PageLoadExtraInfo PageLoadTracker::GetPageLoadMetricsInfo() {
   base::TimeDelta first_background_time;
   base::TimeDelta first_foreground_time;
   if (!background_time_.is_null() && started_in_foreground_)
     first_background_time = background_time_ - navigation_start_;
   if (!foreground_time_.is_null() && !started_in_foreground_)
     first_foreground_time = foreground_time_ - navigation_start_;
   return PageLoadExtraInfo(first_background_time, first_foreground_time,
-                           started_in_foreground_);
+                           started_in_foreground_, has_commit_);
 }
 
-const GURL& PageLoadTracker::GetCommittedURL() {
+const GURL& PageLoadTracker::committed_url() {
   DCHECK(has_commit_);
   return url_;
 }
 
 // Blink calculates navigation start using TimeTicks, but converts to epoch time
 // in its public API. Thus, to compare time values to navigation start, we
 // calculate the current time since the epoch using TimeTicks, and convert to
 // Time. This method is similar to how blink converts TimeTicks to epoch time.
 // There may be slight inaccuracies due to inter-process timestamps, but
 // this solution is the best we have right now.
 //
 // returns a TimeDelta which is
 //  - Infinity if we were never backgrounded
 //  - null (TimeDelta()) if we started backgrounded
 //  - elapsed time to first background if we started in the foreground and
 //    backgrounded.
 base::TimeDelta PageLoadTracker::GetBackgroundDelta() {
   if (started_in_foreground_) {
     return background_time_.is_null() ? base::TimeDelta::Max()
                                       : background_time_ - navigation_start_;
   }
   return base::TimeDelta();
 }
 
 void PageLoadTracker::RecordTimingHistograms() {
   DCHECK(has_commit_);
+  if (!renderer_tracked())
+    return;
+
   if (timing_.IsEmpty()) {
     RecordInternalError(ERR_NO_IPCS_RECEIVED);
     return;
   }
 
-  PageLoadExtraInfo info = GetPageLoadMetricsInfo();
-  FOR_EACH_OBSERVER(PageLoadMetricsObserver, *observers_,
-                    OnComplete(timing_, info));
-
   base::TimeDelta background_delta = GetBackgroundDelta();
 
   if (!timing_.dom_content_loaded_event_start.is_zero()) {
     if (timing_.dom_content_loaded_event_start < background_delta) {
       PAGE_LOAD_HISTOGRAM(kHistogramDomContentLoaded,
                           timing_.dom_content_loaded_event_start);
     } else {
       PAGE_LOAD_HISTOGRAM(kBackgroundHistogramDomContentLoaded,
                           timing_.dom_content_loaded_event_start);
     }
   }
   if (!timing_.load_event_start.is_zero()) {
     if (timing_.load_event_start < background_delta) {
       PAGE_LOAD_HISTOGRAM(kHistogramLoad, timing_.load_event_start);
     } else {
       PAGE_LOAD_HISTOGRAM(kBackgroundHistogramLoad, timing_.load_event_start);
     }
   }
   if (timing_.first_layout.is_zero()) {
-    RecordCommittedEvent(COMMITTED_LOAD_FAILED_BEFORE_FIRST_LAYOUT,
+    RecordCommittedEvent(RELEVANT_LOAD_FAILED_BEFORE_FIRST_LAYOUT,
                          HasBackgrounded());
   } else {
     if (timing_.first_layout < background_delta) {
       PAGE_LOAD_HISTOGRAM(kHistogramFirstLayout, timing_.first_layout);
-      RecordCommittedEvent(COMMITTED_LOAD_SUCCESSFUL_FIRST_LAYOUT, false);
+      RecordCommittedEvent(RELEVANT_LOAD_SUCCESSFUL_FIRST_LAYOUT, false);
     } else {
       PAGE_LOAD_HISTOGRAM(kBackgroundHistogramFirstLayout,
                           timing_.first_layout);
-      RecordCommittedEvent(COMMITTED_LOAD_SUCCESSFUL_FIRST_LAYOUT, true);
+      RecordCommittedEvent(RELEVANT_LOAD_SUCCESSFUL_FIRST_LAYOUT, true);
     }
   }
   if (!timing_.first_paint.is_zero()) {
     if (timing_.first_paint < background_delta) {
       PAGE_LOAD_HISTOGRAM(kHistogramFirstPaint, timing_.first_paint);
     } else {
       PAGE_LOAD_HISTOGRAM(kBackgroundHistogramFirstPaint, timing_.first_paint);
     }
   }
   if (!timing_.first_text_paint.is_zero()) {
@@ skipping 48 matching lines @@
                               PROVISIONAL_LOAD_LAST_ENTRY);
   } else {
     UMA_HISTOGRAM_ENUMERATION(kProvisionalEvents, event,
                               PROVISIONAL_LOAD_LAST_ENTRY);
   }
 }
 
 // RecordCommittedEvent needs a backgrounded input because we need to special
 // case a few events that need either precise timing measurements, or different
 // logic than simply "Did I background before logging this event?"
-void PageLoadTracker::RecordCommittedEvent(CommittedLoadEvent event,
+void PageLoadTracker::RecordCommittedEvent(CommittedRelevantLoadEvent event,
                                            bool backgrounded) {
   if (backgrounded) {
     UMA_HISTOGRAM_ENUMERATION(kBackgroundCommittedEvents, event,
-                              COMMITTED_LOAD_LAST_ENTRY);
+                              RELEVANT_LOAD_LAST_ENTRY);
   } else {
     UMA_HISTOGRAM_ENUMERATION(kCommittedEvents, event,
-                              COMMITTED_LOAD_LAST_ENTRY);
+                              RELEVANT_LOAD_LAST_ENTRY);
   }
 }
 
 void PageLoadTracker::RecordRappor() {
-  DCHECK(!GetCommittedURL().is_empty());
+  DCHECK(!committed_url().is_empty());
   rappor::RapporService* rappor_service =
       embedder_interface_->GetRapporService();
   if (!rappor_service)
     return;
   base::TimeDelta first_contentful_paint = GetFirstContentfulPaint(timing_);
   // Log the eTLD+1 of sites that show poor loading performance.
   if (!first_contentful_paint.is_zero() &&
       first_contentful_paint < GetBackgroundDelta()) {
     scoped_ptr<rappor::Sample> sample =
         rappor_service->CreateSample(rappor::UMA_RAPPOR_TYPE);
-    sample->SetStringField("Domain", rappor::GetDomainAndRegistrySampleFromGURL(
-                                         GetCommittedURL()));
+    sample->SetStringField(
+        "Domain", rappor::GetDomainAndRegistrySampleFromGURL(committed_url()));
     uint64_t bucket_index = RapporHistogramBucketIndex(first_contentful_paint);
     sample->SetFlagsField("Bucket", uint64_t(1) << bucket_index,
                           kNumRapporHistogramBuckets);
     // The IsSlow flag is just a one bit boolean if the first layout was > 10s.
     sample->SetFlagsField("IsSlow", first_contentful_paint.InSecondsF() >= 10,
                           1);
     rappor_service->RecordSampleObj(kRapporMetricsNameCoarseTiming,
                                      sample.Pass());
   }
 }
@@ skipping 13 matching lines @@
 
   MetricsWebContentsObserver* metrics = FromWebContents(web_contents);
   if (!metrics) {
     metrics =
         new MetricsWebContentsObserver(web_contents, embedder_interface.Pass());
     web_contents->SetUserData(UserDataKey(), metrics);
   }
   return metrics;
 }
 
-MetricsWebContentsObserver::~MetricsWebContentsObserver() {
-  // Reset PageLoadTrackers so observers get final notifications.
-  committed_load_.reset();
-  provisional_loads_.clear();
-  FOR_EACH_OBSERVER(PageLoadMetricsObserver, observers_,
-                    OnPageLoadMetricsGoingAway());
-}
-
-void MetricsWebContentsObserver::AddObserver(
-    PageLoadMetricsObserver* observer) {
-  observers_.AddObserver(observer);
-}
-
-void MetricsWebContentsObserver::RemoveObserver(
-    PageLoadMetricsObserver* observer) {
-  observers_.RemoveObserver(observer);
-}
+MetricsWebContentsObserver::~MetricsWebContentsObserver() {}
 
 bool MetricsWebContentsObserver::OnMessageReceived(
     const IPC::Message& message,
     content::RenderFrameHost* render_frame_host) {
   DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
   bool handled = true;
   IPC_BEGIN_MESSAGE_MAP_WITH_PARAM(MetricsWebContentsObserver, message,
                                    render_frame_host)
     IPC_MESSAGE_HANDLER(PageLoadMetricsMsg_TimingUpdated, OnTimingUpdated)
     IPC_MESSAGE_UNHANDLED(handled = false)
   IPC_END_MESSAGE_MAP()
   return handled;
 }
 
 void MetricsWebContentsObserver::DidStartNavigation(
     content::NavigationHandle* navigation_handle) {
   if (!navigation_handle->IsInMainFrame())
     return;
   if (embedder_interface_->IsPrerendering(web_contents()))
     return;
   // We can have two provisional loads in some cases. E.g. a same-site
   // navigation can have a concurrent cross-process navigation started
   // from the omnibox.
   DCHECK_GT(2ul, provisional_loads_.size());
   // Passing raw pointers to observers_ and embedder_interface_ is safe because
   // the MetricsWebContentsObserver owns them both list and they are torn down
   // after the PageLoadTracker.
   provisional_loads_.insert(std::make_pair(
-      navigation_handle, make_scoped_ptr(new PageLoadTracker(
-                             in_foreground_, embedder_interface_.get(),
-                             navigation_handle, &observers_))));
+      navigation_handle,
+      make_scoped_ptr(new PageLoadTracker(
+          in_foreground_, embedder_interface_.get(), navigation_handle))));
 }
 
 void MetricsWebContentsObserver::DidFinishNavigation(
     content::NavigationHandle* navigation_handle) {
   if (!navigation_handle->IsInMainFrame())
     return;
 
   scoped_ptr<PageLoadTracker> finished_nav(
       std::move(provisional_loads_[navigation_handle]));
   provisional_loads_.erase(navigation_handle);
@@ skipping 13 matching lines @@
         : error == net::ERR_ABORTED ? PROVISIONAL_LOAD_ERR_ABORTED
         : PROVISIONAL_LOAD_ERR_FAILED_NON_ABORT);
     return;
   }
   finished_nav->RecordProvisionalEvent(PROVISIONAL_LOAD_COMMITTED);
 
   // Don't treat a same-page nav as a new page load.
   if (navigation_handle->IsSamePage())
     return;
 
-  // Eagerly log the previous UMA even if we don't care about the current
-  // navigation.
-  committed_load_.reset();
+  committed_load_ = finished_nav.Pass();
 
   const GURL& browser_url = web_contents()->GetLastCommittedURL();
   const std::string& mime_type = web_contents()->GetContentsMimeType();
   DCHECK(!browser_url.is_empty());
   DCHECK(!mime_type.empty());
-  if (!IsRelevantNavigation(navigation_handle, browser_url, mime_type))
-    return;
+  committed_load_->set_renderer_tracked(
+      IsRelevantNavigation(navigation_handle, browser_url, mime_type));
 
-  committed_load_ = finished_nav.Pass();
   committed_load_->Commit(navigation_handle);
 }
 
 void MetricsWebContentsObserver::DidRedirectNavigation(
     content::NavigationHandle* navigation_handle) {
   if (!navigation_handle->IsInMainFrame())
     return;
   auto it = provisional_loads_.find(navigation_handle);
   if (it == provisional_loads_.end())
     return;
@@ skipping 23 matching lines @@
 // we have one.
 void MetricsWebContentsObserver::RenderProcessGone(
     base::TerminationStatus status) {
   committed_load_.reset();
 }
 
 void MetricsWebContentsObserver::OnTimingUpdated(
     content::RenderFrameHost* render_frame_host,
     const PageLoadTiming& timing) {
   bool error = false;
-  if (!committed_load_) {
-    RecordInternalError(ERR_IPC_WITH_NO_COMMITTED_LOAD);
+  if (!committed_load_ || !committed_load_->renderer_tracked()) {
+    RecordInternalError(ERR_IPC_WITH_NO_RELEVANT_LOAD);
     error = true;
   }
 
   // We may receive notifications from frames that have been navigated away
   // from. We simply ignore them.
   if (render_frame_host != web_contents()->GetMainFrame()) {
     RecordInternalError(ERR_IPC_FROM_WRONG_FRAME);
     error = true;
   }
 
@@ skipping 10 matching lines @@
 
   if (!committed_load_->UpdateTiming(timing)) {
     // If the page load tracker cannot update its timing, something is wrong
     // with the IPC (it's from another load, or it's invalid in some other way).
     // We expect this to be a rare occurrence.
     RecordInternalError(ERR_BAD_TIMING_IPC);
   }
 }
 
 }  // namespace page_load_metrics