1619498 - Record in telemetry how long it takes to display an autocomplete popup

Status: VERIFIED FIXED

(Toolkit :: Password Manager, task, P1)

Description

[Matthew N. [:MattN]]

We have had reports of autocomplete being slow for dozens of logins (probably due to decryption time e.g. bug 1564074) and we would like to try using Fathom for determining whether to offer password generation (bug 1595244) so it's useful to understand how long it's taking to display autocomplete results in the wild.

Variables we may want to account for:

• password field or text field (username)
• generation enabled and offered
• empty searchString
• has a previousResult
• number of saved logins returned
• resultStyles returned
• autocompleteInfo.fieldName (to compare to previous "new-password" behaviour)

Given that there are so many variables that could affect the timing, I think we should use an event instead of a histogram so we can record these variables more easily in extra_keys rather than hacking together some composite key e.g. password_1_1_0_1 which will be fragile if we add a variable. Using events also means not being able to use TelemetryStopwatch, though I think we probably can't use it here anyways due to wanting to record times between different processes (bug 1354167), instead we'll need to use Services.telemetry.msSystemNow().

Other things to note:

• We should be careful not to record too many events in one session… maybe only handle searchString of 0 and 1?
• Since we know there are ideas about using Fathom for credit card autofill heuristics too, it would be nice to not limit this to login autocomplete results.

Comment 1

[Matthew N. [:MattN]]

The autocomplete search starts in password manager at https://searchfox.org/mozilla-central/rev/91f6c02fcf4c16f78fdc4417f61f192688294066/toolkit/components/passwordmgr/LoginAutoCompleteResult.jsm#431
and is displayed here: https://searchfox.org/mozilla-central/rev/91f6c02fcf4c16f78fdc4417f61f192688294066/toolkit/actors/AutoCompleteParent.jsm#198,249

Comment 2

[Matthew N. [:MattN]]

Attachment: Bug 1619498 - Remove function.bind from LoginAutoCompleteResult.startSearch. r=sfoster

Comment 3

[Matthew N. [:MattN]]

Attachment: Bug 1619498 - Assign to this._autoCompleteLookupPromise inside completeSearch. r=sfoster

Depends on D66723

Comment 4

[Matthew N. [:MattN]]

Attachment: Bug 1619498 - Switch _autoCompleteSearchAsync to an async method. r=sfoster

Depends on D66724

Comment 5

[Matthew N. [:MattN]]

Attachment: Bug 1619498 - Create previousResult once in LoginAutoCompleteResult. r=sfoster

The only difference was the conversion to vanilla objects.

Depends on D66725

Comment 6

[Matthew N. [:MattN]]

Attachment: Bug 1619498 - Rename LoginAutoCompleteResult.jsm to LoginAutoComplete.jsm. r=sfoster

The file is more than just the LoginAutoCompleteResult class, it handles all login autocompletion.

Depends on D66726

Comment 7

[Matthew N. [:MattN]]

Attachment: Bug 1619498 - Move _autoCompleteSearchAsync and gAutoCompleteListener to LoginAutoComplete.jsm. r=sfoster

Consolidate login autocomplete code in one file.

Depends on D66727

Comment 8

[Matthew N. [:MattN]]

Attachment: Bug 1619498 - Reduce duplication between _requestAutoCompleteResultsFromParent and startSearch. r=sfoster

Depends on D66728

Comment 9

[Matthew N. [:MattN]]

Attachment: Bug 1619498 - Record in telemetry how long it takes to display an autocomplete popup. r=sfoster

Depends on D66729

Comment 10

[Matthew N. [:MattN]]

Try is green for the cleanup patches: https://treeherder.mozilla.org/#/jobs?repo=try&revision=2597590a168e0e55e26f0438a2c3f0e75168b9ce

Comment 11

[Matthew N. [:MattN]]

Attachment: Bug 1619498 - Check for a 'generatedPassword' result before accessing gGeneratedPasswordsByPrincipalOrigin. r=bdanforth

Depends on D66729

Comment 12

[Matthew N. [:MattN]]

Attachment: Bug 1619498 - Add missing await in passwordmgr mochitests. r=sfoster

Also simplify checkAutoCompleteResults.

Depends on D66887

Comment 13

[Matthew N. [:MattN]]

Attachment: Bug 1619498 - Fix passwordmgr mochitest-plain test-verify failures. r=sfoster

Also add some logging that seems generally useful.

Depends on D67087

Comment 14

[Matthew N. [:MattN]]

Attachment: Bug 1619498 - Restore access to LoginManagerParent._recipeManager to fix resetting recipes in mochitest. r=sfoster

https://hg.mozilla.org/mozilla-central/rev/aa78dbe7934f7b7c5ec3de348cb70109fa0e35aa#l8.32 deleted this member but didn't update this reference. This caused <!-- formless password field selector recipe test --> in test_formless_autofill.html to fail test verification.

Depends on D67088

Comment 15

[Matthew N. [:MattN]]

