Record first layout time UMA metric in PageLoadHistograms.

Record first layout time UMA metric in PageLoadHistograms.

Due to the issue described in crbug.com/382542, many histograms
intended to be logged by PageLoadHistograms do not get logged,
because fast shutdown kills processes before they get a chance
to log.

This patch logs first layout metrics earlier in the page life cycle,
in order to avoid losing these histograms.

BUG=507790
R=jochen,pmeenan,rdsmith

Committed: https://crrev.com/973721b2beff40e8fd2fd876e826e3cb1176f4f8
Cr-Commit-Position: refs/heads/master@{#338286}

[Bryan McQuade, 2015-07-08 20:48:27]

bmcquade@chromium.org changed reviewers:
+ jochen@chromium.org, pmeenan@chromium.org

[Bryan McQuade, 2015-07-08 20:48:27]

bmcquade@chromium.org changed required reviewers:
+ jochen@chromium.org

[Bryan McQuade, 2015-07-08 20:51:16]

bmcquade@chromium.org changed reviewers:
- pmeenan@chromium.org

[Bryan McQuade, 2015-07-09 18:45:00]

bmcquade@chromium.org changed reviewers:
+ pmeenan@chromium.org

[Bryan McQuade, 2015-07-09 18:45:00]

bmcquade@chromium.org changed required reviewers:
+ pmeenan@chromium.org

[Bryan McQuade, 2015-07-09 18:50:01]

bmcquade@chromium.org changed reviewers:
+ rdsmith@chromium.org

[Randy Smith (Not in Mondays), 2015-07-09 18:58:23]

As may be obvious, my responses will be confined to the abstract level--I don't
know this code :-}.

https://codereview.chromium.org/1230513002/diff/60001/chrome/renderer/page_lo...
File chrome/renderer/page_load_histograms.cc (right):

https://codereview.chromium.org/1230513002/diff/60001/chrome/renderer/page_lo...
chrome/renderer/page_load_histograms.cc:932: Time first_layout =
Time::FromDoubleT(performance.firstLayout());
There's no way to get a signal when first layout actually happens?  That seems
like the thing we want to hook; it's the earliest we can possibly get the
information we need.

[Bryan McQuade, 2015-07-09 19:10:42]

https://codereview.chromium.org/1230513002/diff/60001/chrome/renderer/page_lo...
File chrome/renderer/page_load_histograms.cc (right):

https://codereview.chromium.org/1230513002/diff/60001/chrome/renderer/page_lo...
chrome/renderer/page_load_histograms.cc:932: Time first_layout =
Time::FromDoubleT(performance.firstLayout());
Good question, yes. On the blink side, there's logic to record the timestamp of
the first layout in the WebPerformance object, which is the canonical source for
all document-related timings.

We want to use that when logging first layout time UMA, rather than recording
our own timestamp in a callback.

We do get a DidUpdateLayout callback (below) but because the source of truth for
all document timing information is the blink::WebPerformance object, we want to
use the timestamp recorded in the WebPerformance object as our canonical source
for first layout time.

I added a comment in DidUpdateLayout, below.

[Pat Meenan, 2015-07-09 19:29:28]

Other than the potential overhead, LGTM.  I'm assuming that first layout is
already correctly measured on the blink side since this is just reporting it.

https://codereview.chromium.org/1230513002/diff/80001/chrome/renderer/page_lo...
File chrome/renderer/page_load_histograms.cc (right):

https://codereview.chromium.org/1230513002/diff/80001/chrome/renderer/page_lo...
chrome/renderer/page_load_histograms.cc:960: void
PageLoadHistograms::DidUpdateLayout() {
Just a sanity check, but do you know what the overhead is for the observer? 
Given that layouts can happen fairly frequently and we really only care about
the first layout I'd like to make sure we're not adding a bunch of overhead to
every layout (just by the observer existing).

https://codereview.chromium.org/1230513002/diff/80001/chrome/renderer/page_lo...
chrome/renderer/page_load_histograms.cc:974: if (dumped_first_layout_histograms_
|| !ShouldDump(frame))
Maybe fast exit the dumped_first_layout_histograms_ first before acquiring the
main frame to avoid the extra work for subsequent layouts?

[Bryan McQuade, 2015-07-09 19:35:04]

https://codereview.chromium.org/1230513002/diff/80001/chrome/renderer/page_lo...
File chrome/renderer/page_load_histograms.cc (right):

https://codereview.chromium.org/1230513002/diff/80001/chrome/renderer/page_lo...
chrome/renderer/page_load_histograms.cc:960: void
PageLoadHistograms::DidUpdateLayout() {
Should just be a function call, which is already being dispatched to an empty
implementation of the base class RenderViewObserver::DidUpdateLayout(). So no
new overhead there.

I did make sure to abort this method once dumped_first_layout_histograms_  is
true, which means we won't continue to post new async tasks once we've recorded
the first layout time.

So overall, I don't think we're looking at any real additional overhead.

https://codereview.chromium.org/1230513002/diff/80001/chrome/renderer/page_lo...
chrome/renderer/page_load_histograms.cc:974: if (dumped_first_layout_histograms_
|| !ShouldDump(frame))
On 2015/07/09 19:29:27, Pat Meenan wrote:
> Maybe fast exit the dumped_first_layout_histograms_ first before acquiring the
> main frame to avoid the extra work for subsequent layouts?

Good idea, done.

[Randy Smith (Not in Mondays), 2015-07-09 21:35:23]

LGTM (though again, I don't really know renderer code).

[Bryan McQuade, 2015-07-09 22:14:58]

bmcquade@chromium.org changed reviewers:
+ asvitkine@chromium.org

[Bryan McQuade, 2015-07-09 22:15:24]

Adding asvitkine for histograms.xml.

[Bryan McQuade, 2015-07-10 00:44:49]

bmcquade@chromium.org changed required reviewers:
+ asvitkine@chromium.org

[jochen (gone - plz use gerrit), 2015-07-10 09:06:29]

lgtm

[Bryan McQuade, 2015-07-10 13:15:20]

bmcquade@chromium.org changed reviewers:
- asvitkine@chromium.org

[Bryan McQuade, 2015-07-10 13:15:20]

bmcquade@chromium.org changed required reviewers:
- asvitkine@chromium.org

[Bryan McQuade, 2015-07-10 13:18:10]

The CQ bit was checked by bmcquade@chromium.org

[Bryan McQuade, 2015-07-10 13:18:11]

The patchset sent to the CQ was uploaded after l-g-t-m from
pmeenan@chromium.org, rdsmith@chromium.org, jochen@chromium.org
Link to the patchset: https://codereview.chromium.org/1230513002/#ps180001
(title: "Move histograms.xml to separate change.")

[commit-bot: I haz the power, 2015-07-10 13:18:15]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1230513002/180001

[commit-bot: I haz the power, 2015-07-10 14:08:53]

Committed patchset #10 (id:180001)

[commit-bot: I haz the power, 2015-07-10 14:09:45]

Patchset 10 (id:??) landed as
https://crrev.com/973721b2beff40e8fd2fd876e826e3cb1176f4f8
Cr-Commit-Position: refs/heads/master@{#338286}