Histogram the amount of time spent on HTTP(S) page loads

Histogram the amount of time spent on HTTP(S) page loads

This creates three histograms to show how time is distributed by scheme.
The histograms are intended to answer the question:

Do HTTPS page visits tend to be longer than HTTP page visits?

BUG=588941
Committed: https://crrev.com/6165ca0c38af8740c831b65ad79655933c0ceb5d
Cr-Commit-Position: refs/heads/master@{#394645}

[felt, 2016-04-23 02:01:55]

Description was changed from

==========
Histogram the amount of time spent on HTTP(S) page loads

This creates three histograms to show how time is distributed by scheme.
The histograms are intended to answer the question:

Do HTTPS page visits tend to be longer than HTTP page visits?

BUG=588941
==========

to

==========
Histogram the amount of time spent on HTTP(S) page loads

This creates three histograms to show how time is distributed by scheme.
The histograms are intended to answer the question:

Do HTTPS page visits tend to be longer than HTTP page visits?

BUG=588941
==========

[felt, 2016-04-23 02:01:55]

felt@chromium.org changed reviewers:
+ csharrison@chromium.org

[felt, 2016-04-23 02:02:09]

csharrison, PTAL?

[Charlie Harrison, 2016-04-25 13:20:08]

This looks great! I'm excited about these metrics.

Because the system was not quite designed for this use case, I'll encourage you
to add browser tests / unit tests to catch any faulty logic.

The way I might test this would be to write a test harness that bounds the start
and end of the test:

mark testBeginning
beginTest()
mark testBegun
... test impl ...
mark testEnding
endTest()
mark testEnded

Then, you can make sure your engagement duration is between testEnded -
testBeginning and testEnding - testBegun.

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
File
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.cc
(right):

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.cc:28:
if (last_time_shown_ > current_time) {
If you used TimeTicks you wouldn't have to worry about this problem (except in
extremely rare cases of computers with broken clocks).

The only annoying thing about TimeTicks is that they don't tick when the
computer is in suspend mode. I suspect that actually helps you in this case,
though.

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.cc:44:
if (time_travelled_backwards_ || !url_.is_valid())
You'll also might want to filter out results if the page never committed (i.e. a
connection wasn't successfully made to the server).

Additionally, PageLoadTiming& contains useful metrics about page load time that
you might want to filter by. For instance, you may want to only track pages that
painted contents on the screen.

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
File
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.h
(right):

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.h:13:
class HttpsPageLoadMetricsObserver
Can the class/file name be a bit more descriptive? Maybe
"HttpsEngagementPageLoadMetricsObserver"?

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.h:18:
// page_load_metrics::PageLoadMetricsObserver implementation:
page_load_metrics::PageLoadMetricsObserver:

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.h:28:
GURL url_;
PageLoadExtraInfo has the committed_url in OnComplete, which should be enough
for you. If you only filter by committed loads you can use that and avoid this
copy.

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.h:31:
base::Time last_time_shown_;
Why not use a TimeTicks here? Do you need to correlate with a date?

https://codereview.chromium.org/1913693002/diff/20001/components/page_load_me...
File components/page_load_metrics/browser/page_load_metrics_observer.h (right):

https://codereview.chromium.org/1913693002/diff/20001/components/page_load_me...
components/page_load_metrics/browser/page_load_metrics_observer.h:124: bool
started_in_foreground) {}
It makes more sense to thread this in OnStart. In any case, I think you're
sending in |started_in_foreground| from a member that's initialized at OnStart.

Another technique would be to add a method to PageLoadMetricsObserver that
allows querying the bg/fg state at any time. This would possibly be a better
design and clean up the API, but it would mean adding some logic to the base
class of PageLoadMetricsObserver.

[felt, 2016-04-25 21:30:04]

A quick question below, before I change the API & write tests.

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
File
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.cc
(right):

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.cc:28:
if (last_time_shown_ > current_time) {
On 2016/04/25 13:20:08, csharrison wrote:
> If you used TimeTicks you wouldn't have to worry about this problem (except in
> extremely rare cases of computers with broken clocks).

Ahh, good point. Done.

> The only annoying thing about TimeTicks is that they don't tick when the
> computer is in suspend mode. I suspect that actually helps you in this case,
> though.

Yes, that's actually a great property.

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.cc:44:
if (time_travelled_backwards_ || !url_.is_valid())
On 2016/04/25 13:20:08, csharrison wrote:
> You'll also might want to filter out results if the page never committed (i.e.
a
> connection wasn't successfully made to the server).

