Prerender: fix flaky page load metrics tests

Prerender: fix flaky page load metrics test (First Contentful Paint).

Adds a waiter for the TimingUpdated IPC. This is a little subtle, as the waiter
may fire before the true PageLoadMetrics observer sees the IPC, hence the waiter
handler needs to be requeued.

BUG=657022
Review-Url: https://codereview.chromium.org/2698813005
Cr-Commit-Position: refs/heads/master@{#451594}
Committed: https://chromium.googlesource.com/chromium/src/+/20af066f183963806cf7f43837bd6fdacbe6d5ec

[mattcary, 2017-02-16 16:13:14]

mattcary@chromium.org changed reviewers:
+ bmcquade@chromium.org, droger@chromium.org

[mattcary, 2017-02-16 16:13:15]

Here's a re-animation of David's IPC waiter. It appears that one of the issues
with David's CL is that the IPC waiter can see the IPC before the real PLM
observer.

Anyway, I'm not sure I worked around that in the best way, so LMK.

Thanks

Matt

[droger, 2017-02-16 16:33:12]

Thanks, that looks good!

Glad to see that I was somewhat on the right track :) Could you actually
reproduce the failures or is this still speculative?

We might also want to use this in other tests in this file, because they're
flaky for the same reason.

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
File chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc (right):

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc:87: bool
unused;
Do we really need this variable (since the function always return false anyway)?

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc:99:
timing.dom_content_loaded_event_start) ||
Not exactly sure what would be the use case for setting multiple fields in the
template, but intuitively I would use && instead of ||.

The use case would be that you would call WaitForMatchingIPC with a template
including all the fields you want to test, and then check them.


Using || might also work, but then you need to call WaitForMatchingIPC multiple
times with different templates?

[mattcary, 2017-02-16 17:43:28]

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
File chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc (right):

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc:87: bool
unused;
On 2017/02/16 16:33:12, droger wrote:
> Do we really need this variable (since the function always return false
anyway)?

Probably not, but I didn't know what the convention was. I think we need the
IPC_MESSAGE_UNHANDLED in order to prevent the compiler from complaining about a
missing default: in the switch, but I didn't know if there was a convention
about what to put in as the argument.

I'll poke around the code and see if I can find a relevant example.

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc:99:
timing.dom_content_loaded_event_start) ||
On 2017/02/16 16:33:12, droger wrote:
> Not exactly sure what would be the use case for setting multiple fields in the
> template, but intuitively I would use && instead of ||.
> 
> The use case would be that you would call WaitForMatchingIPC with a template
> including all the fields you want to test, and then check them.
> 
> 
> Using || might also work, but then you need to call WaitForMatchingIPC
multiple
> times with different templates?

Since I'm just checking on the single metric it's all theoretical :)

I can change to && unless Bryan has an objection.

[mattcary, 2017-02-16 17:44:16]

On 2017/02/16 16:33:12, droger wrote:
> Thanks, that looks good!
> 
> Glad to see that I was somewhat on the right track :) Could you actually
> reproduce the failures or is this still speculative?
> 
> We might also want to use this in other tests in this file, because they're
> flaky for the same reason.
> 
Yeah, I think you're right. I was going to wait to see if Bryan thought this
approach looked okay.

[Bryan McQuade, 2017-02-16 18:18:14]

This is great, thanks! Just a couple small suggestions.

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
File chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc (right):

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc:50:
DCHECK(template_timing_.dom_content_loaded_event_start ||
could you use !template_timing_.IsEmpty() here? I see you are excluding the
navigation_start field from testing - maybe to make this more future proof, and
given that it's non perf critical test code, you coul do this:

// Make sure at least one TimeDelta field is non-empty
PageLoadTiming tmp(template_timing_);
tmp.navigation_start = base::Time();
DCHECK(!tmp.IsEmpty());

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc:79:
run_loop_->Run();
can we have this time out and fail after some amount of time (a few seconds)?
otherwise iiuc the test will hang forever if a matching IPC isn't received,
which seems undesirable.

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc:99:
timing.dom_content_loaded_event_start) ||
On 2017/02/16 at 17:43:28, mattcary wrote:
> On 2017/02/16 16:33:12, droger wrote:
> > Not exactly sure what would be the use case for setting multiple fields in
the
> > template, but intuitively I would use && instead of ||.
> > 
> > The use case would be that you would call WaitForMatchingIPC with a template
> > including all the fields you want to test, and then check them.
> > 
> > 
> > Using || might also work, but then you need to call WaitForMatchingIPC
multiple
> > times with different templates?
> 
> Since I'm just checking on the single metric it's all theoretical :)
> 
> I can change to && unless Bryan has an objection.

