5 - 11.76% sessionrestore / sessionrestore_no_auto_restore / ts_paint (linux64) regression on push 06d6f928ed649f4d2978025a9c3535432dbb5ab8 (Wed May 10 2017)

RESOLVED FIXED in Firefox 55

Status

()

defect
RESOLVED FIXED
2 years ago
2 years ago

People

(Reporter: jmaher, Assigned: MattN)

Tracking

(Depends on 1 bug, {perf, regression, talos-regression})

53 Branch
mozilla55
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox-esr52 unaffected, firefox53 unaffected, firefox54 unaffected, firefox55 fixed)

Details

()

Attachments

(4 attachments)

Talos has detected a Firefox performance regression from push 06d6f928ed649f4d2978025a9c3535432dbb5ab8. As author of one of the patches included in that push, we need your help to address this regression.

Regressions:

 12%  sessionrestore_no_auto_restore linux64 opt e10s     713.08 -> 796.92
 11%  sessionrestore linux64 opt e10s                     687.42 -> 762.67
  5%  ts_paint linux64 opt e10s                           1,162.08 -> 1,220.17

Improvements:

  2%  tsvgr_opacity summary linux64 pgo      364.37 -> 356.76
  2%  cart summary linux64 opt e10s          29.79 -> 29.32
  1%  cart summary linux64 pgo e10s          22.58 -> 22.27


You can find links to graphs and comparison views for each of the above tests at: https://treeherder.mozilla.org/perf.html#/alerts?id=6536

On the page above you can see an alert for each affected platform as well as a link to a graph showing the history of scores for this test. There is also a link to a treeherder page showing the Talos jobs in a pushlog format.

To learn more about the regressing test(s), please see: https://wiki.mozilla.org/Buildbot/Talos/Tests

For information on reproducing and debugging the regression, either on try or locally, see: https://wiki.mozilla.org/Buildbot/Talos/Running

*** Please let us know your plans within 3 business days, or the offending patch(es) will be backed out! ***

Our wiki page outlines the common responses and expectations: https://wiki.mozilla.org/Buildbot/Talos/RegressionBugsHandling
there is broken functionality on our trees so I cannot easily backfill and find the root cause.  Here is a range of commits:
https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=a5e5a6e086f8689b1a481af2393a52deeca25e27&tochange=06d6f928ed649f4d2978025a9c3535432dbb5ab8