Good point. I've switched to using the committed URL from extra_info.

> Additionally, PageLoadTiming& contains useful metrics about page load time
that
> you might want to filter by. For instance, you may want to only track pages
that
> painted contents on the screen.

OK, added some more checks. I'm assuming that the paint will never actually
happen in 0 time.

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
File
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.h
(right):

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.h:13:
class HttpsPageLoadMetricsObserver
On 2016/04/25 13:20:08, csharrison wrote:
> Can the class/file name be a bit more descriptive? Maybe
> "HttpsEngagementPageLoadMetricsObserver"?

Done.

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.h:18:
// page_load_metrics::PageLoadMetricsObserver implementation:
On 2016/04/25 13:20:08, csharrison wrote:
> page_load_metrics::PageLoadMetricsObserver:

Done.

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.h:28:
GURL url_;
On 2016/04/25 13:20:08, csharrison wrote:
> PageLoadExtraInfo has the committed_url in OnComplete, which should be enough
> for you. If you only filter by committed loads you can use that and avoid this
> copy.

Done.

https://codereview.chromium.org/1913693002/diff/20001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_page_load_metrics_observer.h:31:
base::Time last_time_shown_;
On 2016/04/25 13:20:08, csharrison wrote:
> Why not use a TimeTicks here? Do you need to correlate with a date?

Done.

https://codereview.chromium.org/1913693002/diff/20001/components/page_load_me...
File components/page_load_metrics/browser/page_load_metrics_observer.h (right):

https://codereview.chromium.org/1913693002/diff/20001/components/page_load_me...
components/page_load_metrics/browser/page_load_metrics_observer.h:124: bool
started_in_foreground) {}
On 2016/04/25 13:20:08, csharrison wrote:
> It makes more sense to thread this in OnStart. In any case, I think you're
> sending in |started_in_foreground| from a member that's initialized at
OnStart.
> 
> Another technique would be to add a method to PageLoadMetricsObserver that
> allows querying the bg/fg state at any time. This would possibly be a better
> design and clean up the API, but it would mean adding some logic to the base
> class of PageLoadMetricsObserver.

Do you mean making PageLoadMetricsObserver no longer a pure interface? I could
add get_in_foreground and set_in_foreground and have it kept updated
appropriately, but it wouldn't be a pure interface anymore.

[Charlie Harrison, 2016-04-25 21:49:10]

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

[Charlie Harrison, 2016-04-25 21:49:11]

Thanks! Looks a lot cleaner now.

https://codereview.chromium.org/1913693002/diff/20001/components/page_load_me...
File components/page_load_metrics/browser/page_load_metrics_observer.h (right):

https://codereview.chromium.org/1913693002/diff/20001/components/page_load_me...
components/page_load_metrics/browser/page_load_metrics_observer.h:124: bool
started_in_foreground) {}
On 2016/04/25 at 21:30:04, felt wrote:
> On 2016/04/25 13:20:08, csharrison wrote:
> > It makes more sense to thread this in OnStart. In any case, I think you're
> > sending in |started_in_foreground| from a member that's initialized at
OnStart.
> > 
> > Another technique would be to add a method to PageLoadMetricsObserver that
> > allows querying the bg/fg state at any time. This would possibly be a better
> > design and clean up the API, but it would mean adding some logic to the base
> > class of PageLoadMetricsObserver.
> 
> Do you mean making PageLoadMetricsObserver no longer a pure interface? I could
add get_in_foreground and set_in_foreground and have it kept updated
appropriately, but it wouldn't be a pure interface anymore.

Yeah that's what I meant. I wouldn't be opposed to this approach. Another
approach would be to expose more underlying state to the observer, i.e. give a
"page_load_tracker()" method to them, which could be used to expose more
information. That would also entail giving a concrete impl (or threading it
through callbacks).

None of these approaches really stand out to me as being best, so it may make
sense to do the simplest (thread a bool through OnStart).

+bmcquade who may have API opinions.

https://codereview.chromium.org/1913693002/diff/40001/chrome/browser/page_loa...
File
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer.cc
(right):

https://codereview.chromium.org/1913693002/diff/40001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer.cc:42:
UMA_HISTOGRAM_LONG_TIMES_100("Navigation.Time.HTTPS", foreground_time_);
Suggestion: "Navigation.Time" implies "time to commit" for me, and the existing
UMA in the "Navigation." namespace is about the PlzNavigate project which is
dealing with optimizing the time to commit. I'm not sure if there is an
engagement namespace, but at least "Navigation.EngagementTime" is better.

