1716896 - Credit Card autofill stops working

Status: REOPENED

(Toolkit :: Form Autofill, defect, P3)

Description

[Jon Bauman [:jbauman:]]

After entering a saved credit card in the preferences, the credit card autofill prompt appears after pressing the down arrow in a credit card number field, but when selected does not fill. This behavior occurs on various websites and is reproducible in https://fill.dev/form/credit-card-simple.

I observe the faulty behavior on macOS Catalina with 89.0 and 91.0a1 (2021-06-01), but not macOS Big Sur, despite the fact that they share a Firefox account with credit card syncing enabled.

One workaround is to delete and reenter the CC info in "Saved Credit Cards…" after which the autofill works, but eventually it stops working, making me wonder if somehow a local database is getting corrupted during the autofilling process.

Comment 1

[Ethan Tseng [:ethan]]

Tim, please see if you could reproduce this issue. Thanks!

Comment 2

[Tim Giles [:tgiles]]

Hmm, I'm not able to reproduce this on Windows 10 91.0a1. My only Mac machine is already on Big Sur and so I would need to figure out how to get Catalina on to that machine (which is entirely doable, but I've never done it before so could take me a minute).

I'll take another look at this Monday and see if I can get my Mac to repro, keeping the NI open so I don't forget.

Comment 3

[Jon Bauman [:jbauman:]]

I have no idea if this is really Catalina-specific, or just a coincidence. If there is particular logging or profiling I can gather that would help, or data from my install I can privately share, I'm happy to.

Comment 4

[Tim Giles [:tgiles]]

Hey :jbauman, if you can set "extensions.formautofill.loglevel" to "all" and then capture and post the logs from the browser console on the fill test site, that should help us figure out what's going on. Note, I don't think these logs would have any private information so it's worthwhile to scan over it before submitting it. I'm still getting up to speed on the form autofill component so I don't know exactly what we log yet, as a heads up.

Comment 5

[Jon Bauman [:jbauman:]]

This has always been inconsistent, and right at the moment I'm not able to reproduce, but rest assured that when I hit this again, I'll follow up here

Comment 6

[Victoria Wang [:victoria]]

I think I reproduced this on a fresh Nightly profile on MacOS 11.4.

• Test page

• Behavior: Added a fake credit card in Settings. Went to test page. First time clicking in the credit card field gave me an empty 1-row menu (and the below error message). Subsequent clicks in the field did not result in a menu but did result in more of the same error message.

• Browser console error:

TypeError: item._adjustAcItem is not a function (5) autocomplete-popup.js:504:16
    _appendCurrentResult chrome://global/content/elements/autocomplete-popup.js:504
    _invalidate chrome://global/content/elements/autocomplete-popup.js:309
    invalidate chrome://global/content/elements/autocomplete-popup.js:283
    showPopupWithResults resource://gre/actors/AutoCompleteParent.jsm:287
    receiveMessage resource://gre/actors/AutoCompleteParent.jsm:440
    (Async: JSActor query)
    openAutocompletePopup resource://gre/actors/AutoCompleteChild.jsm:148
    startSearch resource://autofill/FormAutofillContent.jsm:277
    (Async: promise callback)
    startSearch resource://autofill/FormAutofillContent.jsm:276

Related bug: The first time I tried to reproduce this in my fresh Nightly profile, the CC/address settings seemed to be altogether missing from Settings. They came back when I restarted.

Comment 7

[Victoria Wang [:victoria]]

Attachment: Screen Shot 2021-07-06 at 2.29.10 PM.png

