Factor management of metrics updates into its own class.

chrome/browser/page_load_metrics/page_load_tracker.cc

 // Copyright 2016 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 "chrome/browser/page_load_metrics/page_load_tracker.h"
 
 #include <algorithm>
 #include <ostream>
 #include <string>
 #include <utility>
 
 #include "base/logging.h"
 #include "base/memory/ptr_util.h"
 #include "base/metrics/histogram_macros.h"
-#include "chrome/browser/page_load_metrics/browser_page_track_decider.h"
 #include "chrome/browser/page_load_metrics/page_load_metrics_embedder_interface.h"
 #include "chrome/browser/page_load_metrics/page_load_metrics_util.h"
 #include "chrome/browser/prerender/prerender_contents.h"
 #include "chrome/common/page_load_metrics/page_load_timing.h"
 #include "content/public/browser/navigation_details.h"
 #include "content/public/browser/navigation_handle.h"
 #include "content/public/browser/render_frame_host.h"
 #include "content/public/browser/web_contents.h"
 #include "content/public/browser/web_contents_observer.h"
-#include "content/public/common/browser_side_navigation_policy.h"
 #include "ui/base/page_transition_types.h"
 
 // This macro invokes the specified method on each observer, passing the
 // variable length arguments as the method's arguments, and removes the observer
 // from the list of observers if the given method returns STOP_OBSERVING.
 #define INVOKE_AND_PRUNE_OBSERVERS(observers, Method, ...)    \
   for (auto it = observers.begin(); it != observers.end();) { \
     if ((*it)->Method(__VA_ARGS__) ==                         \
         PageLoadMetricsObserver::STOP_OBSERVING) {            \
       it = observers.erase(it);                               \
@@ skipping 19 matching lines @@
     "PageLoad.Internal.ProvisionalAbortChainSize.NoCommit";
 const char kClientRedirectFirstPaintToNavigation[] =
     "PageLoad.Internal.ClientRedirect.FirstPaintToNavigation";
 const char kClientRedirectWithoutPaint[] =
     "PageLoad.Internal.ClientRedirect.NavigationWithoutPaint";
 const char kPageLoadCompletedAfterAppBackground[] =
     "PageLoad.Internal.PageLoadCompleted.AfterAppBackground";
 const char kPageLoadStartedInForeground[] =
     "PageLoad.Internal.NavigationStartedInForeground";
 const char kPageLoadPrerender[] = "PageLoad.Internal.Prerender";
-const char kPageLoadTimingStatus[] = "PageLoad.Internal.PageLoadTimingStatus";
-const char kPageLoadTimingDispatchStatus[] =
-    "PageLoad.Internal.PageLoadTimingStatus.AtTimingCallbackDispatch";
 
 }  // namespace internal
 
 void RecordInternalError(InternalErrorLoadEvent event) {
   UMA_HISTOGRAM_ENUMERATION(internal::kErrorEvents, event, ERR_LAST_ENTRY);
 }
 
 // TODO(csharrison): Add a case for client side redirects, which is what JS
 // initiated window.location / window.history navigations get set to.
 PageEndReason EndReasonForPageTransition(ui::PageTransition transition) {
@@ skipping 26 matching lines @@
   //
   // TODO(crbug.com/637345): Some browser-initiated navigations incorrectly
   // report that they are renderer-initiated. We will currently report that
   // these navigations are not user initiated, when in fact they are user
   // initiated.
   return handle->HasUserGesture() || !handle->IsRendererInitiated();
 }
 
 namespace {
 
-// Helper to allow use of Optional<> values in LOG() messages.
-std::ostream& operator<<(std::ostream& os,
-                         const base::Optional<base::TimeDelta>& opt) {
-  if (opt)
-    os << opt.value();
-  else
-    os << "(unset)";
-  return os;
-}
-
-// If second is non-zero, first must also be non-zero and less than or equal to
-// second.
-bool EventsInOrder(const base::Optional<base::TimeDelta>& first,
-                   const base::Optional<base::TimeDelta>& second) {
-  if (!second) {
-    return true;
-  }
-  return first && first <= second;
-}
-
-internal::PageLoadTimingStatus IsValidPageLoadTiming(
-    const mojom::PageLoadTiming& timing) {
-  if (page_load_metrics::IsEmpty(timing))
-    return internal::INVALID_EMPTY_TIMING;
-
-  // If we have a non-empty timing, it should always have a navigation start.
-  if (timing.navigation_start.is_null()) {
-    LOG(ERROR) << "Received null navigation_start.";
-    return internal::INVALID_NULL_NAVIGATION_START;
-  }
-
-  // Verify proper ordering between the various timings.
-
-  if (!EventsInOrder(timing.response_start, timing.parse_timing->parse_start)) {
-    // We sometimes get a zero response_start with a non-zero parse start. See
-    // crbug.com/590212.
-    LOG(ERROR) << "Invalid response_start " << timing.response_start
-               << " for parse_start " << timing.parse_timing->parse_start;
-    // When browser-side navigation is enabled, we sometimes encounter this
-    // error case. For now, we disable reporting of this error, since most
-    // PageLoadMetricsObservers don't care about response_start and we want to
-    // see how much closer fixing this error will get us to page load metrics
-    // being consistent with and without browser side navigation enabled. See
-    // crbug.com/716587 for more details.
-    //
-    // return internal::INVALID_ORDER_RESPONSE_START_PARSE_START;
-  }
-
-  if (!EventsInOrder(timing.parse_timing->parse_start,
-                     timing.parse_timing->parse_stop)) {
-    LOG(ERROR) << "Invalid parse_start " << timing.parse_timing->parse_start
-               << " for parse_stop " << timing.parse_timing->parse_stop;
-    return internal::INVALID_ORDER_PARSE_START_PARSE_STOP;
-  }
-
-  if (timing.parse_timing->parse_stop) {
-    const base::TimeDelta parse_duration =
-        timing.parse_timing->parse_stop.value() -
-        timing.parse_timing->parse_start.value();
-    if (timing.parse_timing->parse_blocked_on_script_load_duration >
-        parse_duration) {
-      LOG(ERROR) << "Invalid parse_blocked_on_script_load_duration "
-                 << timing.parse_timing->parse_blocked_on_script_load_duration
-                 << " for parse duration " << parse_duration;
-      return internal::INVALID_SCRIPT_LOAD_LONGER_THAN_PARSE;
-    }
-    if (timing.parse_timing->parse_blocked_on_script_execution_duration >
-        parse_duration) {
-      LOG(ERROR)
-          << "Invalid parse_blocked_on_script_execution_duration "
-          << timing.parse_timing->parse_blocked_on_script_execution_duration
-          << " for parse duration " << parse_duration;
-      return internal::INVALID_SCRIPT_EXEC_LONGER_THAN_PARSE;
-    }
-  }
-
-  if (timing.parse_timing
-          ->parse_blocked_on_script_load_from_document_write_duration >
-      timing.parse_timing->parse_blocked_on_script_load_duration) {
-    LOG(ERROR)
-        << "Invalid parse_blocked_on_script_load_from_document_write_duration "
-        << timing.parse_timing
-               ->parse_blocked_on_script_load_from_document_write_duration
-        << " for parse_blocked_on_script_load_duration "
-        << timing.parse_timing->parse_blocked_on_script_load_duration;
-    return internal::INVALID_SCRIPT_LOAD_DOC_WRITE_LONGER_THAN_SCRIPT_LOAD;
-  }
-
-  if (timing.parse_timing
-          ->parse_blocked_on_script_execution_from_document_write_duration >
-      timing.parse_timing->parse_blocked_on_script_execution_duration) {
-    LOG(ERROR)
-        << "Invalid "
-           "parse_blocked_on_script_execution_from_document_write_duration "
-        << timing.parse_timing
-               ->parse_blocked_on_script_execution_from_document_write_duration
-        << " for parse_blocked_on_script_execution_duration "
-        << timing.parse_timing->parse_blocked_on_script_execution_duration;
-    return internal::INVALID_SCRIPT_EXEC_DOC_WRITE_LONGER_THAN_SCRIPT_EXEC;
-  }
-
-  if (!EventsInOrder(timing.parse_timing->parse_stop,
-                     timing.document_timing->dom_content_loaded_event_start)) {
-    LOG(ERROR) << "Invalid parse_stop " << timing.parse_timing->parse_stop
-               << " for dom_content_loaded_event_start "
-               << timing.document_timing->dom_content_loaded_event_start;
-    return internal::INVALID_ORDER_PARSE_STOP_DOM_CONTENT_LOADED;
-  }
-
-  if (!EventsInOrder(timing.document_timing->dom_content_loaded_event_start,
-                     timing.document_timing->load_event_start)) {
-    LOG(ERROR) << "Invalid dom_content_loaded_event_start "
-               << timing.document_timing->dom_content_loaded_event_start
-               << " for load_event_start "
-               << timing.document_timing->load_event_start;
-    return internal::INVALID_ORDER_DOM_CONTENT_LOADED_LOAD;
-  }
-
-  if (!EventsInOrder(timing.parse_timing->parse_start,
-                     timing.document_timing->first_layout)) {
-    LOG(ERROR) << "Invalid parse_start " << timing.parse_timing->parse_start
-               << " for first_layout " << timing.document_timing->first_layout;
-    return internal::INVALID_ORDER_PARSE_START_FIRST_LAYOUT;
-  }
-
-  if (!EventsInOrder(timing.document_timing->first_layout,
-                     timing.paint_timing->first_paint)) {
-    // This can happen when we process an XHTML document that doesn't contain
-    // well formed XML. See crbug.com/627607.
-    DLOG(ERROR) << "Invalid first_layout "
-                << timing.document_timing->first_layout << " for first_paint "
-                << timing.paint_timing->first_paint;
-    return internal::INVALID_ORDER_FIRST_LAYOUT_FIRST_PAINT;
-  }
-
-  if (!EventsInOrder(timing.paint_timing->first_paint,
-                     timing.paint_timing->first_text_paint)) {
-    LOG(ERROR) << "Invalid first_paint " << timing.paint_timing->first_paint
-               << " for first_text_paint "
-               << timing.paint_timing->first_text_paint;
-    return internal::INVALID_ORDER_FIRST_PAINT_FIRST_TEXT_PAINT;
-  }
-
-  if (!EventsInOrder(timing.paint_timing->first_paint,
-                     timing.paint_timing->first_image_paint)) {
-    LOG(ERROR) << "Invalid first_paint " << timing.paint_timing->first_paint
-               << " for first_image_paint "
-               << timing.paint_timing->first_image_paint;
-    return internal::INVALID_ORDER_FIRST_PAINT_FIRST_IMAGE_PAINT;
-  }
-
-  if (!EventsInOrder(timing.paint_timing->first_paint,
-                     timing.paint_timing->first_contentful_paint)) {
-    LOG(ERROR) << "Invalid first_paint " << timing.paint_timing->first_paint
-               << " for first_contentful_paint "
-               << timing.paint_timing->first_contentful_paint;
-    return internal::INVALID_ORDER_FIRST_PAINT_FIRST_CONTENTFUL_PAINT;
-  }
-
-  if (!EventsInOrder(timing.paint_timing->first_paint,
-                     timing.paint_timing->first_meaningful_paint)) {
-    LOG(ERROR) << "Invalid first_paint " << timing.paint_timing->first_paint
-               << " for first_meaningful_paint "
-               << timing.paint_timing->first_meaningful_paint;
-    return internal::INVALID_ORDER_FIRST_PAINT_FIRST_MEANINGFUL_PAINT;
-  }
-
-  return internal::VALID;
-}
-
-// Updates *|inout_existing_value| with |optional_candidate_new_value|, if
-// either *|inout_existing_value| isn't set, or |optional_candidate_new_value| <
-// |inout_existing_value|.
-void MaybeUpdateTimeDelta(
-    base::Optional<base::TimeDelta>* inout_existing_value,
-    base::TimeDelta navigation_start_offset,
-    const base::Optional<base::TimeDelta>& optional_candidate_new_value) {
-  // If we don't get a new value, there's nothing to do
-  if (!optional_candidate_new_value)
-    return;
-
-  // optional_candidate_new_value is relative to navigation start in its
-  // frame. We need to adjust it to be relative to navigation start in the main
-  // frame, so offset it by navigation_start_offset.
-  base::TimeDelta candidate_new_value =
-      navigation_start_offset + optional_candidate_new_value.value();
-
-  if (*inout_existing_value) {
-    // If we have a new value, but it is after the existing value, then keep the
-    // existing value.
-    if (*inout_existing_value <= candidate_new_value)
-      return;
-
-    // We received a new timing event, but with a timestamp before the timestamp
-    // of a timing update we had received previously. We expect this to happen
-    // occasionally, as inter-frame updates can arrive out of order. Record a
-    // histogram to track how frequently it happens, along with the magnitude
-    // of the delta.
-    PAGE_LOAD_HISTOGRAM("PageLoad.Internal.OutOfOrderInterFrameTiming",
-                        inout_existing_value->value() - candidate_new_value);
-  }
-
-  *inout_existing_value = candidate_new_value;
-}
-
 void RecordAppBackgroundPageLoadCompleted(bool completed_after_background) {
   UMA_HISTOGRAM_BOOLEAN(internal::kPageLoadCompletedAfterAppBackground,
                         completed_after_background);
 }
 
 void DispatchObserverTimingCallbacks(
     PageLoadMetricsObserver* observer,
     const mojom::PageLoadTiming& last_timing,
     const mojom::PageLoadTiming& new_timing,
-    const mojom::PageLoadMetadata& last_metadata,
     const PageLoadExtraInfo& extra_info) {
-  if (extra_info.main_frame_metadata.behavior_flags !=
-      last_metadata.behavior_flags)
-    observer->OnLoadingBehaviorObserved(extra_info);
   if (!last_timing.Equals(new_timing))
     observer->OnTimingUpdate(new_timing, extra_info);
   if (new_timing.document_timing->dom_content_loaded_event_start &&
       !last_timing.document_timing->dom_content_loaded_event_start)
     observer->OnDomContentLoadedEventStart(new_timing, extra_info);
   if (new_timing.document_timing->load_event_start &&
       !last_timing.document_timing->load_event_start)
     observer->OnLoadEventStart(new_timing, extra_info);
   if (new_timing.document_timing->first_layout &&
       !last_timing.document_timing->first_layout)
@@ skipping 33 matching lines @@
     int aborted_chain_size_same_url)
     : did_stop_tracking_(false),
       app_entered_background_(false),
       navigation_start_(navigation_handle->NavigationStart()),
       url_(navigation_handle->GetURL()),
       start_url_(navigation_handle->GetURL()),
       did_commit_(false),
       page_end_reason_(END_NONE),
       page_end_user_initiated_info_(UserInitiatedInfo::NotUserInitiated()),
       started_in_foreground_(in_foreground),
-      merged_page_timing_(CreatePageLoadTiming()),
       last_dispatched_merged_page_timing_(CreatePageLoadTiming()),
-      last_dispatched_main_frame_metadata_(mojom::PageLoadMetadata::New()),
       page_transition_(navigation_handle->GetPageTransition()),
       user_initiated_info_(user_initiated_info),
       aborted_chain_size_(aborted_chain_size),
       aborted_chain_size_same_url_(aborted_chain_size_same_url),
-      embedder_interface_(embedder_interface) {
+      embedder_interface_(embedder_interface),
+      metrics_update_dispatcher_(this, navigation_handle, embedder_interface) {
   DCHECK(!navigation_handle->HasCommitted());
   embedder_interface_->RegisterObservers(this);
   INVOKE_AND_PRUNE_OBSERVERS(observers_, OnStart, navigation_handle,
                              currently_committed_url, started_in_foreground_);
 
   UMA_HISTOGRAM_BOOLEAN(internal::kPageLoadStartedInForeground,
                         started_in_foreground_);
   const bool is_prerender = prerender::PrerenderContents::FromWebContents(
                                 navigation_handle->GetWebContents()) != nullptr;
   if (is_prerender) {
@@ skipping 22 matching lines @@
     if (!failed_provisional_load_info_)
       RecordInternalError(ERR_NO_COMMIT_OR_FAILED_PROVISIONAL_LOAD);
 
     // Don't include any aborts that resulted in a new navigation, as the chain
     // length will be included in the aborter PageLoadTracker.
     if (page_end_reason_ != END_RELOAD &&
         page_end_reason_ != END_FORWARD_BACK &&
         page_end_reason_ != END_NEW_NAVIGATION) {
       LogAbortChainHistograms(nullptr);
     }
-  } else if (page_load_metrics::IsEmpty(*merged_page_timing_)) {
+  } else if (page_load_metrics::IsEmpty(metrics_update_dispatcher_.timing())) {
     RecordInternalError(ERR_NO_IPCS_RECEIVED);
   }
 
   const PageLoadExtraInfo info = ComputePageLoadExtraInfo();
   for (const auto& observer : observers_) {
     if (failed_provisional_load_info_) {
       observer->OnFailedProvisionalLoad(*failed_provisional_load_info_, info);
     } else if (did_commit_) {
-      observer->OnComplete(*merged_page_timing_, info);
+      observer->OnComplete(metrics_update_dispatcher_.timing(), info);
     }
   }
 }
 
 void PageLoadTracker::LogAbortChainHistograms(
     content::NavigationHandle* final_navigation) {
   if (aborted_chain_size_ == 0)
     return;
   // Note that this could be broken out by this navigation's abort type, if more
   // granularity is needed. Add one to the chain size to count the current
@@ skipping 46 matching lines @@
   // Only log the first time we background in a given page load.
   if (background_time_.is_null()) {
     // Make sure we either started in the foreground and haven't been
     // foregrounded yet, or started in the background and have already been
     // foregrounded.
     DCHECK_EQ(started_in_foreground_, foreground_time_.is_null());
     background_time_ = base::TimeTicks::Now();
     ClampBrowserTimestampIfInterProcessTimeTickSkew(&background_time_);
   }
   const PageLoadExtraInfo info = ComputePageLoadExtraInfo();
-  INVOKE_AND_PRUNE_OBSERVERS(observers_, OnHidden, *merged_page_timing_, info);
+  INVOKE_AND_PRUNE_OBSERVERS(observers_, OnHidden,
+                             metrics_update_dispatcher_.timing(), info);
 }
 
 void PageLoadTracker::WebContentsShown() {
   // Only log the first time we foreground in a given page load.
   if (foreground_time_.is_null()) {
     // Make sure we either started in the background and haven't been
     // backgrounded yet, or started in the foreground and have already been
     // backgrounded.
     DCHECK_NE(started_in_foreground_, background_time_.is_null());
     foreground_time_ = base::TimeTicks::Now();
@@ skipping 30 matching lines @@
   for (const auto& observer : observers_) {
     observer->OnCommitSameDocumentNavigation(navigation_handle);
   }
 }
 
 void PageLoadTracker::DidFinishSubFrameNavigation(
     content::NavigationHandle* navigation_handle) {
   for (const auto& observer : observers_) {
     observer->OnDidFinishSubFrameNavigation(navigation_handle);
   }
-
-  if (!navigation_handle->HasCommitted())
-    return;
-
-  // We have a new committed navigation, so discard information about the
-  // previously committed navigation.
-  subframe_navigation_start_offset_.erase(
-      navigation_handle->GetFrameTreeNodeId());
-
-  BrowserPageTrackDecider decider(embedder_interface_,
-                                  navigation_handle->GetWebContents(),
-                                  navigation_handle);
-  if (!decider.ShouldTrack())
-    return;
-
-  if (navigation_start_ > navigation_handle->NavigationStart()) {
-    RecordInternalError(ERR_SUBFRAME_NAVIGATION_START_BEFORE_MAIN_FRAME);
-    return;
-  }
-  base::TimeDelta navigation_delta =
-      navigation_handle->NavigationStart() - navigation_start_;
-  subframe_navigation_start_offset_.insert(std::make_pair(
-      navigation_handle->GetFrameTreeNodeId(), navigation_delta));
+  metrics_update_dispatcher_.DidFinishSubFrameNavigation(navigation_handle);
 }
 
 void PageLoadTracker::FailedProvisionalLoad(
     content::NavigationHandle* navigation_handle,
     base::TimeTicks failed_load_time) {
   DCHECK(!failed_provisional_load_info_);
   failed_provisional_load_info_.reset(new FailedProvisionalLoadInfo(
       failed_load_time - navigation_handle->NavigationStart(),
       navigation_handle->GetNetErrorCode()));
 }
@@ skipping 11 matching lines @@
 }
 
 void PageLoadTracker::FlushMetricsOnAppEnterBackground() {
   if (!app_entered_background_) {
     RecordAppBackgroundPageLoadCompleted(false);
     app_entered_background_ = true;
   }
 
   const PageLoadExtraInfo info = ComputePageLoadExtraInfo();
   INVOKE_AND_PRUNE_OBSERVERS(observers_, FlushMetricsOnAppEnterBackground,
-                             *merged_page_timing_, info);
+                             metrics_update_dispatcher_.timing(), info);
 }
 
 void PageLoadTracker::NotifyClientRedirectTo(
     const PageLoadTracker& destination) {
-  if (merged_page_timing_->paint_timing->first_paint) {
+  if (metrics_update_dispatcher_.timing().paint_timing->first_paint) {
     base::TimeTicks first_paint_time =
         navigation_start() +
-        merged_page_timing_->paint_timing->first_paint.value();
+        metrics_update_dispatcher_.timing().paint_timing->first_paint.value();
     base::TimeDelta first_paint_to_navigation;
     if (destination.navigation_start() > first_paint_time)
       first_paint_to_navigation =
           destination.navigation_start() - first_paint_time;
     PAGE_LOAD_HISTOGRAM(internal::kClientRedirectFirstPaintToNavigation,
                         first_paint_to_navigation);
   } else {
     UMA_HISTOGRAM_BOOLEAN(internal::kClientRedirectWithoutPaint, true);
   }
 }
 
-void PageLoadTracker::UpdateSubFrameTiming(
-    content::RenderFrameHost* render_frame_host,
-    const mojom::PageLoadTiming& new_timing,
-    const mojom::PageLoadMetadata& new_metadata) {
-  UpdateSubFrameMetadata(new_metadata);
-  const auto it = subframe_navigation_start_offset_.find(
-      render_frame_host->GetFrameTreeNodeId());
-  if (it == subframe_navigation_start_offset_.end()) {
-    // We received timing information for an untracked load. Ignore it.
-    return;
-  }
-
-  base::TimeDelta navigation_start_offset = it->second;
-  MergePaintTiming(navigation_start_offset, *(new_timing.paint_timing),
-                   false /* is_main_frame */);
-
-  DispatchTimingUpdates();
-}
-
-void PageLoadTracker::MergePaintTiming(
-    base::TimeDelta navigation_start_offset,
-    const mojom::PaintTiming& new_paint_timing,
-    bool is_main_frame) {
-  MaybeUpdateTimeDelta(&merged_page_timing_->paint_timing->first_paint,
-                       navigation_start_offset, new_paint_timing.first_paint);
-  MaybeUpdateTimeDelta(&merged_page_timing_->paint_timing->first_text_paint,
-                       navigation_start_offset,
-                       new_paint_timing.first_text_paint);
-  MaybeUpdateTimeDelta(&merged_page_timing_->paint_timing->first_image_paint,
-                       navigation_start_offset,
-                       new_paint_timing.first_image_paint);
-  MaybeUpdateTimeDelta(
-      &merged_page_timing_->paint_timing->first_contentful_paint,
-      navigation_start_offset, new_paint_timing.first_contentful_paint);
-  if (is_main_frame) {
-    // first meaningful paint is only tracked in the main frame.
-    merged_page_timing_->paint_timing->first_meaningful_paint =
-        new_paint_timing.first_meaningful_paint;
-  }
-}
-
-void PageLoadTracker::UpdateSubFrameMetadata(
-    const mojom::PageLoadMetadata& subframe_metadata) {
-  // Merge the subframe loading behavior flags with any we've already observed,
-  // possibly from other subframes.
-  const int last_subframe_loading_behavior_flags =
-      subframe_metadata_.behavior_flags;
-  subframe_metadata_.behavior_flags |= subframe_metadata.behavior_flags;
-  if (last_subframe_loading_behavior_flags == subframe_metadata_.behavior_flags)
-    return;
-
-  PageLoadExtraInfo extra_info(ComputePageLoadExtraInfo());
-  for (const auto& observer : observers_) {
-    observer->OnLoadingBehaviorObserved(extra_info);
-  }
-}
-
 void PageLoadTracker::UpdateTiming(
+    content::RenderFrameHost* render_frame_host,
     const mojom::PageLoadTiming& new_timing,
     const mojom::PageLoadMetadata& new_metadata) {
-  // 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.
-  const bool valid_timing_descendent =
-      merged_page_timing_->navigation_start.is_null() ||
-      merged_page_timing_->navigation_start == new_timing.navigation_start;
-  if (!valid_timing_descendent) {
-    RecordInternalError(ERR_BAD_TIMING_IPC_INVALID_TIMING_DESCENDENT);
-    return;
-  }
-
-  // Ensure flags sent previously are still present in the new metadata fields.
-  const bool valid_behavior_descendent =
-      (main_frame_metadata_.behavior_flags & new_metadata.behavior_flags) ==
-      main_frame_metadata_.behavior_flags;
-  if (!valid_behavior_descendent) {
-    RecordInternalError(ERR_BAD_TIMING_IPC_INVALID_BEHAVIOR_DESCENDENT);
-    return;
-  }
-  internal::PageLoadTimingStatus status = IsValidPageLoadTiming(new_timing);
-  UMA_HISTOGRAM_ENUMERATION(internal::kPageLoadTimingStatus, status,
-                            internal::LAST_PAGE_LOAD_TIMING_STATUS);
-  if (status != internal::VALID) {
-    RecordInternalError(ERR_BAD_TIMING_IPC_INVALID_TIMING);
-    return;
-  }
-
   DCHECK(did_commit_);  // OnCommit() must be called first.
-  // There are some subtle ordering constraints here. GetPageLoadMetricsInfo()
-  // must be called before DispatchObserverTimingCallbacks, but its
-  // implementation depends on the state of main_frame_metadata_, so we need
-  // to update main_frame_metadata_ before calling GetPageLoadMetricsInfo.
-  // Thus, we make a copy of timing here, update merged_page_timing_ and
-  // main_frame_metadata_, and then proceed to dispatch the observer timing
-  // callbacks.
-  const mojom::PaintTimingPtr last_paint_timing =
-      std::move(merged_page_timing_->paint_timing);
-
-  // Update the merged_page_timing_, making sure to merge the previously
-  // observed |paint_timing|, which is tracked across all frames in the page.
-  merged_page_timing_ = new_timing.Clone();
-  merged_page_timing_->paint_timing = last_paint_timing.Clone();
-  MergePaintTiming(base::TimeDelta(), *new_timing.paint_timing,
-                   true /* is_main_frame */);
-
-  main_frame_metadata_ = new_metadata;
-
-  DispatchTimingUpdates();
-}
-
-void PageLoadTracker::DispatchTimingUpdates() {
-  if (last_dispatched_merged_page_timing_->Equals(*merged_page_timing_) &&
-      last_dispatched_main_frame_metadata_->Equals(main_frame_metadata_)) {
-    return;
-  }
-
-  if (merged_page_timing_->paint_timing->first_paint) {
-    if (!merged_page_timing_->parse_timing->parse_start ||
-        !merged_page_timing_->document_timing->first_layout) {
-      // When merging paint events across frames, we can sometimes encounter
-      // cases where we've received a first paint event for a child frame before
-      // receiving required earlier events in the main frame, due to buffering
-      // in the render process which results in out of order delivery. For
-      // example, we may receive a notification for a first paint in a child
-      // frame before we've received a notification for parse start or first
-      // layout in the main frame. In these cases, we delay sending timing
-      // updates until we've received all expected events (e.g. wait to receive
-      // a parse or layout event before dispatching a paint event), so observers
-      // can make assumptions about ordering of these events in their callbacks.
-      return;
-    }
-  }
-
-  internal::PageLoadTimingStatus status =
-      IsValidPageLoadTiming(*merged_page_timing_);
-  UMA_HISTOGRAM_ENUMERATION(internal::kPageLoadTimingDispatchStatus, status,
-                            internal::LAST_PAGE_LOAD_TIMING_STATUS);
-
-  const PageLoadExtraInfo info = ComputePageLoadExtraInfo();
-  for (const auto& observer : observers_) {
-    DispatchObserverTimingCallbacks(
-        observer.get(), *last_dispatched_merged_page_timing_,
-        *merged_page_timing_, *last_dispatched_main_frame_metadata_, info);
-  }
-  last_dispatched_merged_page_timing_ = merged_page_timing_->Clone();
-  last_dispatched_main_frame_metadata_ = main_frame_metadata_.Clone();
+  metrics_update_dispatcher_.UpdateMetrics(render_frame_host, new_timing,
+                                           new_metadata);
 }
 
 void PageLoadTracker::OnStartedResource(
     const ExtraRequestStartInfo& extra_request_start_info) {
   for (const auto& observer : observers_) {
     observer->OnStartedResource(extra_request_start_info);
   }
 }
 
 void PageLoadTracker::OnLoadedResource(
@@ skipping 33 matching lines @@
     DCHECK(event_time->is_null() || *event_time >= navigation_start_);
     return;
   }
 
   if (!event_time->is_null() && *event_time < navigation_start_) {
     RecordInternalError(ERR_INTER_PROCESS_TIME_TICK_SKEW);
     *event_time = navigation_start_;
   }
 }
 
-PageLoadExtraInfo PageLoadTracker::ComputePageLoadExtraInfo() {
+PageLoadExtraInfo PageLoadTracker::ComputePageLoadExtraInfo() const {
   base::Optional<base::TimeDelta> first_background_time;
   base::Optional<base::TimeDelta> first_foreground_time;
   base::Optional<base::TimeDelta> page_end_time;
 
   if (!background_time_.is_null()) {
     DCHECK_GE(background_time_, navigation_start_);
     first_background_time = background_time_ - navigation_start_;
   }
 
   if (!foreground_time_.is_null()) {
@@ skipping 11 matching lines @@
   // page_end_reason_ == END_NONE implies page_end_user_initiated_info_ is not
   // user initiated.
   DCHECK(page_end_reason_ != END_NONE ||
          (!page_end_user_initiated_info_.browser_initiated &&
           !page_end_user_initiated_info_.user_gesture &&
           !page_end_user_initiated_info_.user_input_event));
   return PageLoadExtraInfo(
       navigation_start_, first_background_time, first_foreground_time,
       started_in_foreground_, user_initiated_info_, url(), start_url_,
       did_commit_, page_end_reason_, page_end_user_initiated_info_,
-      page_end_time, main_frame_metadata_, subframe_metadata_);
+      page_end_time, metrics_update_dispatcher_.main_frame_metadata(),
+      metrics_update_dispatcher_.subframe_metadata());
 }
 
 bool PageLoadTracker::HasMatchingNavigationRequestID(
     const content::GlobalRequestID& request_id) const {
   DCHECK(request_id != content::GlobalRequestID());
   return navigation_request_id_.has_value() &&
          navigation_request_id_.value() == request_id;
 }
 
 void PageLoadTracker::NotifyPageEnd(PageEndReason page_end_reason,
@@ skipping 87 matching lines @@
   for (const auto& observer : observers_)
     observer->MediaStartedPlaying(video_type, is_in_main_frame);
 }
 
 void PageLoadTracker::OnNavigationDelayComplete(base::TimeDelta scheduled_delay,
                                                 base::TimeDelta actual_delay) {
   for (const auto& observer : observers_)
     observer->OnNavigationDelayComplete(scheduled_delay, actual_delay);
 }
 
+void PageLoadTracker::OnTimingChanged() {
+  if (last_dispatched_merged_page_timing_->Equals(

[Charlie Harrison, 2017/05/23 20:32:10]

Can we DCHECK this somehow? It seems like something that the dispatcher should
be doing for us.

[Bryan McQuade, 2017/05/23 20:50:36]

Agree, done.

+          metrics_update_dispatcher_.timing())) {
+    return;
+  }
+
+  PageLoadExtraInfo extra_info(ComputePageLoadExtraInfo());
+  for (const auto& observer : observers_) {
+    DispatchObserverTimingCallbacks(
+        observer.get(), *last_dispatched_merged_page_timing_,
+        metrics_update_dispatcher_.timing(), extra_info);
+  }
+  last_dispatched_merged_page_timing_ =
+      metrics_update_dispatcher_.timing().Clone();
+}
+
+void PageLoadTracker::OnMainFrameMetadataChanged() {
+  PageLoadExtraInfo extra_info(ComputePageLoadExtraInfo());
+  for (const auto& observer : observers_) {
+    observer->OnLoadingBehaviorObserved(extra_info);
+  }
+}
+
+void PageLoadTracker::OnSubframeMetadataChanged() {
+  PageLoadExtraInfo extra_info(ComputePageLoadExtraInfo());
+  for (const auto& observer : observers_) {
+    observer->OnLoadingBehaviorObserved(extra_info);
+  }
+}
+
 }  // namespace page_load_metrics