https://codereview.chromium.org/1913693002/diff/40001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer.cc:45:
else
The PageLoadMetrics system only (fully) tracks http/s loads. That is, you'll
only get a non-empty PageLoadTiming for those loads. As is, I don't think this
case will be hit.

You could consider relaxing your filters or just not caring about this case.

[Bryan McQuade, 2016-04-25 22:00:04]

Thanks for this! I've been wanting to add shown/hidden methods on
PageLoadTracker - glad to see them added as part of this change.

https://codereview.chromium.org/1913693002/diff/20001/components/page_load_me...
File components/page_load_metrics/browser/page_load_metrics_observer.h (right):

https://codereview.chromium.org/1913693002/diff/20001/components/page_load_me...
components/page_load_metrics/browser/page_load_metrics_observer.h:124: bool
started_in_foreground) {}
On 2016/04/25 at 21:49:11, csharrison wrote:
> On 2016/04/25 at 21:30:04, felt wrote:
> > On 2016/04/25 13:20:08, csharrison wrote:
> > > It makes more sense to thread this in OnStart. In any case, I think you're
> > > sending in |started_in_foreground| from a member that's initialized at
OnStart.
> > > 
> > > Another technique would be to add a method to PageLoadMetricsObserver that
> > > allows querying the bg/fg state at any time. This would possibly be a
better
> > > design and clean up the API, but it would mean adding some logic to the
base
> > > class of PageLoadMetricsObserver.
> > 
> > Do you mean making PageLoadMetricsObserver no longer a pure interface? I
could add get_in_foreground and set_in_foreground and have it kept updated
appropriately, but it wouldn't be a pure interface anymore.
> 
> Yeah that's what I meant. I wouldn't be opposed to this approach. Another
approach would be to expose more underlying state to the observer, i.e. give a
"page_load_tracker()" method to them, which could be used to expose more
information. That would also entail giving a concrete impl (or threading it
through callbacks).
> 
> None of these approaches really stand out to me as being best, so it may make
sense to do the simplest (thread a bool through OnStart).
> 
> +bmcquade who may have API opinions.

I'm open to either providing a getter for the current visibility state, or
moving the boolean to OnStart. I'm disinclined to provide a getter for
PageLoadTracker since we didn't design that class to be a public part of the API
& would want to spend a bit of time before deciding it was ready to expose.

https://codereview.chromium.org/1913693002/diff/20001/components/page_load_me...
components/page_load_metrics/browser/page_load_metrics_observer.h:138: // fire
when the page first loads; for that, listen for OnCommit instead.
if we move the boolean to OnStart let's update this comment to point to OnStart
as well.

[felt, 2016-04-26 01:46:29]

Added unit tests too.

https://codereview.chromium.org/1913693002/diff/20001/components/page_load_me...
File components/page_load_metrics/browser/page_load_metrics_observer.h (right):

https://codereview.chromium.org/1913693002/diff/20001/components/page_load_me...
components/page_load_metrics/browser/page_load_metrics_observer.h:124: bool
started_in_foreground) {}
On 2016/04/25 22:00:04, Bryan McQuade wrote:
> On 2016/04/25 at 21:49:11, csharrison wrote:
> > On 2016/04/25 at 21:30:04, felt wrote:
> > > On 2016/04/25 13:20:08, csharrison wrote:
> > > > It makes more sense to thread this in OnStart. In any case, I think
you're
> > > > sending in |started_in_foreground| from a member that's initialized at
> OnStart.
> > > > 
> > > > Another technique would be to add a method to PageLoadMetricsObserver
that
> > > > allows querying the bg/fg state at any time. This would possibly be a
> better
> > > > design and clean up the API, but it would mean adding some logic to the
> base
> > > > class of PageLoadMetricsObserver.
> > > 
> > > Do you mean making PageLoadMetricsObserver no longer a pure interface? I
> could add get_in_foreground and set_in_foreground and have it kept updated
> appropriately, but it wouldn't be a pure interface anymore.
> > 
> > Yeah that's what I meant. I wouldn't be opposed to this approach. Another
> approach would be to expose more underlying state to the observer, i.e. give a
> "page_load_tracker()" method to them, which could be used to expose more
> information. That would also entail giving a concrete impl (or threading it
> through callbacks).
> > 
> > None of these approaches really stand out to me as being best, so it may
make
> sense to do the simplest (thread a bool through OnStart).
> > 
> > +bmcquade who may have API opinions.
> 
> I'm open to either providing a getter for the current visibility state, or
> moving the boolean to OnStart. I'm disinclined to provide a getter for
> PageLoadTracker since we didn't design that class to be a public part of the
API
> & would want to spend a bit of time before deciding it was ready to expose.