I have included all reviewers and authors on this email.
:tnikkel, can you comment on the chance of your patch in Bug 1342567 causing these regressions.
Flags: needinfo?(tnikkel)
:dao, can you comment on the chance of your patch in Bug 1363840 causing these regressions.
Flags: needinfo?(dao+bmo)
:gijs, can you comment on the chance of your patch in Bug 1354094 causing these regressions.
Flags: needinfo?(gijskruitbosch+bugs)
:mattn, can you comment on the chance of your patches in Bug 1362571 and bug 1361560 causing these regressions.
Flags: needinfo?(MattN+bmo)
(In reply to Joel Maher ( :jmaher) from comment #3)
> :dao, can you comment on the chance of your patch in Bug 1363840 causing
> these regressions.

I can't rule it out although it seems rather unlikely to me.

Rendering the reload and stop buttons as regular buttons outside of the url bar shouldn't be significantly more expensive than rendering them as special buttons in the url bar. In fact the tsvgr_opacity and cart improvements suggest to me that it might be slightly cheaper. There's also no tresize regression. (From what I understand, tresize is very sensitive to rendering the UI becoming more expensive.)

Finally, it seems counterintuitive that this would regress e10s startup perf but not non-e10s. So I'd be surprised if this was the cause, but that wouldn't be the first time.
Flags: needinfo?(dao+bmo)
(In reply to Joel Maher ( :jmaher) from comment #5)
> :mattn, can you comment on the chance of your patches in Bug 1362571

The chances of this being from bug 1362571 are near 0 since it was just moving a button in about:preferences.

> and bug 1361560 causing these regressions.

Looking at bug 1361560 comment 3 I only saw minor regressions but now I realize that the automatic re-trigger of 5 runs didn't seem to work for linux64…
No longer blocks: 1362571
(In reply to Joel Maher ( :jmaher) from comment #2)
> :tnikkel, can you comment on the chance of your patch in Bug 1342567 causing
> these regressions.

Very unlikely. The patch just added a MOZ_RELEASE_ASSERT(false), if we were executing this code then Firefox would be crashing.
Flags: needinfo?(tnikkel)
(In reply to Matthew N. [:MattN] (PM if requests are blocking you) from comment #7)
> (In reply to Joel Maher ( :jmaher) from comment #5)
> > and bug 1361560 causing these regressions.
> 
> Looking at bug 1361560 comment 3 I only saw minor regressions but now I
> realize that the automatic re-trigger of 5 runs didn't seem to work for
> linux64…

Now that I manually re-triggered the linux64 and os x talos jobs on my try push I see the same regressions :( It's very frustrating to learn that the automation failed me since I proactively used --rebuild-talos 5 and it didn't work on linux64 and os x so I was fooled into thinking I didn't regress anything…

I will try figure out the cause now.
Assignee: nobody → MattN+bmo
Status: NEW → ASSIGNED
No longer blocks: 1354094, 1363840
thanks :mattn, let me know if I can help with any try retriggers, validation, etc.
Component: Untriaged → Session Restore
Profiling of startup pointed me to our stylesheet addition code: https://dxr.mozilla.org/mozilla-central/rev/1e2fe13035e13b7b4001ade3b48f226957cef5fc/browser/extensions/formautofill/bootstrap.js#34,38

I have a try push to use requestIdleCallback after the load event since we don't need the stylesheet immediately, only before the first form autofill popup is opened. I'm waiting for results at https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=c5bf38704c5e28f7dd45a315ea113d7a6bc682f9&newProject=try&newRevision=7c21c4700ed54367f823acd91f213c588c1cc0ff&framework=1&showOnlyImportant=0
Component: Session Restore → Form Manager
Flags: needinfo?(MattN+bmo)
Product: Firefox → Toolkit
Is bug 1364421 the reason why I'm also not getting any osx or linux64 talos results on the above pushes?

Also, is the --rebuild-talos 5 brokenness from comment 10 known?
Flags: needinfo?(jmaher)
I've wasted a lot of time on this bug already due to automation issues… it reminds me why people cringe when a talos regression is mentioned…

The other automation failure that I didn't already complain about is that `./mach talos-test -a ts_paint` gave a python venv file not found error on my linux64 vm which meant I couldn't get an SPS profile from it.
the automation jobs are not scheduled because of bug 1363409.  A typical workaround is to just add jobs after the fact, but bug 1364421 prevents us from doing that.  workaround, push to try with |-t all|.

as for the --rebuild-talos being broken, yes that is known and should be fixed as of 3 days ago with bug 1317189.

Please pastebin your error from ./mach talos-test.  I know that was working yesterday on linux, but possibly there is more work to do there.
Flags: needinfo?(jmaher)
(In reply to Joel Maher ( :jmaher) from comment #15)
> the automation jobs are not scheduled because of bug 1363409.  A typical
> workaround is to just add jobs after the fact, but bug 1364421 prevents us
> from doing that.  workaround, push to try with |-t all|.

I'm sure you agree but this is a horrible situation… we should have tests to avoid both of those things being broken…

I hope `-t all` will work but so far it's not… I'll wait a bit longer: https://treeherder.mozilla.org/#/jobs?repo=try&author=mozilla@noorenberghe.ca&fromchange=41c565a75384041b90a7d4d4d5a0b5c3f5f04117&group_state=expanded&tochange=25da5ac341fee01146b8cb4febf2d239cac16e7e

> as for the --rebuild-talos being broken, yes that is known and should be
> fixed as of 3 days ago with bug 1317189.

Good to know

> Please pastebin your error from ./mach talos-test.  I know that was working
> yesterday on linux, but possibly there is more work to do there.

I filed bug 1364704
Clearing ni per comment #10.
Flags: needinfo?(gijskruitbosch+bugs)
This is a bit tricky to investigate since there was another regression (bug 1364488) to these same 3 tests (plus more) the day after which affects the % change on potential fixes. I'm pushing my potential fixes on the original inbound revision now to use that as a baseline without getting interference from changes in the meantime.

https://treeherder.mozilla.org/#/jobs?repo=try&author=mozilla@noorenberghe.ca&fromchange=3bd7fd902adaf646044875c2d67e324852f7018c&group_state=expanded&tochange=57235b7f45648783eb06cde192739ccce9accb0c

Bug 1348031 is also necessary to do useful profiling of startup. I'm trying to figure out what exact part of bootstrap.js is the main bottleneck:
a) `Services.wm.addListener(…)`
b) `domWindow.addEventListener("load", onWindowLoaded)` from within that wm listener
c) insertStyleSheet which creates a stylesheet with an xml p.i. which may cause a layout/style reflush/reflow

A potential solution is to only append the stylesheet the first time something in the window will open an autocomplete popup. That should be possible but I'm not sure if the timing of the current messages and appending the stylesheet is good enough as I need to ensure that the -moz-binding is attached before the popup opens to avoid a flicker. That solution would get rid of (a) and (b) but simply delays (c) to a later time which may jank some other animation which is why determining the issue is important.

We may be able to do (c) in requestAnimationFrame to avoid dirtying layout/style at a bad time. See https://developer.mozilla.org/en-US/Firefox/Performance_best_practices_for_Firefox_fe_engineers#Detecting_and_avoiding_synchronous_reflow
Depends on: 1348031
The issue could also be I/O of initializing autofill-profiles.json but the warmup to create the profile before ts_paint should do that for us… unless it doesn't wait long enough?

New try push to skip initializing FormAutofillParent: https://treeherder.mozilla.org/#/jobs?repo=try&revision=0a15b90d9b606ec6f5f215900437989a67f0aa14
OK, so the data that just came in shows that despite not showing up in the profiler (probably due to the 1ms interval cap before bug 1348031), the problem is mostly related to initializing FormAutofillParent (comment 19) and the remaining small regression would be from things mentioned in comment 18 which I have a patch for.

I'll need to dig more into comment 19 and figure out why FormAutofillParent's initialization is so expensive… or how we can do it lazier. The current architecture relied on it being initialized in order to set initialProcessData before a form field gets focused. Maybe we can change that do only initialize upon the first form field focus? We should first profile to see what exactly is expensive though.
Comment on attachment 8868066 [details]
Bug 1364477 - Only append formautofill.css the first time autocomplete is opening.

https://reviewboard.mozilla.org/r/139672/#review142964

::: browser/extensions/formautofill/bootstrap.js:38
(Diff revision 1)
>  function startup() {
>    if (!Services.prefs.getBoolPref("browser.formautofill.experimental")) {
>      return;
>    }
>  
> -  let parent = new FormAutofillParent();
> +  Services.mm.addMessageListener("FormAutoComplete:MaybeOpenPopup", function onMaybeOpenPopup(evt) {

TODO: Test with non-e10s.
Profile calling init on a FAP instance from the Browser Console: https://perfht.ml/2rlucZv (filter on autofill)
as a note, we are not running non-e10s talos on the trees anymore (technically right now windows runs, we are just waiting for a patch to deploy)
Comment on attachment 8868066 [details]
Bug 1364477 - Only append formautofill.css the first time autocomplete is opening.

https://reviewboard.mozilla.org/r/139672/#review143068

::: browser/extensions/formautofill/bootstrap.js:38
(Diff revision 1)
>  function startup() {
>    if (!Services.prefs.getBoolPref("browser.formautofill.experimental")) {
>      return;
>    }
>  
> -  let parent = new FormAutofillParent();
> +  Services.mm.addMessageListener("FormAutoComplete:MaybeOpenPopup", function onMaybeOpenPopup(evt) {

should we removeMessageListener() when shutdown?
---
not 100% sure, but it seems prior to this point, we might match https://dxr.mozilla.org/mozilla-central/rev/3e166b6838931b3933ca274331f9e0e115af5cc0/toolkit/content/xul.css#1187-1189 first, then match 
https://dxr.mozilla.org/mozilla-central/rev/3e166b6838931b3933ca274331f9e0e115af5cc0/browser/extensions/formautofill/content/formautofill.css#12 after our handler. Would it cost more time if this case?
Comment on attachment 8868067 [details]
Bug 1364477 - Only getAll Address Profiles once at initialization.

What do you think of this approach to use the field names to determine the status instead of another getAll access?

This patch is probably less necessary with part 3 but maybe the API changes without the .count change is still nice?
Attachment #8868067 - Flags: feedback?(schung)
Attachment #8868067 - Flags: feedback?(lchang)
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

What do you think of this general approach?

It seems to account for most of the regression[1]. With part 1 there will be no regression remaining, maybe even an improvement.


[1] https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=3bd7fd902adaf646044875c2d67e324852f7018c&newProject=try&newRevision=5a220c7c499c8f13321cf376ec5212edd50541b6&framework=1&filter=linux64%20e10s&showOnlyImportant=0
Attachment #8868439 - Flags: feedback?(selee)
Attachment #8868439 - Flags: feedback?(lchang)
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review143368

::: browser/extensions/formautofill/FormAutofillContent.jsm:96
(Diff revision 1)
>      this.log.debug("startSearch: for", searchString, "with input", formFillController.focusedInput);
>      let focusedInput = formFillController.focusedInput;
>      this.forceStop = false;
>      let info = FormAutofillContent.getInputDetails(focusedInput);
>  
> -    if (!FormAutofillContent.savedFieldNames.has(info.fieldName) ||
> +    if (!FormAutofillContent.savedFieldNames.has(info.fieldName) || // TODO

IIUC, the TODO here is for waiting savedFieldNames/InitParent ready.

::: browser/extensions/formautofill/FormAutofillContent.jsm:409
(Diff revision 1)
> +    if (!this.savedFieldNames) {
> +      this.log.debug("identifyAutofillFields: savedFieldNames are not known yet");
> +      Services.cpmm.sendAsyncMessage("FormAutofill:InitParent");
> +      this.log.trace("sent FormAutofill:InitParent");
> +    }
> +

`identifyAutofillFields` is also for heuristics code path. If `InitParent` and heuristics are both heavy tasks, the response time could be an issue. That would be better if we can find a timeslot to initialize Parent/Storage before identifyAutofillFields.

However, `savedFieldNames` check is still necessary here to trigger `InitParent`.

::: browser/extensions/formautofill/FormAutofillParent.jsm:94
(Diff revision 1)
> +    }
> +
> +    log.trace("init _profileStore");
> +    let storePath = OS.Path.join(OS.Constants.Path.profileDir, PROFILE_JSON_FILE_NAME);
> +    this.__profileStore = new ProfileStorage(storePath);
> +    this.__profileStore.initialize();

`profileStorage.initialize` is async now in the latest m-c.
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review143368

> `profileStorage.initialize` is async now in the latest m-c.

The patch needs to be rebased to m-c since ProfileStorage is a singleton now. In the latest patch, `await profileStorage.initialize`[1] blocks the following flow, this could be the reason why we don't see the performance regression in WW.
IMO, `await profileStorage.initialize` is still correct here to make sure the following behavior is based on the storage initialized.

[1] http://searchfox.org/mozilla-central/rev/9a7fbdee1d54f99cd548af95b81231d80e5f9ad1/browser/extensions/formautofill/FormAutofillParent.jsm#69
Comment on attachment 8868067 [details]
Bug 1364477 - Only getAll Address Profiles once at initialization.

Yeah, I also prefer this API change.
Attachment #8868067 - Flags: feedback?(lchang) → feedback+
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review143434

::: browser/extensions/formautofill/FormAutofillContent.jsm:96
(Diff revision 1)
>      this.log.debug("startSearch: for", searchString, "with input", formFillController.focusedInput);
>      let focusedInput = formFillController.focusedInput;
>      this.forceStop = false;
>      let info = FormAutofillContent.getInputDetails(focusedInput);
>  
> -    if (!FormAutofillContent.savedFieldNames.has(info.fieldName) ||
> +    if (!FormAutofillContent.savedFieldNames.has(info.fieldName) || // TODO

Since we won't register `ProfileAutocomplete` until receiving `FormAutofill:enabledStatus` event, which means `profileStorage` is ready, I think we can assume `savedFieldNames` is always ready when `startSearch` is invoked.
Comment on attachment 8868067 [details]
Bug 1364477 - Only getAll Address Profiles once at initialization.

This idea looks fine to me. Although it would not become an issue if we delay the storage init, it's still good to spend less time in storage init. I might take time time to think about the 3rd patch as well.
Attachment #8868067 - Flags: feedback?(schung) → feedback+
Comment on attachment 8868066 [details]
Bug 1364477 - Only append formautofill.css the first time autocomplete is opening.

https://reviewboard.mozilla.org/r/139672/#review143762

I've tested this patch on the latest central codebase and it works fine.
Attachment #8868066 - Flags: review?(lchang) → review+
Comment on attachment 8868066 [details]
Bug 1364477 - Only append formautofill.css the first time autocomplete is opening.

https://reviewboard.mozilla.org/r/139672/#review143068

> should we removeMessageListener() when shutdown?
> ---
> not 100% sure, but it seems prior to this point, we might match https://dxr.mozilla.org/mozilla-central/rev/3e166b6838931b3933ca274331f9e0e115af5cc0/toolkit/content/xul.css#1187-1189 first, then match 
> https://dxr.mozilla.org/mozilla-central/rev/3e166b6838931b3933ca274331f9e0e115af5cc0/browser/extensions/formautofill/content/formautofill.css#12 after our handler. Would it cost more time if this case?

Yeah, I'll add the removeMessageListener to avoid it getting recorded as a leak.

I'm not sure what you're asking… Would it take more time to do what?
Comment on attachment 8868066 [details]
Bug 1364477 - Only append formautofill.css the first time autocomplete is opening.

https://reviewboard.mozilla.org/r/139672/#review143068

> Yeah, I'll add the removeMessageListener to avoid it getting recorded as a leak.
> 
> I'm not sure what you're asking… Would it take more time to do what?

Sorry I didn't make it clear. I was worry if it's possible to occur binding switching (from richlistbox.xml#richlistitem to formautofill.xml#autocomplete-profile-listitem) in a short time(maybe depends on how fast is CSS parsing?) and cause a flicker. 

But since Luke has tested the patch and didn't found flicker, I think it's fine then.
Comment on attachment 8868066 [details]
Bug 1364477 - Only append formautofill.css the first time autocomplete is opening.

https://reviewboard.mozilla.org/r/139672/#review143942

Thanks
Attachment #8868066 - Flags: review?(ralin) → review+
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review144422

::: browser/extensions/formautofill/FormAutofillContent.jsm:406
(Diff revision 3)
>    identifyAutofillFields(doc) {
>      this.log.debug("identifyAutofillFields:", "" + doc.location);
> +
> +    if (!this.savedFieldNames) {
> +      this.log.debug("identifyAutofillFields: savedFieldNames are not known yet");
> +      Services.cpmm.sendAsyncMessage("FormAutofill:InitParent");

If we decide to delay the storage init in identifyAutofillFields which should happens while input is focused in, doesn't that imply the ProfileAutocomplete might be registered "after" element focused? ProfileAutocomplete could be registered while (1) initialProcessData autofillEnabled is true in content init (2) enable status changes to true, and both cases might not exist if we delay the storage init until identifyAutofillFields, and profile autocomplete could not be launched unless re-focus.

Maybe we could register the profile autocomplete only by checking the enabled pref, and let it decide to fallback or not in startSearch. I think it's safer for the first focused input, wdyt?
Attachment #8868439 - Flags: review?(schung)
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review144422

> If we decide to delay the storage init in identifyAutofillFields which should happens while input is focused in, doesn't that imply the ProfileAutocomplete might be registered "after" element focused? ProfileAutocomplete could be registered while (1) initialProcessData autofillEnabled is true in content init (2) enable status changes to true, and both cases might not exist if we delay the storage init until identifyAutofillFields, and profile autocomplete could not be launched unless re-focus.
> 
> Maybe we could register the profile autocomplete only by checking the enabled pref, and let it decide to fallback or not in startSearch. I think it's safer for the first focused input, wdyt?

I had noticed this but wasn't sure of a good solution yet. I like your idea so I implemented that but only in the case where autofillEnabled is null so we don't register needlessly after storage is initialized. Hopefully this doesn't regress tp5.
Comment on attachment 8869337 [details]
Bug 1364477 - Remove FormAutofillParent.init logging to load logging code later.

https://reviewboard.mozilla.org/r/140968/#review144466
Attachment #8869337 - Flags: review?(schung) → review+
Comment on attachment 8868067 [details]
Bug 1364477 - Only getAll Address Profiles once at initialization.

https://reviewboard.mozilla.org/r/139674/#review144474

::: browser/extensions/formautofill/test/unit/test_activeStatus.js:25
(Diff revision 4)
>    do_check_eq(Services.ppmm.initialProcessData.autofillEnabled, false);
>  
>    formAutofillParent._uninit();
>  });
>  
> -add_task(function* test_enabledStatus_observe() {
> +add_task(function* test_activeStatus_observe() {

nit: You could change to await since you're editing the test.
Attachment #8868067 - Flags: review?(schung) → review+
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review144500

I think this could work theoretically, but it would have a side effect that address autofill could not be able to display immediately in the first focused input. It might not a serious problem since it will display eventually, but I just wonder if it would cause intermittent error in mochitest if we try to verify the dropdown menu result.

::: browser/extensions/formautofill/FormAutofillContent.jsm:412
(Diff revision 4)
>    identifyAutofillFields(doc) {
>      this.log.debug("identifyAutofillFields:", "" + doc.location);
> +
> +    if (!this.savedFieldNames) {
> +      this.log.debug("identifyAutofillFields: savedFieldNames are not known yet");
> +      Services.cpmm.sendAsyncMessage("FormAutofill:InitParent");

nit: Maybe the message could be "InitStorage" to specify that we'll need to initialized storgae for savedFieldNames?

::: browser/extensions/formautofill/FormAutofillParent.jsm:57
(Diff revision 4)
> +  // Once storage is loaded we need to update saved field names and inform content processes.
> +  XPCOMUtils.defineLazyGetter(this, "profileStorage", () => {
> +    let {profileStorage} = Cu.import("resource://formautofill/ProfileStorage.jsm", {});
> +    log.debug("Loading profileStorage");
> +
> +    profileStorage.initialize().then(function onStorageInitialized() {

Not sure if it works, but maybe we can init storage and updateSavedFieldNames only in initParent? And maybe we can call updateSavedFieldNames directly instead of waiting promise return since updateSavedFieldNames will trigger ensureDataReady. I know it's not a good coding style, but I just wonder if we could get the profile as early as possible in initParent.
Attachment #8868439 - Flags: review?(schung)
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review144898

This patch

::: browser/extensions/formautofill/FormAutofillContent.jsm:96
(Diff revision 4)
>      this.log.debug("startSearch: for", searchString, "with input", formFillController.focusedInput);
>      let focusedInput = formFillController.focusedInput;
>      this.forceStop = false;
>      let info = FormAutofillContent.getInputDetails(focusedInput);
>  
>      if (!FormAutofillContent.savedFieldNames.has(info.fieldName) ||

`TypeError: FormAutofillContent.savedFieldNames is undefined` here when users press down key to trigger popup during storage/parent initialization.

::: browser/extensions/formautofill/FormAutofillContent.jsm:314
(Diff revision 4)
> +    if (autofillEnabled ||
> +        // If storage hasn't be initialized yet autofillEnabled is undefined but we need to ensure
> +        // autocomplete is registered before the focusin so register it in this case as long as the
> +        // pref is true.
> +        (autofillEnabled === undefined &&
> +         Services.prefs.getBoolPref("extensions.formautofill.addresses.enabled"))) {

This patch fixes the case of the following steps:
1. a user clicks one field (focus-in)
2. wait for parent/storage initialized.
3. press down-key or click the field to trigger the popup.

I found there is another similar procedure can not be fulfilled:
1. a user clicks one field (focus-in)
2. `DO NOT` wait for parent/storage initialized.
3. press down-key or click the field to trigger the popup.

The second can happen when a user double-clicks a field.
(first click => focus-in, second click => trigger startSearch)

I am not sure if it's caused by this patch. I would like to discuss this issue in another bug to not block this one.

::: browser/extensions/formautofill/FormAutofillParent.jsm:57
(Diff revision 4)
> +  // Once storage is loaded we need to update saved field names and inform content processes.
> +  XPCOMUtils.defineLazyGetter(this, "profileStorage", () => {
> +    let {profileStorage} = Cu.import("resource://formautofill/ProfileStorage.jsm", {});
> +    log.debug("Loading profileStorage");
> +
> +    profileStorage.initialize().then(function onStorageInitialized() {

We could even consider removing the usage of `profileStorage.initialize()` here if [1] is moved to its constructor.

As Steve mentioned, `updateSavedFieldNames` can be invoked in "FormAutofill:InitParent" handler. Then we don't need `profileStorage.initialize` in the handler as well. The message name can be renamed to "FormAutofill:UpdateSavedFieldNames".

Another reason to avoid using `profileStorage.initialize()` or `this._store.load()` in ProfileStorage.jsm is that the JSON file could be read twice if the first accesses to this.profileStorage. e.g. `this.profileStorage.addresses.getAll()`.

[1] http://searchfox.org/mozilla-central/rev/15edcfd962be2c8cfdd0b8a96102150703bd4ac5/browser/extensions/formautofill/ProfileStorage.jsm#582-585
Attachment #8868439 - Flags: review?(selee)
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review144966

::: browser/extensions/formautofill/FormAutofillContent.jsm:314
(Diff revision 4)
> +    if (autofillEnabled ||
> +        // If storage hasn't be initialized yet autofillEnabled is undefined but we need to ensure
> +        // autocomplete is registered before the focusin so register it in this case as long as the
> +        // pref is true.
> +        (autofillEnabled === undefined &&
> +         Services.prefs.getBoolPref("extensions.formautofill.addresses.enabled"))) {

One addition here...

For the second case, the users won't see the popup if `startSearch` is invoked before storage initialized.  The way to show the popup again is to focus on the field again.
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review144500

It shouldn't cause a problem if we write our mochitests properly to listen for the popupshown event.

> nit: Maybe the message could be "InitStorage" to specify that we'll need to initialized storgae for savedFieldNames?

Fine with me. I was thinking we may need to init other things in the parent but for now it is just storage.

> Not sure if it works, but maybe we can init storage and updateSavedFieldNames only in initParent? And maybe we can call updateSavedFieldNames directly instead of waiting promise return since updateSavedFieldNames will trigger ensureDataReady. I know it's not a good coding style, but I just wonder if we could get the profile as early as possible in initParent.

> Not sure if it works, but maybe we can init storage and updateSavedFieldNames only in initParent?

IIUC, only initializing storage in initParent may cause problems if storage is first accessed my the parent process e.g. the user opens autofill preferences before visiting a form.

The reason for updating updateSavedFieldNames as soon as we can for free (not getting a performance penalty due to storage already being initialized is to avoid the delay on the first autocomplete popup that you were concerned about above.

>   And maybe we can call updateSavedFieldNames directly instead of waiting promise return since updateSavedFieldNames will trigger ensureDataReady. I know it's not a good coding style, but I just wonder if we could get the profile as early as possible in initParent.

I would rather avoid the sync. I/O, if possible. We can make initialization more agressive in a follow-up if it causes problems.
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review144898

> This patch fixes the case of the following steps:
> 1. a user clicks one field (focus-in)
> 2. wait for parent/storage initialized.
> 3. press down-key or click the field to trigger the popup.
> 
> I found there is another similar procedure can not be fulfilled:
> 1. a user clicks one field (focus-in)
> 2. `DO NOT` wait for parent/storage initialized.
> 3. press down-key or click the field to trigger the popup.
> 
> The second can happen when a user double-clicks a field.
> (first click => focus-in, second click => trigger startSearch)
> 
> I am not sure if it's caused by this patch. I would like to discuss this issue in another bug to not block this one.

Yeah, this is a known limitation of the approach but I thought that if they do a new search by typing then it would fix itself so I didn't really care. From your next comment it seems like that may not be the case and a re-focus is needed? I will file a follow-up

> We could even consider removing the usage of `profileStorage.initialize()` here if [1] is moved to its constructor.
> 
> As Steve mentioned, `updateSavedFieldNames` can be invoked in "FormAutofill:InitParent" handler. Then we don't need `profileStorage.initialize` in the handler as well. The message name can be renamed to "FormAutofill:UpdateSavedFieldNames".
> 
> Another reason to avoid using `profileStorage.initialize()` or `this._store.load()` in ProfileStorage.jsm is that the JSON file could be read twice if the first accesses to this.profileStorage. e.g. `this.profileStorage.addresses.getAll()`.
> 
> [1] http://searchfox.org/mozilla-central/rev/15edcfd962be2c8cfdd0b8a96102150703bd4ac5/browser/extensions/formautofill/ProfileStorage.jsm#582-585

I would rather we make all our storage APIs async and await on the initialization promise/method… that would be a nicer API and avoid some of these problems I think.
The situation with the perf numbers is:
* Doing a backout at this point won't get rid of the perf regression… it seems that something else has landed in the meantime that would have hit this same regression.
* The patches on this bug would remove the regression if they were landed on the commit that caused it.
* Upon rebasing the the fixes to inbound, the patches would have the same perf impact as landing the backout.
(See the spreadsheet for numbers)

Given that after these patches, Form Autofill would no longer be the cause of any regression, I will go ahead and land these patches are mark the bug as resolved. Joel agreed that this makes sense.
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review144500

But the problem would be the popupshown might be the history one instead of profile one. Of cource we can avoid adding history and profile on same field for testing now, but I guess we'll need one for history fallback testing after form autofilled in the future.
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review144500

I see what you mean but if we fix it with the proposed solution in bug 1366953 (to wait to give the search results until storage is initialized) we shouldn't have that problem since we wouldn't give history results.
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review145346

::: browser/extensions/formautofill/FormAutofillContent.jsm:96
(Diff revision 5)
>      this.log.debug("startSearch: for", searchString, "with input", formFillController.focusedInput);
>      let focusedInput = formFillController.focusedInput;
>      this.forceStop = false;
>      let info = FormAutofillContent.getInputDetails(focusedInput);
>  
>      if (!FormAutofillContent.savedFieldNames.has(info.fieldName) ||

nit: Although you'll fix that in bug 1366953, I think it's still slightly better to ealry retrun if savedFieldNames is undifined than error.
Attachment #8868439 - Flags: review?(schung) → review+
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review145346

> nit: Although you'll fix that in bug 1366953, I think it's still slightly better to ealry retrun if savedFieldNames is undifined than error.

Well it is an error condition that we would want to know about and it will remind us to fix bug 1366953. I'd rather not do that here since there's enough going on in this bug.
Duplicate of this bug: 1366242
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review145384

LGTM!
Attachment #8868439 - Flags: review?(selee) → review+
Comment on attachment 8868439 [details]
Bug 1364477 - Delay ProfileStorage initialization until focusin.

https://reviewboard.mozilla.org/r/140036/#review145404

Looks great!
Attachment #8868439 - Flags: review?(lchang) → review+
Pushed by lchang@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/a2c656d53aac
Only append formautofill.css the first time autocomplete is opening. r=lchang,ralin
https://hg.mozilla.org/integration/autoland/rev/c4d9c5751a2f
Only getAll Address Profiles once at initialization. r=steveck
https://hg.mozilla.org/integration/autoland/rev/8766c76d6c6a
Delay ProfileStorage initialization until focusin. r=lchang,seanlee,steveck
https://hg.mozilla.org/integration/autoland/rev/17797be76425
Remove FormAutofillParent.init logging to load logging code later. r=steveck
You need to log in before you can comment on or make changes to this bug.