yeah i think i agree that we should verify that all specified values in the
template are set in the IPC value. it's ok for a value to be present in the IPC
value but not in the template, though.

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc:168:
template_timing.first_contentful_paint =
maybe add a comment noting that the actual value is unimportant, and that all we
want to do is make sure the value is set?

[mattcary, 2017-02-17 09:37:47]

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
File chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc (right):

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc:50:
DCHECK(template_timing_.dom_content_loaded_event_start ||
On 2017/02/16 18:18:14, Bryan McQuade wrote:
> could you use !template_timing_.IsEmpty() here? I see you are excluding the
> navigation_start field from testing - maybe to make this more future proof,
and
> given that it's non perf critical test code, you coul do this:
> 
> // Make sure at least one TimeDelta field is non-empty
> PageLoadTiming tmp(template_timing_);
> tmp.navigation_start = base::Time();
> DCHECK(!tmp.IsEmpty());

Thanks, IsEmpty is much better. I don't think the navigation_start field is
critical.

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc:79:
run_loop_->Run();
On 2017/02/16 18:18:14, Bryan McQuade wrote:
> can we have this time out and fail after some amount of time (a few seconds)?
> otherwise iiuc the test will hang forever if a matching IPC isn't received,
> which seems undesirable.

The test harness will time out tests. It seems better to continue to use that
mechanism rather than add an additional one---for example, there are
command-line flags that can adjust timeouts, which can be useful in debugging
things, and adding another timeout will complicate that.

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc:87: bool
unused;
On 2017/02/16 17:43:28, mattcary wrote:
> On 2017/02/16 16:33:12, droger wrote:
> > Do we really need this variable (since the function always return false
> anyway)?
> 
> Probably not, but I didn't know what the convention was. I think we need the
> IPC_MESSAGE_UNHANDLED in order to prevent the compiler from complaining about
a
> missing default: in the switch, but I didn't know if there was a convention
> about what to put in as the argument.
> 
> I'll poke around the code and see if I can find a relevant example.

Seems to work without the unhandled case. Hooray!

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc:99:
timing.dom_content_loaded_event_start) ||
On 2017/02/16 18:18:14, Bryan McQuade wrote:
> On 2017/02/16 at 17:43:28, mattcary wrote:
> > On 2017/02/16 16:33:12, droger wrote:
> > > Not exactly sure what would be the use case for setting multiple fields in
> the
> > > template, but intuitively I would use && instead of ||.
> > > 
> > > The use case would be that you would call WaitForMatchingIPC with a
template
> > > including all the fields you want to test, and then check them.
> > > 
> > > 
> > > Using || might also work, but then you need to call WaitForMatchingIPC
> multiple
> > > times with different templates?
> > 
> > Since I'm just checking on the single metric it's all theoretical :)
> > 
> > I can change to && unless Bryan has an objection.
> 
> yeah i think i agree that we should verify that all specified values in the
> template are set in the IPC value. it's ok for a value to be present in the
IPC
> value but not in the template, though.

Done.

https://codereview.chromium.org/2698813005/diff/1/chrome/browser/page_load_me...
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc:168:
template_timing.first_contentful_paint =
On 2017/02/16 18:18:14, Bryan McQuade wrote:
> maybe add a comment noting that the actual value is unimportant, and that all
we
> want to do is make sure the value is set?

Done.

[droger, 2017-02-17 09:55:00]

lgtm, thanks!

[mattcary, 2017-02-17 15:01:25]

I've unflaked the related tests mentioned in the bug as well. It all seems to
work okay locally. PreloadDocumentWrite flaked once in I think an unrelated way
but I haven't been able to preproduce it.

[mattcary, 2017-02-17 15:01:41]

Description was changed from

==========
Prerender: fix flaky page load metrics test (First Contentful Paint).

Adds a waiter for the TimingUpdated IPC. This is a little subtle, as the waiter
may fire before the true PageLoadMetrics observer sees the IPC, hence the waiter
handler needs to be requeued.