I personally prefer moving the boolean to OnStart, to keep the interface pure.
So went ahead and did that.

https://codereview.chromium.org/1913693002/diff/20001/components/page_load_me...
components/page_load_metrics/browser/page_load_metrics_observer.h:138: // fire
when the page first loads; for that, listen for OnCommit instead.
On 2016/04/25 22:00:04, Bryan McQuade wrote:
> if we move the boolean to OnStart let's update this comment to point to
OnStart
> as well.

Done.

https://codereview.chromium.org/1913693002/diff/40001/chrome/browser/page_loa...
File
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer.cc
(right):

https://codereview.chromium.org/1913693002/diff/40001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer.cc:42:
UMA_HISTOGRAM_LONG_TIMES_100("Navigation.Time.HTTPS", foreground_time_);
On 2016/04/25 21:49:11, csharrison wrote:
> Suggestion: "Navigation.Time" implies "time to commit" for me, and the
existing
> UMA in the "Navigation." namespace is about the PlzNavigate project which is
> dealing with optimizing the time to commit. I'm not sure if there is an
> engagement namespace, but at least "Navigation.EngagementTime" is better.

Navigation.MainFrameScheme and Navigation.MainFrameSchemeDifferentPage are other
major HTTP(S) metrics that I rely on, so I think this should stay in the
Navigation namespace. But, I like EngagementTime better so changed that.

https://codereview.chromium.org/1913693002/diff/40001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer.cc:45:
else
On 2016/04/25 21:49:11, csharrison wrote:
> The PageLoadMetrics system only (fully) tracks http/s loads. That is, you'll
> only get a non-empty PageLoadTiming for those loads. As is, I don't think this
> case will be hit.
> 
> You could consider relaxing your filters or just not caring about this case.

Done.

[Charlie Harrison, 2016-04-26 21:09:47]

I think you missed a "git add" for the unit tests. Otherwise looks good.

https://codereview.chromium.org/1913693002/diff/40001/chrome/browser/page_loa...
File
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer.cc
(right):

https://codereview.chromium.org/1913693002/diff/40001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer.cc:42:
UMA_HISTOGRAM_LONG_TIMES_100("Navigation.Time.HTTPS", foreground_time_);
On 2016/04/26 01:46:29, felt wrote:
> On 2016/04/25 21:49:11, csharrison wrote:
> > Suggestion: "Navigation.Time" implies "time to commit" for me, and the
> existing
> > UMA in the "Navigation." namespace is about the PlzNavigate project which is
> > dealing with optimizing the time to commit. I'm not sure if there is an
> > engagement namespace, but at least "Navigation.EngagementTime" is better.
> 
> Navigation.MainFrameScheme and Navigation.MainFrameSchemeDifferentPage are
other
> major HTTP(S) metrics that I rely on, so I think this should stay in the
> Navigation namespace. But, I like EngagementTime better so changed that.

SGTM. You're right about those metrics.

https://codereview.chromium.org/1913693002/diff/80001/chrome/browser/page_loa...
File
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer.cc
(right):

https://codereview.chromium.org/1913693002/diff/80001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer.cc:24:
foreground_time_ += current_time - last_time_shown_;
Hmm, if |last_time_shown_| is null at this point then the foreground time could
be huge. You might want to make sure that currently_in_foreground_ is true.

https://codereview.chromium.org/1913693002/diff/80001/chrome/browser/page_loa...
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer.cc:36:
extra_info.time_to_commit.is_zero() || timing.first_paint.is_zero())
Can you use braces for conditionals whose condition spans multiple lines?

[felt, 2016-04-26 21:15:05]

Well that's embarrassing. Did the git add, so file now there...

[Charlie Harrison, 2016-04-26 21:31:49]

Thanks!

https://codereview.chromium.org/1913693002/diff/100001/chrome/browser/page_lo...
File
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer_unittest.cc
(right):

