Sync fails to fetch keys, reports "Invalid authentication token in request signature"

RESOLVED WORKSFORME

Status

Cloud Services
General
RESOLVED WORKSFORME
3 years ago
2 years ago

People

(Reporter: nolski, Unassigned)

Tracking

(Blocks: 1 bug)

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(3 attachments, 1 obsolete attachment)

(Reporter)

Description

3 years ago
Created attachment 8538200 [details]
sync-logs.zip

User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:36.0) Gecko/20100101 Firefox/36.0
Build ID: 20141217004003

Steps to reproduce:

I can't remember when this started happening but it was fairly recent. I think after updating Firefox Aurora. I have recently been using bugzilla and other Mozilla login services which may or may not have affected this issue.


Actual results:

Upon startup a yellow banner says "Sync encountered an error while syncing: Incorrect account name or password. Sync will automatically retry this action." With a button redirecting to preferences.


Expected results:

I am automatically logged into Sync.
Mike reports in IRC that disconnecting and reconnecting to sync did not resolve this issue.
The bit I find most suspicious from these logs is:

  1418502282415	FirefoxAccounts	ERROR	error GETing /account/keys: {"code":401,"errno":110,"error":"Unauthorized","message":"Invalid authentication token in request signature","info":"https://github.com/mozilla/fxa-auth-server/blob/master/docs/api.md#response-format"}

In theory, an errno 110 should only occur if you try to use a keyFetchToken that does not exist in the server db.  At a guess, I'd say it's trying to use a keyFetchToken that has already been used (and hence has been deleted from the DB).

The earliest occurrence of this I can find in the logs is 13th december, although i see something on the 9th of december that says just:

  1418139791206	Sync.BrowserIDManager	ERROR	Background fetch for key bundle failed: null: null
  1418139791206	Sync.BrowserIDManager	ERROR	Could not authenticate: null: null

And may be the same or a related issue.
I am really surprised that disconnecting and re-connecting to sync did not resolve this, by flushing all the account state.

Mike, if you get a chance could you please try creating a new profile and set up sync in there?  I'm hoping it will work in a clean profile, which will help us narrow down to what the bug might be.
Flags: needinfo?(me)
(Reporter)

Comment 4

3 years ago
I created a new profile using my personal gmail and the issue happened again after restarting.
Flags: needinfo?(me)
Sorry, I should have been much more explicit: try creating a new client-side firefox profile, not a new server-side account, in order to clear out any weird state that firefox might have recorded internally in your default profile.

Details on using firefox profiles are at https://support.mozilla.org/en-US/kb/profile-manager-create-and-remove-firefox-profiles
Flags: needinfo?(me)
User "Rolcol" in IRC is reporting the same: "At launch, I keep getting the yellow bar at the bottom of Firefox telling me: "Sync encountered an error while syncing: Incorrect account name or password.  Sync will automatically retry this action."  My email/password credentials have not changed.  When I log back in, everything is fine until Firefox is exited and reopened."

Comment 7

3 years ago
Created attachment 8539338 [details]
rolcol-about_sync-log-error-1418544839593.txt

This is the last log before callahad suggested that I disconnect, restart, then reconnect.  Sync began working like normal after that.

Comment 8

3 years ago
Created attachment 8539341 [details]
about_sync-log_logs.zip

Ok, I lied.  That other error log was from before I went to IRC looking for help.  This attachment is all the logs.
Attachment #8539338 - Attachment is obsolete: true
For the record, creating a new profile also appeared to work. Rolcol noted that several other clients were syncing without difficulty, so it was something profile-specific. This was on OS X 10.10.1, Fx Beta 35.0b4.
(Reporter)

Comment 10

3 years ago
Creating a new profile also worked for me but when switching back to my current profile the issue persisted.
Flags: needinfo?(me)
(Reporter)

Comment 11