BUG=657022
==========

to

==========
Prerender: fix flaky page load metrics test (First Contentful Paint).

Adds a waiter for the TimingUpdated IPC. This is a little subtle, as the waiter
may fire before the true PageLoadMetrics observer sees the IPC, hence the waiter
handler needs to be requeued.

BUG=657022
==========

[Bryan McQuade, 2017-02-17 18:54:48]

LGTM, thank you very much for driving this fix! One optional API suggestion to
change the API, but I'm fine leaving it as you have it if you prefer.

https://codereview.chromium.org/2698813005/diff/60001/chrome/browser/page_loa...
File chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc (right):

https://codereview.chromium.org/2698813005/diff/60001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc:78:
page_load_metrics::PageLoadTiming* template_timing() {
looking at this some more i think my suggestion to use a PageLoadTiming to do
matching was perhaps not so great. the '// Set to nonzero for matching.' bits
are a touch confusing.

in hindsight I think I prefer a bitfield enum e.g.
enum ExpectedTimingFields {
  FIRST_PAINT = 1<<0;
  FIRST_CONTENTFUL_PAINT = 1<<1;
}

which you pass into the constructor of the TimingUpdatedObserver.

I'm fine leaving it as you have it, but feel free to make this change if you
think it's better and doesn't add too much complexity.

we could extend the enum only as needed.

[mattcary, 2017-02-20 10:25:25]

https://codereview.chromium.org/2698813005/diff/60001/chrome/browser/page_loa...
File chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc (right):

https://codereview.chromium.org/2698813005/diff/60001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc:78:
page_load_metrics::PageLoadTiming* template_timing() {
On 2017/02/17 18:54:48, Bryan McQuade wrote:
> looking at this some more i think my suggestion to use a PageLoadTiming to do
> matching was perhaps not so great. the '// Set to nonzero for matching.' bits
> are a touch confusing.
> 
> in hindsight I think I prefer a bitfield enum e.g.
> enum ExpectedTimingFields {
>   FIRST_PAINT = 1<<0;
>   FIRST_CONTENTFUL_PAINT = 1<<1;
> }
> 
> which you pass into the constructor of the TimingUpdatedObserver.
> 
> I'm fine leaving it as you have it, but feel free to make this change if you
> think it's better and doesn't add too much complexity.
> 
> we could extend the enum only as needed.

Done.

[mattcary, 2017-02-20 10:25:31]

The CQ bit was checked by mattcary@chromium.org

[mattcary, 2017-02-20 10:25:32]

The patchset sent to the CQ was uploaded after l-g-t-m from droger@chromium.org,
bmcquade@chromium.org
Link to the patchset: https://codereview.chromium.org/2698813005/#ps80001
(title: "comments/field matching bitvector")

[commit-bot: I haz the power, 2017-02-20 10:25:47]

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, 2017-02-20 11:08:04]

CQ is committing da patch.

Bot data: {"patchset_id": 80001, "attempt_start_ts": 1487586331696410,
"parent_rev": "39bfaaba5dc0d78349ccb2a1a6c2eb42d16dca69", "commit_rev":
"20af066f183963806cf7f43837bd6fdacbe6d5ec"}

[commit-bot: I haz the power, 2017-02-20 11:08:44]

Description was changed from

==========
Prerender: fix flaky page load metrics test (First Contentful Paint).

Adds a waiter for the TimingUpdated IPC. This is a little subtle, as the waiter
may fire before the true PageLoadMetrics observer sees the IPC, hence the waiter
handler needs to be requeued.

BUG=657022
==========

to

==========
Prerender: fix flaky page load metrics test (First Contentful Paint).

Adds a waiter for the TimingUpdated IPC. This is a little subtle, as the waiter
may fire before the true PageLoadMetrics observer sees the IPC, hence the waiter
handler needs to be requeued.

BUG=657022

Review-Url: https://codereview.chromium.org/2698813005
Cr-Commit-Position: refs/heads/master@{#451594}
Committed:
https://chromium.googlesource.com/chromium/src/+/20af066f183963806cf7f43837bd...
==========

[commit-bot: I haz the power, 2017-02-20 11:08:46]

Committed patchset #5 (id:80001) as
https://chromium.googlesource.com/chromium/src/+/20af066f183963806cf7f43837bd...