A different approach to fixing FirstWebContentsProfiler with PlzNavigate.

A different approach to fixing FirstWebContentsProfiler with PlzNavigate.

The previous fix depended on ensuring we add hooks to all the code paths that cause the first active WebContents to get added to the tab strip. We're still missing some code paths. So instead restore the old behavior. Even though it did miss navigation starts, fix that by using the time from NavigationHandle for PlzNavigate.

This should restore the metrics for non-PlzNavigate case.
For PlzNavigate, the start timings were already different regardless from non-PlzNavigate because of how navigations are structured very differently. This change shouldn't affects things too much for PlzNavigate though, because the only difference should be the IPC time from the renderer to the browser thread.

BUG=650349
Committed: https://crrev.com/f4ba53f555685c67fc3fb4ffdb18c4ff7baea19c
Cr-Commit-Position: refs/heads/master@{#427144}

[jam, 2016-10-24 17:27:04]

The CQ bit was checked by jam@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2016-10-24 17:27:34]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2016-10-24 18:03:41]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2016-10-24 18:03:42]

Dry run: Try jobs failed on following builders:
  win_chromium_x64_rel_ng on master.tryserver.chromium.win (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.win/builders/win_chromium_x64_...)

[jam, 2016-10-24 18:19:50]

Description was changed from

==========
debug firstwebcontentsprofiler

BUG=
==========

to

==========
A different approach to fixing FirstWebContentsProfiler with PlzNavigate.

The previous fix depended on ensuring we add hooks to all the code paths that
cause the first active WebContents to get added to the tab strip. We're still
missing some code paths. So instead restore the old behavior. Even though it did
miss navigation starts, fix that by using the time from NavigationHandle for
PlzNavigate.

This should restore the metrics for non-PlzNavigate case.
For PlzNavigate, the start timings were already different regardless from
non-PlzNavigate because of how navigations are structured very differently. This
change shouldn't affects things too much for PlzNavigate though, because the
only difference should be the IPC time from the renderer to the browser thread.

BUG=650349
==========

[jam, 2016-10-24 18:19:59]

The CQ bit was checked by jam@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2016-10-24 18:20:34]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[jam, 2016-10-24 19:24:08]

jam@chromium.org changed reviewers:
+ gab@chromium.org

[commit-bot: I haz the power, 2016-10-24 19:33:31]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2016-10-24 19:33:31]

Dry run: This issue passed the CQ dry run.

[gab, 2016-10-24 19:48:17]

https://codereview.chromium.org/2448553002/diff/20001/chrome/browser/metrics/...
File chrome/browser/metrics/first_web_contents_profiler.cc (right):

https://codereview.chromium.org/2448553002/diff/20001/chrome/browser/metrics/...
chrome/browser/metrics/first_web_contents_profiler.cc:94: // will miss this
signal. Instead we record it when the commit completes.
Does that mean that DidStartNavigation is invoked before creating the
FirstWebContentsProfiler? In that case I think we should either not record the
metric at all (and update its histograms.xml description to mention that it's
not recorded for PlzNavigate) or record it in the FirstWebContentsProfiler's
constructor if we think it's close enough?

Recording it on the finished signal seems wrong to me

[gab, 2016-10-24 19:58:15]

lgtm w/ suggestion

https://codereview.chromium.org/2448553002/diff/20001/chrome/browser/metrics/...
File chrome/browser/metrics/first_web_contents_profiler.cc (right):

https://codereview.chromium.org/2448553002/diff/20001/chrome/browser/metrics/...
chrome/browser/metrics/first_web_contents_profiler.cc:94: // will miss this
signal. Instead we record it when the commit completes.
On 2016/10/24 19:48:17, gab wrote:
> Does that mean that DidStartNavigation is invoked before creating the
> FirstWebContentsProfiler? In that case I think we should either not record the
> metric at all (and update its histograms.xml description to mention that it's
> not recorded for PlzNavigate) or record it in the FirstWebContentsProfiler's
> constructor if we think it's close enough?
> 
> Recording it on the finished signal seems wrong to me

Ah nvm, read too fast, 139 doesn't record TimeTicks::Now() but time from handle,
maybe be explicit about that in this comment?

[jam, 2016-10-24 20:39:43]

https://codereview.chromium.org/2448553002/diff/20001/chrome/browser/metrics/...
File chrome/browser/metrics/first_web_contents_profiler.cc (right):