Attachment: Request for data collection review form

The actual telemetry recording is in https://phabricator.services.mozilla.com/D66730#change-F6M6PHCi3D7P

Comment 16

[Matthew N. [:MattN]]

Try push: https://treeherder.mozilla.org/#/jobs?repo=try&revision=546234bf542ef734bad4bc3e8cb15b44cfab7e6a

Comment 17

[Matthew N. [:MattN]]

I'm landing all but D66730 (since data-review is pending) to unblock other work.

Comment 18

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/f89d7b0e4a76
Remove function.bind from LoginAutoCompleteResult.startSearch. r=sfoster
https://hg.mozilla.org/integration/autoland/rev/4ba98b434622
Assign to this._autoCompleteLookupPromise inside completeSearch. r=sfoster
https://hg.mozilla.org/integration/autoland/rev/02dca53e816a
Switch _autoCompleteSearchAsync to an async method. r=sfoster
https://hg.mozilla.org/integration/autoland/rev/07a87d64d4d8
Create previousResult once in LoginAutoCompleteResult. r=sfoster
https://hg.mozilla.org/integration/autoland/rev/6e5ce5c2ad45
Rename LoginAutoCompleteResult.jsm to LoginAutoComplete.jsm. r=sfoster
https://hg.mozilla.org/integration/autoland/rev/b6536f155576
Move _autoCompleteSearchAsync and gAutoCompleteListener to LoginAutoComplete.jsm. r=sfoster
https://hg.mozilla.org/integration/autoland/rev/de9538b840e9
Reduce duplication between _requestAutoCompleteResultsFromParent and startSearch. r=sfoster
https://hg.mozilla.org/integration/autoland/rev/1c8f108909cb
Check for a 'generatedPassword' result before accessing gGeneratedPasswordsByPrincipalOrigin. r=bdanforth
https://hg.mozilla.org/integration/autoland/rev/b3503cdeb434
Add missing await in passwordmgr mochitests. r=sfoster
https://hg.mozilla.org/integration/autoland/rev/c47897bb4792
Fix passwordmgr mochitest-plain test-verify failures. r=sfoster
https://hg.mozilla.org/integration/autoland/rev/18edd0bc728a
Restore access to LoginManagerParent._recipeManager to fix resetting recipes in mochitest. r=sfoster

Comment 19

[Daniel Varga [:dvarga]]

https://hg.mozilla.org/mozilla-central/rev/f89d7b0e4a76
https://hg.mozilla.org/mozilla-central/rev/4ba98b434622
https://hg.mozilla.org/mozilla-central/rev/02dca53e816a
https://hg.mozilla.org/mozilla-central/rev/07a87d64d4d8
https://hg.mozilla.org/mozilla-central/rev/6e5ce5c2ad45
https://hg.mozilla.org/mozilla-central/rev/b6536f155576
https://hg.mozilla.org/mozilla-central/rev/de9538b840e9
https://hg.mozilla.org/mozilla-central/rev/1c8f108909cb
https://hg.mozilla.org/mozilla-central/rev/b3503cdeb434
https://hg.mozilla.org/mozilla-central/rev/c47897bb4792
https://hg.mozilla.org/mozilla-central/rev/18edd0bc728a

Comment 20

[Tim Smith (inactive) 👨‍🔬 [:tdsmith]]

Sorry for the delay; where does this value come from? Can it contain arbitrary values from the page?

acFieldName: The "field name" token (last one) of the field's autocomplete attribute.

Comment 21

[Matthew N. [:MattN]]

(In reply to Tim Smith 👨‍🔬 [:tdsmith] from comment #20)

Sorry for the delay; where does this value come from? Can it contain arbitrary values from the page?

acFieldName: The "field name" token (last one) of the field's autocomplete attribute.

It comes from the HTML standard and we only return valid values so it can't contain arbitrary values. These are the valid values: https://searchfox.org/mozilla-central/rev/61f224ec08ddc6f9a93ac45c8c3c5f7159be7c2a/dom/base/AutocompleteFieldList.h#91-147 (we actually only support a subset of those)

HTML spec link

Comment 22

[Tim Smith (inactive) 👨‍🔬 [:tdsmith]]

Comment on attachment 9133764 [details]
Request for data collection review form

Thanks!

--

1) Is there or will there be **documentation** that describes the schema for the ultimate data set in a public, complete, and accurate way?

Yes, Events.yaml and the probe dictionary.

2) Is there a control mechanism that allows the user to turn the data collection on and off?

Yes, the Firefox telemetry opt-out.

3) If the request is for permanent data collection, is there someone who will monitor the data over time?

Yes, MattN.

4) Using the **[category system of data types](https://wiki.mozilla.org/Firefox/Data_Collection)** on the Mozilla wiki, what collection type of data do the requested measurements fall under?

Category 2, interaction data.

5) Is the data collection request for default-on or default-off?

Default-on.

6) Does the instrumentation include the addition of **any *new* identifiers** (whether anonymous or otherwise; e.g., username, random IDs, etc.  See the appendix for more details)?