Ah, whoops, reproduced again with "extensions.formautofill.loglevel" set to "all". Got this additional info in browser console (attached screenshot since there's so much formatting)

Comment 8

[Victoria Wang [:victoria]]

(This bug seems to be the same)

Comment 10

[Jon Bauman [:jbauman:]]

(In reply to Tim Giles [:tgiles] from comment #4)

Hey :jbauman, if you can set "extensions.formautofill.loglevel" to "all" and then capture and post the logs from the browser console on the fill test site, that should help us figure out what's going on. Note, I don't think these logs would have any private information so it's worthwhile to scan over it before submitting it. I'm still getting up to speed on the form autofill component so I don't know exactly what we log yet, as a heads up.

Ok, I finally got this to reproduce in 94.0.2 on macOS 10.15.7:

FormAutofillHandler: Ignoring FormAutofillAddressSection related fields since it is an invalid section FormAutofillHandler.jsm:86
FormAutofillHandler: Creating new credit card section with flowId = {db34beaf-5ae3-5d45-bf15-e41834a3744d} FormAutofillHandler.jsm:927
AutofillRecords:creditCards: getAll false false FormAutofillStorageBase.jsm:664
AddressResult: Constructing new ProfileAutoCompleteResult: <unavailable> ProfileAutoCompleteResult.jsm:43
FormAutofillHandler: preview profile:  <unavailable> FormAutofillHandler.jsm:416
FormAutofillParent: Reauth is disabled FormAutofillParent.jsm:328
NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIAutoCompleteController.getStyleAt] LoginManagerChild.jsm:209
    observe resource://gre/modules/LoginManagerChild.jsm:209
    receiveMessage resource://gre/actors/AutoCompleteChild.jsm:56
FormAutofillHandler: clear previewed fields in: undefined 4 FormAutofillHandler.jsm:457
FormAutofillParent: User canceled encryption login FormAutofillParent.jsm:338
FormAutofillHandler: profile cannot be filled <unavailable> FormAutofillHandler.jsm:338
FormAutofillHandler: register change handler for filled form: <unavailable> FormAutofillHandler.jsm:1483
sendRemoveListener on closed conduit {7a7a4a92-a2a0-41d1-9fd7-1e92480d612d}.6734508725482 ConduitsChild.jsm:108
sendRemoveListener on closed conduit {7a7a4a92-a2a0-41d1-9fd7-1e92480d612d}.6734508725470 ConduitsChild.jsm:108
sendRemoveListener on closed conduit {7a7a4a92-a2a0-41d1-9fd7-1e92480d612d}.6734508725460 ConduitsChild.jsm:108
sendRemoveListener on closed conduit {7a7a4a92-a2a0-41d1-9fd7-1e92480d612d}.1649267451269 ConduitsChild.jsm:108
sendRemoveListener on closed conduit {7a7a4a92-a2a0-41d1-9fd7-1e92480d612d}.1649267451257 ConduitsChild.jsm:108
sendRemoveListener on closed conduit {7a7a4a92-a2a0-41d1-9fd7-1e92480d612d}.1649267451247 ConduitsChild.jsm:108

I tried in private browsing mode as well, which disables nearly all my add-ons and the results were basically the same. Is this helpful at all?

Comment 11

[Tim Giles [:tgiles]]

:jbauman, is this log from visiting https://fill.dev/form/credit-card-simple? If I had to guess at what's going on: it looks like something funky might be happening with the OS keychain and how we're accessing it (I guess?).

So Reauth is disabled according to the log and we have User canceled encryption login as well. This implies that the ensureLoggedIn check in the OSKeyStore did not authenticate as expected. Looking at the docs for ensureLoggedIn it looks like this key generation we do on Mac shouldn't have any issues but I'm not an expert on OSKeyStore nor MacOS key chain so I can't elaborate further. Since the authentication check failed (or we didn't ask the OS to authenticate or whatever else is happening) then credit card autofilling would not work. Why this happens intermittently though, I have no idea.

If there was a different error then it should have appeared before the "User canceled encryption login" message, so I'm assuming something went wrong during the OSKeyStore.decrypt part when Form Autofill tried to get the decrypted cc-number. Obviously this doesn't solve the issue, but gives us something to look into. I just wonder if sometimes we don't request the OS authentication prompt "correctly" and that causes this issue or something...

Comment 12

[Jon Bauman [:jbauman:]]

Is there any benefit to me holding off upgrading to try to maintain this repro, or do you have all the info you need here?

Comment 13

[Tim Giles [:tgiles]]

If you're able to repro relatively consistently, change the logging level for toolkit.osKeyStore.loglevel to Debug (I'm guessing it's Debug since OSKeyStore is using the Console API to log) and see if you can repro with additional logging. There might be sensitive information in this particular log so please check for "ensureLoggedIn: Secret generated. Recovery phrase length: " in your log before uploading or you can send me the log directly to avoid this potential issue.

Comment 14

[Jon Bauman [:jbauman:]]

Logs communicated out-of-band.

I also tried checking the "Require macOS authentication…" pref, and did get a prompt to enter my password when doing the autofill, but it still failed.

Comment 15

[Jon Bauman [:jbauman:]]

I understand this is a hard one to track down, so have no qualms with P3, but didn't expect this to be considered S3: "Blocks non-critical functionality and a work around exists". In the context of the browser, I suppose autofill is not critical, but in the context of the Form autofill component, it seems like it should be. Is the implication that manual entry is the work around? Personally, I find this bug enormously frustrating and it's the sort of thing that I could see driving people away from using Firefox for this incredibly common use case.

Comment 16

[Sergey Galich [:serg]]

:jbauman thanks for pointing this out.

For the record, I can not reproduce on Windows, Firefox Nightly 97.01a. But I'm seeing something else that we need to file separately.