https://codereview.chromium.org/2448553002/diff/20001/chrome/browser/metrics/...
chrome/browser/metrics/first_web_contents_profiler.cc:94: // will miss this
signal. Instead we record it when the commit completes.
On 2016/10/24 19:58:15, gab wrote:
> On 2016/10/24 19:48:17, gab wrote:
> > Does that mean that DidStartNavigation is invoked before creating the
> > FirstWebContentsProfiler? In that case I think we should either not record
the
> > metric at all (and update its histograms.xml description to mention that
it's
> > not recorded for PlzNavigate) or record it in the FirstWebContentsProfiler's
> > constructor if we think it's close enough?
> > 
> > Recording it on the finished signal seems wrong to me
> 
> Ah nvm, read too fast, 139 doesn't record TimeTicks::Now() but time from
handle,
> maybe be explicit about that in this comment?

IMO I don't think this is worth documenting (i.e. you found it yourself), since
anyone looking at this code can look at the function comment for
NavigationStart. I prefer not to duplicate the documentation for it here.

[jam, 2016-10-24 20:39:47]

The CQ bit was checked by jam@chromium.org

[commit-bot: I haz the power, 2016-10-24 20:40:29]

CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2016-10-24 20:58:58]

Description was changed from

==========
A different approach to fixing FirstWebContentsProfiler with PlzNavigate.

The previous fix depended on ensuring we add hooks to all the code paths that
cause the first active WebContents to get added to the tab strip. We're still
missing some code paths. So instead restore the old behavior. Even though it did
miss navigation starts, fix that by using the time from NavigationHandle for
PlzNavigate.

This should restore the metrics for non-PlzNavigate case.
For PlzNavigate, the start timings were already different regardless from
non-PlzNavigate because of how navigations are structured very differently. This
change shouldn't affects things too much for PlzNavigate though, because the
only difference should be the IPC time from the renderer to the browser thread.

BUG=650349
==========

to

==========
A different approach to fixing FirstWebContentsProfiler with PlzNavigate.

The previous fix depended on ensuring we add hooks to all the code paths that
cause the first active WebContents to get added to the tab strip. We're still
missing some code paths. So instead restore the old behavior. Even though it did
miss navigation starts, fix that by using the time from NavigationHandle for
PlzNavigate.

This should restore the metrics for non-PlzNavigate case.
For PlzNavigate, the start timings were already different regardless from
non-PlzNavigate because of how navigations are structured very differently. This
change shouldn't affects things too much for PlzNavigate though, because the
only difference should be the IPC time from the renderer to the browser thread.

BUG=650349
==========

[commit-bot: I haz the power, 2016-10-24 20:58:59]

Committed patchset #2 (id:20001)

[commit-bot: I haz the power, 2016-10-24 21:00:44]

Description was changed from

==========
A different approach to fixing FirstWebContentsProfiler with PlzNavigate.

The previous fix depended on ensuring we add hooks to all the code paths that
cause the first active WebContents to get added to the tab strip. We're still
missing some code paths. So instead restore the old behavior. Even though it did
miss navigation starts, fix that by using the time from NavigationHandle for
PlzNavigate.

This should restore the metrics for non-PlzNavigate case.
For PlzNavigate, the start timings were already different regardless from
non-PlzNavigate because of how navigations are structured very differently. This
change shouldn't affects things too much for PlzNavigate though, because the
only difference should be the IPC time from the renderer to the browser thread.

BUG=650349
==========

to

==========
A different approach to fixing FirstWebContentsProfiler with PlzNavigate.

The previous fix depended on ensuring we add hooks to all the code paths that
cause the first active WebContents to get added to the tab strip. We're still
missing some code paths. So instead restore the old behavior. Even though it did
miss navigation starts, fix that by using the time from NavigationHandle for
PlzNavigate.

This should restore the metrics for non-PlzNavigate case.
For PlzNavigate, the start timings were already different regardless from
non-PlzNavigate because of how navigations are structured very differently. This
change shouldn't affects things too much for PlzNavigate though, because the
only difference should be the IPC time from the renderer to the browser thread.

BUG=650349

Committed: https://crrev.com/f4ba53f555685c67fc3fb4ffdb18c4ff7baea19c
Cr-Commit-Position: refs/heads/master@{#427144}
==========

[commit-bot: I haz the power, 2016-10-24 21:00:45]

Patchset 2 (id:??) landed as
https://crrev.com/f4ba53f555685c67fc3fb4ffdb18c4ff7baea19c
Cr-Commit-Position: refs/heads/master@{#427144}