No.

7) Is the data collection covered by the existing Firefox privacy notice? 

Yes.

8) Does there need to be a check-in in the future to determine whether to renew the data?

No, permanent collection.

9) Does the data collection use a third-party collection tool?

No.

Comment 23

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/ed44b5d1ca3f
Record in telemetry how long it takes to display an autocomplete popup. r=sfoster

Comment 24

[Matthew N. [:MattN]]

[Tracking Requested - why for this release]: Need to establish a performance baseline for bug 1595244 to know whether we can ship it in Fx76

Timea, is there any chance this can get verified soon so we can try uplift it to beta so we have a baseline for bug 1595244?

Comment 25

[Andreea Pavel [:apavel]]

https://hg.mozilla.org/mozilla-central/rev/ed44b5d1ca3f

Comment 26

[Timea Cernea [:tbabos][inactive]]

Verified-fixed on MacOS 10.13 and Ubuntu 16.04 on the latest Nightly 76.0a1 (2020-13-19).
The "form_autocomplete" "show" "logins" "time" telemetry is recorded.
The autocomplete dropdown is toggled for the Username/Mail or the Password field. Checked with 10, 20 and 1000 login entries.

Nightly updates on Windows are not working due to signing issues for now so can't verify on that. Will mark FX76 as verified after checking it on Windows too.
Submitted Bug 1623657 as a regression, more info there.

Comment 27

[Matthew N. [:MattN]]

(In reply to Timea Cernea [:tbabos] from comment #26)

Submitted Bug 1623657 as a regression, more info there.

Btw. I believe this isn't a problem because we record stringLength in the event.

Comment 28

[Matthew N. [:MattN]]

Comment on attachment 9133108 [details]
Bug 1619498 - Record in telemetry how long it takes to display an autocomplete popup. r=sfoster

Beta/Release Uplift Approval Request

• User impact if declined: Need to establish a performance baseline for bug 1595244 to know whether we can ship it in Fx76. Not having this data could mean that the major improvement to password generation will have to be delayed and we are trying to market 4 different password manager projects for Fx76.
  This will also allow us to potentially prioritize bug 1564074 sooner as we will know how well login autocomplete performs in aggregate in the wild.
• Is this code covered by automated tests?: Yes
• Has the fix been verified in Nightly?: Yes
• Needs manual test from QE?: Yes
• If yes, steps to reproduce: Already done.
• List of other uplifts needed: None
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): The first 7 commits are smallish cleanups/refactorings to make the telemetry recording easier and more efficient. They are low risk given our test coverage.
  The 8th fixes a regression from bug 1616356 which is straightforward as it just inverts the order of two checks. This is trivial.
  The 9th and 10th are test-only fixes to avoid intermittent failures with this series. These have no product risk.
  The 11th is the core patch that address the telemetry event recording and includes automated tests. Initial data in STMO seems to be valid with no unusual records. e.g. all time measurements are >0. It's pretty straightforward code as it passes data along with the autocomplete results in a way we already use so that it can be recorded when the popup is shown. We have a PI request for this feature so we could ask QA to do additional autocomplete smoke testing if wanted.
• String changes made/needed: None

Comment 29

[Timea Cernea [:tbabos][inactive]]

Verified on Windows 10 as well, waiting for uplift to Beta. Aside from this verification, we will also test telemetry on top sites as part of the PI request for FX76.

Comment 30

[Julien Cristau [:jcristau]]

Comment on attachment 9133108 [details]
Bug 1619498 - Record in telemetry how long it takes to display an autocomplete popup. r=sfoster

thanks for the details in the request, very helpful.

Approved for 75.0b7

Comment 31

[Julien Cristau [:jcristau]]

https://hg.mozilla.org/releases/mozilla-beta/rev/5d8eb3ea412e
https://hg.mozilla.org/releases/mozilla-beta/rev/c86f50cde1af
https://hg.mozilla.org/releases/mozilla-beta/rev/0a2a25c150af
https://hg.mozilla.org/releases/mozilla-beta/rev/78c29ec2230a
https://hg.mozilla.org/releases/mozilla-beta/rev/a59600f166e6
https://hg.mozilla.org/releases/mozilla-beta/rev/bb04263dc872
https://hg.mozilla.org/releases/mozilla-beta/rev/c7d18c20f9a5
https://hg.mozilla.org/releases/mozilla-beta/rev/91d222a72d3f
https://hg.mozilla.org/releases/mozilla-beta/rev/d123344fef1e
https://hg.mozilla.org/releases/mozilla-beta/rev/8ec15d9b0d49
https://hg.mozilla.org/releases/mozilla-beta/rev/b211ac31f030
https://hg.mozilla.org/releases/mozilla-beta/rev/1a8c76b92633

Comment 32

[Timea Cernea [:tbabos][inactive]]

Verified-fixed on latest Beta 75.0b7 on Windows 10 x64, Ubuntu 16.04 and MacOS 10.13.