Add Finch experiment to cookie monster.

Add Finch experiment to cookie monster.

The Finch experiment measures the effect of the cookie fetching strategy on
startup time. Under the current logic, as soon as any cookie is requested, all
cookies are fetched. In one of the paths of the Finch experiment, all cookies
are fetched only if all cookies are required.

BUG=473483
Committed: https://crrev.com/1dd72a70454392b22a700a46ba99cc64f2875227
Cr-Commit-Position: refs/heads/master@{#328603}

[erikchen, 2015-04-03 01:33:49]

erikchen@chromium.org changed reviewers:
+ erikwright@chromium.org

[erikchen, 2015-04-03 01:33:49]

erikwright: Please review.

[erikchen, 2015-04-03 02:30:23]

On 2015/04/03 01:33:49, erikchen wrote:
> erikwright: Please review.

The cookie_monster has no behavioral change when the Finch setting is at its
default. All browser tests pass when the LoadWhenNecessary strategy is enabled.

[erikwright (departed), 2015-04-07 22:37:09]

https://codereview.chromium.org/1052373003/diff/20001/content/browser/net/sql...
File content/browser/net/sqlite_persistent_cookie_store.cc (right):

https://codereview.chromium.org/1052373003/diff/20001/content/browser/net/sql...
content/browser/net/sqlite_persistent_cookie_store.cc:471:
DeleteSessionCookiesOnStartup();
Isn't this ineffective here? I would think it should be called from
FinishedLoadingCookies, or (if you follow my next suggestion to make it take a
key) at the end of ChainLoadCookies?

https://codereview.chromium.org/1052373003/diff/20001/content/browser/net/sql...
content/browser/net/sqlite_persistent_cookie_store.cc:492:
DeleteSessionCookiesOnStartup();
This makes me think that, in fact, we have a bug as follows:

* Domain X is loaded.
* A session cookie for domain X is received and stored.
* Some other domains are loaded, completing the load.
* All session cookies are deleted.

This would only delete them from disk (not memory) so the only user-visible
problem is after a session restore.

Your change doesn't cause the bug, just changes the mechanism somewhat.

ideally, DeleteSessionClookiesOnStartup should take a domain key and restrict
its operation to that key.

[erikchen, 2015-04-08 17:44:26]

https://codereview.chromium.org/1052373003/diff/20001/content/browser/net/sql...
File content/browser/net/sqlite_persistent_cookie_store.cc (right):

https://codereview.chromium.org/1052373003/diff/20001/content/browser/net/sql...
content/browser/net/sqlite_persistent_cookie_store.cc:492:
DeleteSessionCookiesOnStartup();
On 2015/04/07 22:37:09, erikwright wrote:
> This makes me think that, in fact, we have a bug as follows:
> 
> * Domain X is loaded.
> * A session cookie for domain X is received and stored.
> * Some other domains are loaded, completing the load.
> * All session cookies are deleted.
> 
> This would only delete them from disk (not memory) so the only user-visible
> problem is after a session restore.
> 
> Your change doesn't cause the bug, just changes the mechanism somewhat.
> 
> ideally, DeleteSessionClookiesOnStartup should take a domain key and restrict
> its operation to that key.

I agree that the previous behavior was incorrect. 

I don't understand why you want to DeleteSessionClookiesOnStartup() by
individual keys. I moved the call into InitializeDatabase(), so it happens
exactly once, immediately after startup, before any cookies are loaded into
memory. That prevents it from deleting session cookies from the current session,
and also ensures that memory/database are in sync.

[erikwright (departed), 2015-04-13 13:47:12]

I believe that the delete might cause a full table scan, which will undo all of
the optimizations you/I have put in place (and also invalidate the results of
your experiment).

https://codereview.chromium.org/1052373003/diff/40001/content/browser/net/sql...
File content/browser/net/sqlite_persistent_cookie_store.cc (left):

https://codereview.chromium.org/1052373003/diff/40001/content/browser/net/sql...
content/browser/net/sqlite_persistent_cookie_store.cc:434: // This function
should be called only once per instance.
Why did this change?

[erikchen, 2015-04-27 22:00:13]

https://codereview.chromium.org/1052373003/diff/40001/content/browser/net/sql...
File content/browser/net/sqlite_persistent_cookie_store.cc (left):

https://codereview.chromium.org/1052373003/diff/40001/content/browser/net/sql...
content/browser/net/sqlite_persistent_cookie_store.cc:434: // This function
should be called only once per instance.
On 2015/04/13 13:47:11, erikwright wrote:
> Why did this change?

I removed this change.

[erikchen, 2015-04-27 22:00:22]

On 2015/04/13 13:47:12, erikwright wrote:
> I believe that the delete might cause a full table scan, which will undo all
of
> the optimizations you/I have put in place (and also invalidate the results of
> your experiment).
> 
>
https://codereview.chromium.org/1052373003/diff/40001/content/browser/net/sql...
> File content/browser/net/sqlite_persistent_cookie_store.cc (left):
> 
>
https://codereview.chromium.org/1052373003/diff/40001/content/browser/net/sql...
> content/browser/net/sqlite_persistent_cookie_store.cc:434: // This function
> should be called only once per instance.
> Why did this change?

erikwright: PTAL

[erikwright (departed), 2015-04-28 17:25:57]

Please wait until you have at least a full day of data from your other recent
changes to verify that they had no impact on any of the relevant metrics (all
those we have previously discussed).

Please also confirm that you have run all of the unit tests with the experiment
enabled and it still passes (or at least that the failures are due to tests that
are too explicitly characterizing the implementation).

Assuming those two things, LGTM.

[erikchen, 2015-04-29 18:22:50]

On 2015/04/28 17:25:57, erikwright wrote:
> Please wait until you have at least a full day of data from your other recent
> changes to verify that they had no impact on any of the relevant metrics (all
> those we have previously discussed).
> 
> Please also confirm that you have run all of the unit tests with the
experiment
> enabled and it still passes (or at least that the failures are due to tests
that
> are too explicitly characterizing the implementation).
> 
> Assuming those two things, LGTM.

We didn't A/B test my recent changes, and there's a lot of noise in Canary, so
there's no good way to tell whether my changes impacted these stats. I looked at
Startup.FirstWebContents.NonEmptyPaint and
Cookie.Startup.StartFetchingAllCookies - there are recent improvements in these
stats, but we have no way of drawing correlations, and it's unclear our much of
the change is noise.

[erikwright (departed), 2015-04-29 18:45:20]

I would think that the following metrics would be interesting:

Cookie.TimeLoad - the sum of the durations of the load tasks in the
persistent store
Cookie.TimeBlockedOnLoad - the wall clock time that the cookie store waits
for the persistent store to load
Cookie.PriorityBlockingTime - the sum of the intervals during which at
least one request is blocked waiting for cookies.

The 1st would seem our best measurement of any impact on load time.
The 3rd would seem our best measurement of impact on latency.

The 3rd seems quite stable. Stable enough that I'd be curious to go back
and investigate some of the bumps in the graph.

https://uma.googleplex.com/timeline_v2?{%22day_count%22:%2290%22,%22end_date%...

Your change only hit Canary on the 28th, so there is 0 data from it. How
about waiting until Friday to see what impact, if any, there is on
Cookie.PriorityBlockingTime?

On Wed, Apr 29, 2015 at 2:22 PM, <erikchen@chromium.org> wrote:

> On 2015/04/28 17:25:57, erikwright wrote:
>
>> Please wait until you have at least a full day of data from your other
>> recent
>> changes to verify that they had no impact on any of the relevant metrics
>> (all
>> those we have previously discussed).
>>
>
>  Please also confirm that you have run all of the unit tests with the
>>
> experiment
>
>> enabled and it still passes (or at least that the failures are due to
>> tests
>>
> that
>
>> are too explicitly characterizing the implementation).
>>
>
>  Assuming those two things, LGTM.
>>
>
> We didn't A/B test my recent changes, and there's a lot of noise in
> Canary, so
> there's no good way to tell whether my changes impacted these stats. I
> looked at
> Startup.FirstWebContents.NonEmptyPaint and
> Cookie.Startup.StartFetchingAllCookies - there are recent improvements in
> these
> stats, but we have no way of drawing correlations, and it's unclear our
> much of
> the change is noise.
>
> https://codereview.chromium.org/1052373003/
>

To unsubscribe from this group and stop receiving emails from it, send an email
to chromium-reviews+unsubscribe@chromium.org.

[erikchen, 2015-04-29 18:59:15]

On 2015/04/29 18:45:20, erikwright wrote:
> I would think that the following metrics would be interesting:
> 
> Cookie.TimeLoad - the sum of the durations of the load tasks in the
> persistent store
> Cookie.TimeBlockedOnLoad - the wall clock time that the cookie store waits
> for the persistent store to load
> Cookie.PriorityBlockingTime - the sum of the intervals during which at
> least one request is blocked waiting for cookies.
> 
> The 1st would seem our best measurement of any impact on load time.
> The 3rd would seem our best measurement of impact on latency.
> 
> The 3rd seems quite stable. Stable enough that I'd be curious to go back
> and investigate some of the bumps in the graph.
> 
>
https://uma.googleplex.com/timeline_v2?{%22day_count%22:%2290%22,%22end_date%...
> 
> Your change only hit Canary on the 28th, so there is 0 data from it. How
> about waiting until Friday to see what impact, if any, there is on
> Cookie.PriorityBlockingTime?
> 
> On Wed, Apr 29, 2015 at 2:22 PM, <mailto:erikchen@chromium.org> wrote:
> 
> > On 2015/04/28 17:25:57, erikwright wrote:
> >
> >> Please wait until you have at least a full day of data from your other
> >> recent
> >> changes to verify that they had no impact on any of the relevant metrics
> >> (all
> >> those we have previously discussed).
> >>
> >
> >  Please also confirm that you have run all of the unit tests with the
> >>
> > experiment
> >
> >> enabled and it still passes (or at least that the failures are due to
> >> tests
> >>
> > that
> >
> >> are too explicitly characterizing the implementation).
> >>
> >
> >  Assuming those two things, LGTM.
> >>
> >
> > We didn't A/B test my recent changes, and there's a lot of noise in
> > Canary, so
> > there's no good way to tell whether my changes impacted these stats. I
> > looked at
> > Startup.FirstWebContents.NonEmptyPaint and
> > Cookie.Startup.StartFetchingAllCookies - there are recent improvements in
> > these
> > stats, but we have no way of drawing correlations, and it's unclear our
> > much of
> > the change is noise.
> >
> > https://codereview.chromium.org/1052373003/
> >
> 
> To unsubscribe from this group and stop receiving emails from it, send an
email
> to mailto:chromium-reviews+unsubscribe@chromium.org.

I'm happy to wait until Friday to measure the impact of my previous changes.
That being said, all of the metrics that you've named:

Cookie.TimeLoad
Cookie.TimeBlockedOnLoad
Cookie.PriorityBlockingTime

are only emitted after the cookie store is loaded. This CL adds an experiment to
prevent the cookie store from loading for most users, so those metrics won't be
relevant to this CL. We should probably move this discussion off of this bug?

[erikwright (departed), 2015-04-29 19:11:11]

On 2015/04/29 18:59:15, erikchen wrote:
> On 2015/04/29 18:45:20, erikwright wrote:
> > I would think that the following metrics would be interesting:
> > 
> > Cookie.TimeLoad - the sum of the durations of the load tasks in the
> > persistent store
> > Cookie.TimeBlockedOnLoad - the wall clock time that the cookie store waits
> > for the persistent store to load
> > Cookie.PriorityBlockingTime - the sum of the intervals during which at
> > least one request is blocked waiting for cookies.
> > 
> > The 1st would seem our best measurement of any impact on load time.
> > The 3rd would seem our best measurement of impact on latency.
> > 
> > The 3rd seems quite stable. Stable enough that I'd be curious to go back
> > and investigate some of the bumps in the graph.
> > 
> >
>
https://uma.googleplex.com/timeline_v2?{%22day_count%22:%2290%22,%22end_date%...
> > 
> > Your change only hit Canary on the 28th, so there is 0 data from it. How
> > about waiting until Friday to see what impact, if any, there is on
> > Cookie.PriorityBlockingTime?
> > 
> > On Wed, Apr 29, 2015 at 2:22 PM, <mailto:erikchen@chromium.org> wrote:
> > 
> > > On 2015/04/28 17:25:57, erikwright wrote:
> > >
> > >> Please wait until you have at least a full day of data from your other
> > >> recent
> > >> changes to verify that they had no impact on any of the relevant metrics
> > >> (all
> > >> those we have previously discussed).
> > >>
> > >
> > >  Please also confirm that you have run all of the unit tests with the
> > >>
> > > experiment
> > >
> > >> enabled and it still passes (or at least that the failures are due to
> > >> tests
> > >>
> > > that
> > >
> > >> are too explicitly characterizing the implementation).
> > >>
> > >
> > >  Assuming those two things, LGTM.
> > >>
> > >
> > > We didn't A/B test my recent changes, and there's a lot of noise in
> > > Canary, so
> > > there's no good way to tell whether my changes impacted these stats. I
> > > looked at
> > > Startup.FirstWebContents.NonEmptyPaint and
> > > Cookie.Startup.StartFetchingAllCookies - there are recent improvements in
> > > these
> > > stats, but we have no way of drawing correlations, and it's unclear our
> > > much of
> > > the change is noise.
> > >
> > > https://codereview.chromium.org/1052373003/
> > >
> > 
> > To unsubscribe from this group and stop receiving emails from it, send an
> email
> > to mailto:chromium-reviews+unsubscribe@chromium.org.
> 
> I'm happy to wait until Friday to measure the impact of my previous changes.
> That being said, all of the metrics that you've named:
> 
> Cookie.TimeLoad
> Cookie.TimeBlockedOnLoad
> Cookie.PriorityBlockingTime
> 
> are only emitted after the cookie store is loaded. This CL adds an experiment
to
> prevent the cookie store from loading for most users, so those metrics won't
be
> relevant to this CL. We should probably move this discussion off of this bug?

I'm afraid of moving too fast, landing a series of CLs and then finding out that
the first of the series introduced a significant regression.

[erikchen, 2015-05-06 00:39:04]

On 2015/04/29 19:11:11, erikwright wrote:
> On 2015/04/29 18:59:15, erikchen wrote:
> > On 2015/04/29 18:45:20, erikwright wrote:
> > > I would think that the following metrics would be interesting:
> > > 
> > > Cookie.TimeLoad - the sum of the durations of the load tasks in the
> > > persistent store
> > > Cookie.TimeBlockedOnLoad - the wall clock time that the cookie store waits
> > > for the persistent store to load
> > > Cookie.PriorityBlockingTime - the sum of the intervals during which at
> > > least one request is blocked waiting for cookies.
> > > 
> > > The 1st would seem our best measurement of any impact on load time.
> > > The 3rd would seem our best measurement of impact on latency.
> > > 
> > > The 3rd seems quite stable. Stable enough that I'd be curious to go back
> > > and investigate some of the bumps in the graph.
> > > 
> > >
> >
>
https://uma.googleplex.com/timeline_v2?{%22day_count%22:%2290%22,%22end_date%...
> > > 
> > > Your change only hit Canary on the 28th, so there is 0 data from it. How
> > > about waiting until Friday to see what impact, if any, there is on
> > > Cookie.PriorityBlockingTime?
> > > 
> > > On Wed, Apr 29, 2015 at 2:22 PM, <mailto:erikchen@chromium.org> wrote:
> > > 
> > > > On 2015/04/28 17:25:57, erikwright wrote:
> > > >
> > > >> Please wait until you have at least a full day of data from your other
> > > >> recent
> > > >> changes to verify that they had no impact on any of the relevant
metrics
> > > >> (all
> > > >> those we have previously discussed).
> > > >>
> > > >
> > > >  Please also confirm that you have run all of the unit tests with the
> > > >>
> > > > experiment
> > > >
> > > >> enabled and it still passes (or at least that the failures are due to
> > > >> tests
> > > >>
> > > > that
> > > >
> > > >> are too explicitly characterizing the implementation).
> > > >>
> > > >
> > > >  Assuming those two things, LGTM.
> > > >>
> > > >
> > > > We didn't A/B test my recent changes, and there's a lot of noise in
> > > > Canary, so
> > > > there's no good way to tell whether my changes impacted these stats. I
> > > > looked at
> > > > Startup.FirstWebContents.NonEmptyPaint and
> > > > Cookie.Startup.StartFetchingAllCookies - there are recent improvements
in
> > > > these
> > > > stats, but we have no way of drawing correlations, and it's unclear our
> > > > much of
> > > > the change is noise.
> > > >
> > > > https://codereview.chromium.org/1052373003/
> > > >
> > > 
> > > To unsubscribe from this group and stop receiving emails from it, send an
> > email
> > > to mailto:chromium-reviews+unsubscribe@chromium.org.
> > 
> > I'm happy to wait until Friday to measure the impact of my previous changes.
> > That being said, all of the metrics that you've named:
> > 
> > Cookie.TimeLoad
> > Cookie.TimeBlockedOnLoad
> > Cookie.PriorityBlockingTime
> > 
> > are only emitted after the cookie store is loaded. This CL adds an
experiment
> to
> > prevent the cookie store from loading for most users, so those metrics won't
> be
> > relevant to this CL. We should probably move this discussion off of this
bug?
> 
> I'm afraid of moving too fast, landing a series of CLs and then finding out
that
> the first of the series introduced a significant regression.

I've confirmed using UMA timeline v2 that there's been no major change to
Cookie.Timeload, Cookie.TimeBlockedOnLoad, or Cookie.PriorityBlockingTime in
Chrome Canary on Windows or Mac.

The largest change was in Windows for Cookie.TimeBlockedOnLoad, which changed
from ~160ms in the previous week to ~200ms in the days after I landed my CL.
This looks significant, but the graph itself has a huge amount of noise. e.g.
two weeks before my change landed, it spiked to 292 ms.

[erikchen, 2015-05-06 18:29:50]

erikwright: PTAL.

I removed the DCHECK from Load(). Prior to this CL, the semantics of Load()
were: 
This method should be called exactly once, immediately after the cookie store
has been initialized. It will attempt to load all cookies from disk, and as a
side effect, it will also initialize the cookie DB. The cookie DB must not be
initialized.

With the deferred load, the semantics become:
This method must be called at most once. It is not guaranteed to be called. It
will attempt to load all cookies from disk. If necessary, it will initialize the
cookie DB.

If the Finch experiment shows positive results, I will rename the method to
"LoadAllCookies" and update the description appropriately. For this CL, I've
removed the DCHECK and added a comment to this effect in cookie_monster.h.

[erikwright (departed), 2015-05-06 18:36:31]

LGTM.

If the experiment pans out, is there any reason anyone would ever all
LoadAllCookies?

[erikchen, 2015-05-06 19:28:51]

On 2015/05/06 18:36:31, erikwright wrote:
> LGTM.
> 
> If the experiment pans out, is there any reason anyone would ever all
> LoadAllCookies?

GetAllCookiesAsync() would need to call LoadAllCookies(), at the very least.

[erikchen, 2015-05-06 19:30:28]

On 2015/05/06 19:28:51, erikchen wrote:
> On 2015/05/06 18:36:31, erikwright wrote:
> > LGTM.
> > 
> > If the experiment pans out, is there any reason anyone would ever all
> > LoadAllCookies?
> 
> GetAllCookiesAsync() would need to call LoadAllCookies(), at the very least.

With deferred load forced on,

net_unittests has failures in:
    DeferredCookieTaskTest.DeferredDeleteAllForHostCookies
    DeferredCookieTaskTest.DeferredDeleteCookie
    DeferredCookieTaskTest.DeferredGetAllForUrlCookies
    DeferredCookieTaskTest.DeferredGetAllForUrlWithOptionsCookies
    DeferredCookieTaskTest.DeferredGetCookies
    DeferredCookieTaskTest.DeferredSetCookie
    DeferredCookieTaskTest.DeferredSetCookieWithDetails
    DeferredCookieTaskTest.DeferredTaskOrder
    MultiThreadedCookieMonsterTest.GetAllCookiesForURLEffectiveDomain

This is expected, since each of those tests relies on the timing of an
OnLoaded() callback.

content_unittests pass.
browser_tests pass (ignoring 2 android related tests)

browser_tests passing is the most important, since it has several suites of
functional tests that use the cookie store.

[erikchen, 2015-05-06 19:33:25]

The CQ bit was checked by erikchen@chromium.org

[commit-bot: I haz the power, 2015-05-06 19:35:01]

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

[commit-bot: I haz the power, 2015-05-06 20:45:15]

Committed patchset #5 (id:80001)

[commit-bot: I haz the power, 2015-05-06 20:46:14]

Patchset 5 (id:??) landed as
https://crrev.com/1dd72a70454392b22a700a46ba99cc64f2875227
Cr-Commit-Position: refs/heads/master@{#328603}