982241 - signing in again after changing password doesn't update menu panel UI

Status: VERIFIED FIXED

(Firefox :: Sync, defect, P1)

Description

[Edwin Wong [:edwong]]

1. setup sync in profile A
2. change password
3. launch new profile B
4. sign in with same account with the new password from step 2

result: you get in an 'signed in' screen but desktop UI says 'reconnect'.  When you reconnect, you get the same result.

Comment 1

[Edwin Wong [:edwong]]

methinks some form of invalid assertion is being sent to token server - not sure which component owns this bug.

Comment 2

[Edwin Wong [:edwong]]

also - there are no logs to pull out - so the failure maybe occurring before it attempts to talk to token server

Comment 3

[Chris Karlof [:ckarlof]]

Edwin, I couldn't reproduce this. Can you reproduce?

Comment 4

[Chris Karlof [:ckarlof]]

Ah, when I restart profile A, and "reconnect" the state in the hamburger menu still shows "Reconnect", but the Prefs panel shows the correct state. I don't think the hamburger menu is getting notified properly after the user logs in. Is this what you're seeing?

Comment 5

[Edwin Wong [:edwong]]

triaged

Comment 6

[Chris Karlof [:ckarlof]]

I think that the menu items are missing an observer that the pref panel observes to know that the "reconnect" has happened.

Comment 7

[Chris Karlof [:ckarlof]]

Gavin said he'd take a look at this.

Comment 8

[Edwin Wong [:edwong]]

actually - sync is in fact busted when i use the hamburger > sync button i get this error:

1394650489182	Sync.BrowserIDManager	ERROR	Authentication error in _fetchTokenForUser: AuthenticationError(TokenServerClientServerError({"now":"2014-03-12T18:54:49.181Z","message":"Authentication failed.","cause":"invalid-client-state","response_body":"{\"status\": \"invalid-client-state\", \"errors\": [{\"location\": \"body\", \"name\": \"\", \"description\": \"Unauthorized\"}]}","response_headers":{"content-type":"application/json; charset=UTF-8","date":"Wed, 12 Mar 2014 18:54:52 GMT","server":"nginx/1.4.4","x-timestamp":"1394650492","content-length":"111","connection":"keep-alive"},"response_status":401}))
1394650489182	Sync.Status	DEBUG	Status.login: success.login => error.login.reason.account
1394650489182	Sync.Status	DEBUG	Status.service: success.status_ok => error.login.failed
1394650489183	Sync.BrowserIDManager	ERROR	Background fetch for key bundle failed: AuthenticationError(TokenServerClientServerError({"now":"2014-03-12T18:54:49.181Z","message":"Authentication failed.","cause":"invalid-client-state","response_body":"{\"status\": \"invalid-client-state\", \"errors\": [{\"location\": \"body\", \"name\": \"\", \"description\": \"Unauthorized\"}]}","response_headers":{"content-type":"application/json; charset=UTF-8","date":"Wed, 12 Mar 2014 18:54:52 GMT","server":"nginx/1.4.4","x-timestamp":"1394650492","content-length":"111","connection":"keep-alive"},"response_status":401}))

Comment 9

[Edwin Wong [:edwong]]

you're welcome to use my acct which should repro the issue:
[e-mail]
pw: 123456789

Comment 10

[:Gavin Sharp [email: [e-mail]]]

Edwin: I'm seeing that too. I filed bug 982798 to cover it since it's a separate issue.

My STR:
1) Set up profile
2) Shut it down
3) Change password
4) Re-launch original profile
5) re-sign in
6) panel UI still shows "Reconnect", despite tools menu and prefs being updated correctly

What I'm seeing when re-logging in at 5) is that browser-fxaccounts' observer (http://hg.mozilla.org/mozilla-central/annotate/a1639dd9dd3d/browser/base/content/browser-fxaccounts.js#l102) is called for:

  * fxaccounts:onlogin, which calls updateUI, but loginFailed is still true when getSignedInUser returns, at http://hg.mozilla.org/mozilla-central/annotate/a1639dd9dd3d/browser/base/content/browser-fxaccounts.js#l188, so UI stays in the "need to log in" state
  * fxaccounts:onverified, which does not call updateUI, because it's handled separately: http://hg.mozilla.org/mozilla-central/annotate/a1639dd9dd3d/browser/base/content/browser-fxaccounts.js#l109

I think the observer should be calling updateUI for onverified.

Comment 11

[:Gavin Sharp [email: [e-mail]]]

Attachment: patch

I think this fixes the issue, hard to test at the moment given that other bug.

Comment 12

[:Gavin Sharp [email: [e-mail]]]

Comment on attachment 8390030 [details] [diff] [review]
patch

This patch doesn't fix it - when the "onverified" message is sent, this.loginFailed is still true (i.e. Weave.Status.login == Weave.LOGIN_FAILED_LOGIN_REJECTED).

I think this might be a bug in browserid_identity.js - I see it setting Weave.Status.login = LOGIN_SUCCEEDED in initializeWithCurrentIdentity, and I see it setting LOGIN_FAILED_LOGIN_REJECTED or LOGIN_FAILED_NETWORK_ERROR in _fetchTokenForUser, but I don't ever see it setting Weave.Status.login in a "logging back in after an auth error" code path.

Comment 13

[Chris Karlof [:ckarlof]]

> I don't ever see it setting Weave.Status.login in a "logging back in after an auth error" code path.

"logging back in after an auth error" calls initializeWithCurrentIdentity() again.

Comment 14

[:Gavin Sharp [email: [e-mail]]]

So the issue is that both the UI and browserid_identity are observing onlogin, so there's an ordering issue. But even ignoring that, initializeWithCurrentIdentity (which is what sets Sync's login status after the sign in) takes several spins of the event loop before it actually sets Weave.Status.login, so it's not set by the time the UI's onlogin handler is called.

Thankfully, initializeWithCurrentIdentity fires "weave:service:setup-complete" for updates that are the result of a login, so we can have the UI just use that. That fixes this issue for me.

(I filed bug 982986 about an implementation detail of browserid_identity that makes it safer for the UI to rely on that notification.)

Comment 15

[:Gavin Sharp [email: [e-mail]]]

Attachment: patch

Comment 16

[Chris Karlof [:ckarlof]]

> This patch doesn't fix it - when the "onverified" message is sent, this.loginFailed is still true (i.e. Weave.Status.login == Weave.LOGIN_FAILED_LOGIN_REJECTED).

This makes sense. The "onverified" message probably arrives before browserid_identity.initializeWithIdentity gets around to setting Weave.Status.login = LOGIN_SUCCEEDED.

Comment 17

[:Gavin Sharp [email: [e-mail]]]

https://hg.mozilla.org/integration/fx-team/rev/75f3bd5737a6

Comment 18

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/75f3bd5737a6

Comment 19

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/24ec57c72c91

Comment 20

[Bogdan Maris, Desktop Test Engineering]

Reproduced the initial issue on old Nightly from 2014-03-11, verified as fixed on Firefox 29 RC and latest Aurora.