https://codereview.chromium.org/1913693002/diff/100001/chrome/browser/page_lo...
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer_unittest.cc:60:
EXPECT_GT(upper_bound_delta.InMilliseconds(),
This is good, but I'm nervous that these tests will be flaky on bots with
terrible clocks (Win10 GCE in particular, which is almost ready for production).

I know EXPECT_GE isn't quite as strong as you'd probably like. You could also
bound the value between a lower and upper bound.

Ditto for the other tests that EXPECT_GT.

https://codereview.chromium.org/1913693002/diff/100001/chrome/browser/page_lo...
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer_unittest.cc:163:
base::TimeDelta upper_bound_delta = base::TimeTicks::Now() - start;
This feels really flaky to me. I don't have a solution handy that will solve
this sort of problem in a nice way. Maybe a browsertest?
Feel free to add them to a new browsertest file or
chrome/browser/page_load_metrics/page_load_metrics_browsertest.cc.

I'd also like to see a test where the entire navigation is in the background
(expect 0 fg time), as well as a start in the background and finish in
foreground test.

[felt, 2016-05-17 20:51:29]

I've completely rewritten the tests as browser tests. I feel much better about
the coverage of these tests. (Sorry about the delay.)

I still worry about the timing being flaky. Only a few tests rely on the upper
bound timing check. My thought is that if it proves to be flaky, we can remove
it and still have reasonable coverage -- in most cases it's sufficient to check
that an entry (of any size) was added to the appropriate histogram.

[Charlie Harrison, 2016-05-18 15:17:50]

This looks great! Thanks for the updated browser tests.

https://codereview.chromium.org/1913693002/diff/140001/chrome/browser/page_lo...
File
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer_browsertest.cc
(right):

https://codereview.chromium.org/1913693002/diff/140001/chrome/browser/page_lo...
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer_browsertest.cc:24:
const char kHttpHistogram[] = "Navigation.EngagementTime.HTTP";
Suggestion: Lots of other observers declare these as extern const chars in the
observer header. Then they can be reused in implementation and tests.

https://codereview.chromium.org/1913693002/diff/140001/chrome/browser/page_lo...
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer_browsertest.cc:52:
// for how long the URL was open in the foreground.
It's a bit odd that some of these methods return a TimeDelta and some don't.
Maybe there could be a naming convention (or a spacial separation in the code).
That would also make things more clear why some tests need the tiny sleep and
some don't.

https://codereview.chromium.org/1913693002/diff/140001/chrome/browser/page_lo...
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer_browsertest.cc:176:
EXPECT_GT(upper_bound.InMilliseconds(), bucket_min);
Can you EXPECT_GE? We've seen some cases of bots with really terrible clock
resolution.

[felt, 2016-05-18 19:36:58]

https://codereview.chromium.org/1913693002/diff/140001/chrome/browser/page_lo...
File
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer_browsertest.cc
(right):

https://codereview.chromium.org/1913693002/diff/140001/chrome/browser/page_lo...
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer_browsertest.cc:24:
const char kHttpHistogram[] = "Navigation.EngagementTime.HTTP";
On 2016/05/18 15:17:49, csharrison wrote:
> Suggestion: Lots of other observers declare these as extern const chars in the
> observer header. Then they can be reused in implementation and tests.

Done.

https://codereview.chromium.org/1913693002/diff/140001/chrome/browser/page_lo...
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer_browsertest.cc:52:
// for how long the URL was open in the foreground.
On 2016/05/18 15:17:49, csharrison wrote:
> It's a bit odd that some of these methods return a TimeDelta and some don't.
> Maybe there could be a naming convention (or a spacial separation in the
code).
> That would also make things more clear why some tests need the tiny sleep and
> some don't.

I added "WithTiming" to the names.

https://codereview.chromium.org/1913693002/diff/140001/chrome/browser/page_lo...
chrome/browser/page_load_metrics/observers/https_engagement_page_load_metrics_observer_browsertest.cc:176:
EXPECT_GT(upper_bound.InMilliseconds(), bucket_min);
On 2016/05/18 15:17:49, csharrison wrote:
> Can you EXPECT_GE? We've seen some cases of bots with really terrible clock
> resolution.

Done.

[felt, 2016-05-18 19:38:14]

felt@chromium.org changed reviewers:
+ holte@chromium.org

[felt, 2016-05-18 19:38:47]

+holte, PTAL as an OWNER of histograms.xml?

[Charlie Harrison, 2016-05-18 19:47:28]

Thanks. The only thing I'm concerned with now is the checks for TinyDelay.

Do we know for sure that if we sleep for TinyDelay it is for sure going to take
>= TinyDelay?

[Charlie Harrison, 2016-05-18 19:47:29]

Thanks. The only thing I'm concerned with now is the checks for TinyDelay.

Do we know for sure that if we sleep for TinyDelay it is for sure going to take
>= TinyDelay?

[felt, 2016-05-18 19:58:38]

On 2016/05/18 19:47:29, csharrison wrote:
> Thanks. The only thing I'm concerned with now is the checks for TinyDelay.
> 
> Do we know for sure that if we sleep for TinyDelay it is for sure going to
take
> >= TinyDelay?

On my local machine, it always held true. However, from the trybots it appears
that at least on Mac this is not the case. :( I can't think of any better way to
test a lower bound, unfortunately. You seemed keen on having lower bound checks,
do you think it is important?

[Charlie Harrison, 2016-05-18 20:42:28]

On 2016/05/18 19:58:38, felt wrote:
> On 2016/05/18 19:47:29, csharrison wrote:
> > Thanks. The only thing I'm concerned with now is the checks for TinyDelay.
> > 
> > Do we know for sure that if we sleep for TinyDelay it is for sure going to
> take
> > >= TinyDelay?
> 
> On my local machine, it always held true. However, from the trybots it appears
> that at least on Mac this is not the case. :( I can't think of any better way
to
> test a lower bound, unfortunately. You seemed keen on having lower bound
checks,
> do you think it is important?

The main thing with lower bounds is they assert that you aren't just sending 0ms
as the engagement time.

Can you do something like

MarkUpperbound();
NavigateToURL(url);
MarkLowerBoundStart();

~sleep?~

MarkLowerBoundEnd();
DestroyTab();
MarkUpperBoundEnd();

If it makes the tests harder to write you could have the methods return the
lower bounds, and the inline tests calculate the upper bounds for you.

like:

TEST_F() {
  start = Now();
  lower_bound = RunTheTest();
  upper_bound = Now() - start;
  <do assertions w/ upper and lower bounds>
}

[felt, 2016-05-18 21:29:37]

On 2016/05/18 20:42:28, csharrison wrote:
> On 2016/05/18 19:58:38, felt wrote:
> > On 2016/05/18 19:47:29, csharrison wrote:
> > > Thanks. The only thing I'm concerned with now is the checks for TinyDelay.
> > > 
> > > Do we know for sure that if we sleep for TinyDelay it is for sure going to
> > take
> > > >= TinyDelay?
> > 
> > On my local machine, it always held true. However, from the trybots it
appears
> > that at least on Mac this is not the case. :( I can't think of any better
way
> to
> > test a lower bound, unfortunately. You seemed keen on having lower bound
> checks,
> > do you think it is important?
> 
> The main thing with lower bounds is they assert that you aren't just sending
0ms
> as the engagement time.
> 
> Can you do something like
> 
> MarkUpperbound();
> NavigateToURL(url);
> MarkLowerBoundStart();
> 
> ~sleep?~
> 
> MarkLowerBoundEnd();
> DestroyTab();
> MarkUpperBoundEnd();
> 
> If it makes the tests harder to write you could have the methods return the
> lower bounds, and the inline tests calculate the upper bounds for you.
> 
> like:
> 
> TEST_F() {
>   start = Now();
>   lower_bound = RunTheTest();
>   upper_bound = Now() - start;
>   <do assertions w/ upper and lower bounds>
> }

This doesn't work as cleanly as it seems. A Bucket comes with a min and a count.
The bucket sizes increase as the value increases. If I calculate the lower bound
like you've sketched out, it very well might be larger than the Bucket's min but
inside the same bucket. (The reason I used 89ms for comparison was because that
is a known bucket min value.) So we cannot do a lower bound check in comparison
to the min. There are therefore three options:
1. Round the lower bound to the nearest Bucket min size. That will require some
non-trivial calculations, potentially can make use of
Histogram::InitializeBucketRanges to help.
2. Hard code the Bucket sizes and round to the nearest.
3. Add a max to the Bucket class, although I suspect it's intentional that it
does not have a max.

I don't mind doing this, but I want to make sure it's worth the additional
complexity that it will add to the tests (especially around timing, which is
flakiness-prone to begin with). If the only goal is to make sure we aren't
sending 0ms or something silly like that, I can do a check for not equal to 0ms
with a lot less complexity.

[Charlie Harrison, 2016-05-18 21:40:06]

On 2016/05/18 21:29:37, felt wrote:
> On 2016/05/18 20:42:28, csharrison wrote:
> > On 2016/05/18 19:58:38, felt wrote:
> > > On 2016/05/18 19:47:29, csharrison wrote:
> > > > Thanks. The only thing I'm concerned with now is the checks for
TinyDelay.
> > > > 
> > > > Do we know for sure that if we sleep for TinyDelay it is for sure going
to
> > > take
> > > > >= TinyDelay?
> > > 
> > > On my local machine, it always held true. However, from the trybots it
> appears
> > > that at least on Mac this is not the case. :( I can't think of any better
> way
> > to
> > > test a lower bound, unfortunately. You seemed keen on having lower bound
> > checks,
> > > do you think it is important?
> > 
> > The main thing with lower bounds is they assert that you aren't just sending
> 0ms
> > as the engagement time.
> > 
> > Can you do something like
> > 
> > MarkUpperbound();
> > NavigateToURL(url);
> > MarkLowerBoundStart();
> > 
> > ~sleep?~
> > 
> > MarkLowerBoundEnd();
> > DestroyTab();
> > MarkUpperBoundEnd();
> > 
> > If it makes the tests harder to write you could have the methods return the
> > lower bounds, and the inline tests calculate the upper bounds for you.
> > 
> > like:
> > 
> > TEST_F() {
> >   start = Now();
> >   lower_bound = RunTheTest();
> >   upper_bound = Now() - start;
> >   <do assertions w/ upper and lower bounds>
> > }
> 
> This doesn't work as cleanly as it seems. A Bucket comes with a min and a
count.
> The bucket sizes increase as the value increases. If I calculate the lower
bound
> like you've sketched out, it very well might be larger than the Bucket's min
but
> inside the same bucket. (The reason I used 89ms for comparison was because
that
> is a known bucket min value.) So we cannot do a lower bound check in
comparison
> to the min. There are therefore three options:
> 1. Round the lower bound to the nearest Bucket min size. That will require
some
> non-trivial calculations, potentially can make use of
> Histogram::InitializeBucketRanges to help.
> 2. Hard code the Bucket sizes and round to the nearest.
> 3. Add a max to the Bucket class, although I suspect it's intentional that it
> does not have a max.
> 
> I don't mind doing this, but I want to make sure it's worth the additional
> complexity that it will add to the tests (especially around timing, which is
> flakiness-prone to begin with). If the only goal is to make sure we aren't
> sending 0ms or something silly like that, I can do a check for not equal to
0ms
> with a lot less complexity.

Good point. I forgot how much resolution we lose with the bucket sizes. I'm
tempted to go with your solution to just EXPECT(bucket > 0).

In general I would say the upper bound is good to ensure that the background is
not being counted, but the lower bound is good to ensure that we're actually
calculating useful numbers at all. So, I think bucket > 0 fits that criteria.

The other solutions would be to somehow pick the EngagmentObserver out of the
WebContents, and introspect the class directly. Again, this is also complex and
you'd need to write extra boilerplate which would go in production code.

Anyways, I'll leave this up to you. I don't see an easy way to solve this
problem with the traditional approach of just observing histograms.

[felt, 2016-05-18 23:06:25]

On 2016/05/18 21:40:06, csharrison wrote:
> On 2016/05/18 21:29:37, felt wrote:
> > On 2016/05/18 20:42:28, csharrison wrote:
> > > On 2016/05/18 19:58:38, felt wrote:
> > > > On 2016/05/18 19:47:29, csharrison wrote:
> > > > > Thanks. The only thing I'm concerned with now is the checks for
> TinyDelay.
> > > > > 
> > > > > Do we know for sure that if we sleep for TinyDelay it is for sure
going
> to
> > > > take
> > > > > >= TinyDelay?
> > > > 
> > > > On my local machine, it always held true. However, from the trybots it
> > appears
> > > > that at least on Mac this is not the case. :( I can't think of any
better
> > way
> > > to
> > > > test a lower bound, unfortunately. You seemed keen on having lower bound
> > > checks,
> > > > do you think it is important?
> > > 
> > > The main thing with lower bounds is they assert that you aren't just
sending
> > 0ms
> > > as the engagement time.
> > > 
> > > Can you do something like
> > > 
> > > MarkUpperbound();
> > > NavigateToURL(url);
> > > MarkLowerBoundStart();
> > > 
> > > ~sleep?~
> > > 
> > > MarkLowerBoundEnd();
> > > DestroyTab();
> > > MarkUpperBoundEnd();
> > > 
> > > If it makes the tests harder to write you could have the methods return
the
> > > lower bounds, and the inline tests calculate the upper bounds for you.
> > > 
> > > like:
> > > 
> > > TEST_F() {
> > >   start = Now();
> > >   lower_bound = RunTheTest();
> > >   upper_bound = Now() - start;
> > >   <do assertions w/ upper and lower bounds>
> > > }
> > 
> > This doesn't work as cleanly as it seems. A Bucket comes with a min and a
> count.
> > The bucket sizes increase as the value increases. If I calculate the lower
> bound
> > like you've sketched out, it very well might be larger than the Bucket's min
> but
> > inside the same bucket. (The reason I used 89ms for comparison was because
> that
> > is a known bucket min value.) So we cannot do a lower bound check in
> comparison
> > to the min. There are therefore three options:
> > 1. Round the lower bound to the nearest Bucket min size. That will require
> some
> > non-trivial calculations, potentially can make use of
> > Histogram::InitializeBucketRanges to help.
> > 2. Hard code the Bucket sizes and round to the nearest.
> > 3. Add a max to the Bucket class, although I suspect it's intentional that
it
> > does not have a max.
> > 
> > I don't mind doing this, but I want to make sure it's worth the additional
> > complexity that it will add to the tests (especially around timing, which is
> > flakiness-prone to begin with). If the only goal is to make sure we aren't
> > sending 0ms or something silly like that, I can do a check for not equal to
> 0ms
> > with a lot less complexity.
> 
> Good point. I forgot how much resolution we lose with the bucket sizes. I'm
> tempted to go with your solution to just EXPECT(bucket > 0).
> 
> In general I would say the upper bound is good to ensure that the background
is
> not being counted, but the lower bound is good to ensure that we're actually
> calculating useful numbers at all. So, I think bucket > 0 fits that criteria.
> 
> The other solutions would be to somehow pick the EngagmentObserver out of the
> WebContents, and introspect the class directly. Again, this is also complex
and
> you'd need to write extra boilerplate which would go in production code.
> 
> Anyways, I'll leave this up to you. I don't see an easy way to solve this
> problem with the traditional approach of just observing histograms.

I personally don't think the tighter bound is worth the test complexity. I added
the > 0 check, which I think is really the important part. PTAL.

[Steven Holte, 2016-05-18 23:50:22]

lgtm

[Charlie Harrison, 2016-05-19 00:46:10]

LGTM thanks!

[felt, 2016-05-19 00:49:08]

The CQ bit was checked by felt@chromium.org

[commit-bot: I haz the power, 2016-05-19 00:49:32]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1913693002/220001
View timeline at
 https://chromium-cq-status.appspot.com/patch-timeline/1913693002/220001

[commit-bot: I haz the power, 2016-05-19 03:04:54]

Description was changed from

==========
Histogram the amount of time spent on HTTP(S) page loads

This creates three histograms to show how time is distributed by scheme.
The histograms are intended to answer the question:

Do HTTPS page visits tend to be longer than HTTP page visits?

BUG=588941
==========

to

==========
Histogram the amount of time spent on HTTP(S) page loads

This creates three histograms to show how time is distributed by scheme.
The histograms are intended to answer the question:

Do HTTPS page visits tend to be longer than HTTP page visits?

BUG=588941
==========

[commit-bot: I haz the power, 2016-05-19 03:04:57]

Committed patchset #12 (id:220001)

[commit-bot: I haz the power, 2016-05-19 03:07:42]

Description was changed from

==========
Histogram the amount of time spent on HTTP(S) page loads

This creates three histograms to show how time is distributed by scheme.
The histograms are intended to answer the question:

Do HTTPS page visits tend to be longer than HTTP page visits?

BUG=588941
==========

to

==========
Histogram the amount of time spent on HTTP(S) page loads

This creates three histograms to show how time is distributed by scheme.
The histograms are intended to answer the question:

Do HTTPS page visits tend to be longer than HTTP page visits?

BUG=588941

Committed: https://crrev.com/6165ca0c38af8740c831b65ad79655933c0ceb5d
Cr-Commit-Position: refs/heads/master@{#394645}
==========

[commit-bot: I haz the power, 2016-05-19 03:07:43]

Patchset 12 (id:??) landed as
https://crrev.com/6165ca0c38af8740c831b65ad79655933c0ceb5d
Cr-Commit-Position: refs/heads/master@{#394645}