3 years ago
Also for the record, when I started with the new profile it booted into current firefox, not the aroura build that I normally use (it didn't seem to give a choice?).
Mike, perhaps the extra explicit step that :callahad suggested above might work for you, if you didn't try it already: (1) disconnect from sync, (2) shutdown and restart firefox, (3) connect to sync again.  I'm not sure if you were restarting firefox in-between when you tried this last time.
Also FWIW, it looks like :Rolcol's error was "invalid-client-state" which is a little different to the one that :nolski was seeing.  They could easily have the same underlying cause, but could also easily not.

Comment 14

3 years ago
Created attachment 8540437 [details]
syncprefs-nodisconnectbtn.png

This may be of interest:  there isn't a "disconnect" button when this bug pops up; there's just a "Forget this Email" link.  

Also, I just hit this bug on a Windows client.
Rolcol, have you seen this error re-appear on any clients that you fixed with the disconnect/restart/reconnect hack, or is it just slowly working its way around all the machines connected to your account?
Flags: needinfo?(rolyc5)
I *think* that "forget this email" should do the same thing as "disconnect" when in this state, but thanks for pointing it out explicitly, I did not realize the UI changed like that.
(Reporter)

Comment 17

3 years ago
:rfkelly Just to keep this thread up to date I disconnected from sync (forget this account)->closed firefox->opened firefox->reconnected->closed firefox->opened firefox and the issue showed up again.

Comment 18

3 years ago
I have not seen it reappear yet, no.  Once I have done the disconnection dance, the clients have worked again.  It seems to be working its way around, but my Android devices are fine so far.  

I'm using the beta branch across most of my synced Firefox profiles.  I do have an Aurora client on Android connected in.  Nightly is installed on my Nexus 7, but I'm not near it to confirm whether or not it's connected.
Flags: needinfo?(rolyc5)
Do any of you have Firefox set to delete your passwords on exit?

Comment 21

3 years ago
I do not use the "Remember passwords for sites" feature, it's unchecked.  History is set to the default of "Remember History".
FxA uses the password manager to store the Sync credentials. Rolcol, can you verify that you have a kB value stored in your password manager? You can see the values via "Saved Passwords" on the Security Preferences pane.

Comment 23

3 years ago
Yes, I do have a kB value, but this is on a profile that I have already disconnected and reconnected.  I made a backup of another profile that had the same syncing problem.  If you need me to check that one, I will.
Let's spin :Rolcol's issue out into a separate bug, since it seems to present different symptoms.  I filed Bug 1115215 for this purpose.
Regrouping on :nolski's error in this bug, here's the current status:

  * Firefox fails to connect to sync with the error "Invalid authentication token in request signature".

  * Disconnecting and reconnecting to sync does not fix the problem.

  * But connecting to the same account in a clean profile works correctly.

So I'm wondering if there's some cached state in the profile that is not being cleared correctly, even in the event of a disconnect.  The only way to get an "invalid authentication token" error is to (a) use a token that has never existing, or (b) try to re-use a token that has already been used.

Updated

3 years ago
Summary: Sync has issues authenticating account name and password on FF Start → Sync fails to fetch keys, reports "Invalid authentication token in request signature"
(In reply to Ryan Kelly [:rfkelly] from comment #25)
> So I'm wondering if there's some cached state in the profile that is not
> being cleared correctly, even in the event of a disconnect.  The only way to
> get an "invalid authentication token" error is to (a) use a token that has
> never existing, or (b) try to re-use a token that has already been used.

That sounds a little like the data not being deleted from the login manager.  :nolski, do you happen to have an addon installed that provides login manager or password manager related functionality?

(If for some reason something else is failing in or around our login manager, we could possibly make this more robust by storing a unique ID in both signedInUser.json and the login manager and insisting they match - at the moment I think we would happily reuse "stale" info from the login manager so long as the email addresses match)

Updated

3 years ago
Blocks: 1119667
FTR, the problems reported by Mike are almost certainly due to the macos-keychain@fitzell.ca addon - see bug 1128402. Attempting to save the FxA credentials are failing which explains why we see the reauth prompt, and why "forgetting" and starting from scratch still fails.  Rolcol's issues look different.
(Reporter)

Comment 28

3 years ago
Sorry for not replying to this earlier. :markh is correct in that the issues were due to the macos-keychain issue and uninstalling that solved the issue.
Thanks everyone for following up on this. Given :nolski's issue is bug 1128402 and :RolCol's issue had bug 1115215 filed for it, I'm going to close this as WFM (not sure WFM really is the right resolution in this scenario, but it seems better than INVALID or duping it, and it doesn't really matter :)
Status: UNCONFIRMED → RESOLVED
Last Resolved: 2 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.