buffer cross-frame paint timing updates in browser process |
||||
Issue descriptionWe recently landed a few changes to move us closer to being able to merge cross-frame paint timings in the browser process: 1. zhenw@ fixed a bug where paint timings in child frames where reported in the top frame: https://bugs.chromium.org/p/chromium/issues/detail?id=705315 2. I landed a patch that merges paint timings for all frames in a page when reporting first paints to observers: https://codereview.chromium.org/2859393002 With this change we continue to report page-level first paints however the implementation is somewhat different: instead of merging timings in the render process (due to the bug zhen fixed) we now merge timings reported from different frames in the browser process. This should be a no-op but there is some risk for timings to arrive out of order - for example we might see: 1. main frame starts parsing 2. main frame sends initial timing update 3. main frame paints 4. main frame schedules a timer to send updated timing to browser process 5. child frame created 6. child frame paints 7. child frame sends initial timing update 8. main frame dispatches timing update In this case, the browser will most likely receive the paint message for the child frame first, even though the main frame painted first. I expected this to be rare, but metrics suggest that this happens more than I had hoped - it affects about 4% of pages, adding on average 370ms for affected pages, increasing mean TTFP by 15ms across all page loads (on canary, anyway). So I think we need to fix this, given that it adds a significant delay to mean paint timings. Observers only want their First*PaintInPage callbacks to be invoked once per page. So if we know that we sometimes receive per-frame first paints out of order, unless we want to complicate observers to understand that this can happen, we probably want to buffer timing updates in the browser process, at the PageLoadTracker level, for a period before dispatching to observers, so we are able to wait to dispatch the real/correct first paint times to observers. We already have some logic in the browser to buffer timing updates that we know are received out of order before dispatching them to observers. If for example we receive a first paint in a child frame before we'e received first parse in the main frame, we buffer the paint update until we've received the parse update, since observers reasonably assume we can't paint without having started parsing. I believe what we need to do here is also buffer paint timing updates for a period of time before dispatching to observers, in case we receive subsequent updates for a paint that happened earlier in the page. The UMA suggests that a delay of 1s is reasonable - this makes sense since this is our buffering timer delay in the render process. So I will plan to buffer paint updates for 1s: when we receive our first first paint of a given type (e.g. FP, FCP, FMP, etc) across all frames in the page, we will set a timer for 1s, and dispatch the most recently received PageLoadTiming during that 1s to observers once the timer fires. This allows us to receive out of order updates that arrive up to 1s late, and still report the right page level information to observers. I'll add UMA to see how much this corrects the issue & we can tune the timeout accordingly.
,
May 31 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/a49b11bb29ce7018da6f440703ec983009c98cc5 commit a49b11bb29ce7018da6f440703ec983009c98cc5 Author: Mathieu Perreault <mathp@chromium.org> Date: Wed May 31 14:22:04 2017 Revert "Buffer cross frame paint timing updates." This reverts commit 457de7596c43cbce74ea3cbae7d9ab1e93fe9d5a. Suspected for browsertest failures: https://build.chromium.org/p/chromium.win/builders/Win7%20Tests%20%28dbg%29%281%29/builds/60448 TBR=isherman,mattcary,csharrison Bug: 726387 Change-Id: I323c25a19a9ab62cea2bdd313329661f1bdd43d8 Reviewed-on: https://chromium-review.googlesource.com/519363 Reviewed-by: Mathieu Perreault <mathp@chromium.org> Reviewed-by: Charles Harrison <csharrison@chromium.org> Commit-Queue: Mathieu Perreault <mathp@chromium.org> Cr-Commit-Position: refs/heads/master@{#475903} [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/browser/page_load_metrics/metrics_web_contents_observer.cc [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/browser/page_load_metrics/metrics_web_contents_observer.h [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/browser/page_load_metrics/metrics_web_contents_observer_unittest.cc [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/browser/page_load_metrics/observers/page_load_metrics_observer_test_harness.cc [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/browser/page_load_metrics/observers/page_load_metrics_observer_test_harness.h [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/browser/page_load_metrics/page_load_metrics_embedder_interface.h [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/browser/page_load_metrics/page_load_metrics_initialize.cc [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/browser/page_load_metrics/page_load_metrics_update_dispatcher.cc [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/browser/page_load_metrics/page_load_metrics_update_dispatcher.h [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/browser/page_load_metrics/page_load_metrics_util.cc [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/browser/page_load_metrics/page_load_metrics_util.h [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/browser/page_load_metrics/page_load_tracker.cc [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/browser/prerender/prerender_browsertest.cc [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/common/BUILD.gn [delete] https://crrev.com/93fdbfecc3703f4b1459d8dec0fb412ed508f90a/chrome/common/page_load_metrics/page_load_metrics_util.cc [delete] https://crrev.com/93fdbfecc3703f4b1459d8dec0fb412ed508f90a/chrome/common/page_load_metrics/page_load_metrics_util.h [delete] https://crrev.com/93fdbfecc3703f4b1459d8dec0fb412ed508f90a/chrome/common/page_load_metrics/test/page_load_metrics_test_util.cc [delete] https://crrev.com/93fdbfecc3703f4b1459d8dec0fb412ed508f90a/chrome/common/page_load_metrics/test/page_load_metrics_test_util.h [delete] https://crrev.com/93fdbfecc3703f4b1459d8dec0fb412ed508f90a/chrome/common/page_load_metrics/test/weak_mock_timer.cc [delete] https://crrev.com/93fdbfecc3703f4b1459d8dec0fb412ed508f90a/chrome/common/page_load_metrics/test/weak_mock_timer.h [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/renderer/page_load_metrics/metrics_render_frame_observer.cc [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/renderer/page_load_metrics/metrics_render_frame_observer.h [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/renderer/page_load_metrics/metrics_render_frame_observer_unittest.cc [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/chrome/test/BUILD.gn [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/tools/metrics/histograms/enums.xml [modify] https://crrev.com/a49b11bb29ce7018da6f440703ec983009c98cc5/tools/metrics/histograms/histograms.xml
,
May 31 2017
,
May 31 2017
,
Jun 2 2017
|
||||
►
Sign in to add a comment |
||||
Comment 1 by bugdroid1@chromium.org
, May 31 2017